JNDI查找时间的巨大差异-HugevarianceinJNDIlookuptimes

We're experiencing huge variance in response times on a legacy J2EE web application running on Weblogic 10.3. The system consists of two Weblogic server instances (frontend and backend) which run on the same physical server machine and an Oracle database running on a separate host. External measurement tool alerts us every time a login to the system takes more than four seconds. Lately these warnings have been frequent. Looking at the log written by the servlet handling the login requests reveals that the time is spent on an EJB call from the frontend to the backend.

我们在Weblogic 10.3上运行的遗留J2EE Web应用程序的响应时间差异很大。该系统由两个Weblogic服务器实例(前端和后端)组成,它们运行在同一个物理服务器计算机上,另一个Oracle数据库运行在单独的主机上。每次登录系统超过四秒钟时,外部测量工具会向我们发出警报。最近这些警告频繁发生。查看处理登录请求的servlet所写的日志会显示从前端到后端的EJB调用所花费的时间。

Example of the measured times:

测量时间的示例:

time    ms   
8:40:43 25
8:42:14 26
8:44:04 26
8:44:25 26
8:44:47 26
8:46:06 26
8:46:41 7744
8:47:00 27
8:47:37 27
8:49:00 26
8:49:37 26
8:50:03 8213
8:50:57 27
8:51:04 26
8:51:06 25
8:57:26 2545
8:58:13 26
9:00:06 5195

As can be seen, most of the requests (70%, taken from a larger sample) complete in timely fashion but a significant portion of them take a very long time to complete.

可以看出,大多数请求(70%,来自更大的样本)及时完成,但其中很大一部分需要很长时间才能完成。

The steps performed during the measured time are the following:

在测量时间内执行的步骤如下:

• JNDI lookup of the session bean offering the authentication interface (frontend)

提供身份验证接口(前端)的会话bean的JNDI查找

• Calling the authentication method of the session bean (frontend->backend)

调用会话bean的身份验证方法(frontend-> backend)

• Reserving a JDBC connection from the connection pool (backend)

从连接池(后端)保留JDBC连接

• Making a query to the user database (table size is very moderate and the table should be properly indexed) (backend)

对用户数据库进行查询(表大小非常适中,表应该正确编入索引)(后端)

• Reading the result set, creating the POJO user object (backend)

读取结果集,创建POJO用户对象(后端)

• Returning the POJO user object (backend->frontend)

返回POJO用户对象(后端 - >前端)

The load on the server machine is very small (99% idle) and the number of users is very moderate. Amount of free memory reported by Weblogic varies between 60% and 90% on both servers. Garbage collection is logged. Major collections are rare and complete in 2-3 seconds when they do occur. Further, the major GC occurances seem not to happen at the same time when long response times are seen. Long response times occur on both busy and non-busy hours. The JDBC connection pool max size is currently set to 80 which is more than the number of concurrent users.

服务器计算机上的负载非常小(99%空闲),用户数量非常适中。两个服务器上Weblogic报告的可用内存量在60%到90%之间。记录垃圾收集。主要藏品很少见,并且在发生时会在2-3秒内完成。此外,主要的GC出现似乎不会在看到长响应时间的同时发生。繁忙和非繁忙时段都会出现较长的响应时间。 JDBC连接池最大大小当前设置为80,大于并发用户数。

Update:

Got a permission to reboot the system with some more performance logging added. The log clearly shows that the JNDI lookup is the part where the time is spent:

获得了重新启动系统的权限,并添加了更多性能日志记录。日志清楚地显示JNDI查找是花费时间的部分:

03:01:23.977 PERFORMANCE: looking up foo.bar.Bar from JNDI took 6 ms
03:14:47.179 PERFORMANCE: looking up foo.bar.Bar from JNDI took 2332 ms
03:15:55.040 PERFORMANCE: looking up foo.bar.Bar from JNDI took 1585 ms
03:29:25.548 PERFORMANCE: looking up foo.bar.Bar from JNDI took 7 ms
03:31:09.010 PERFORMANCE: looking up foo.bar.Bar from JNDI took 6 ms
03:44:25.587 PERFORMANCE: looking up foo.bar.Bar from JNDI took 6 ms
03:46:00.289 PERFORMANCE: looking up foo.bar.Bar from JNDI took 7 ms
03:59:28.028 PERFORMANCE: looking up foo.bar.Bar from JNDI took 2052 ms

Looking at the GC logs of the frontend and backend shows that GC is not done when the slow JNDI lookups occur.

查看前端和后端的GC日志显示,当发生慢速JNDI查找时,GC未完成。

The context is got the following way when a session is created:

创建会话时,上下文的方式如下:

Hashtable ht = new Hashtable();
ht.put(Context.PROVIDER_URL, url);
ht.put(Context.INITIAL_CONTEXT_FACTORY, "weblogic.jndi.WLInitialContextFactory");
jndiCOntext= new InitialContext(ht);

where url is a t3 url pointing to the DNS name and port of the backend server. This should be ok, right?

其中url是指向后端服务器的DNS名称和端口的t3 url。这应该没问题吧?

First thing to pop into mind is to cache the references got from JNDI, at least this was the preferred way to go 10 years ago... But shouldn't Weblogic's InitialContext implementation already do this caching, or does it really fetch the reference from the backend server on each call?

要记住的第一件事是缓存从JNDI获得的引用,至少这是10年前的首选方式......但是不应该Weblogic的InitialContext实现已经执行了这个缓存,或者它是否真的从中获取引用每次通话后端服务器?

What could be causing the frequent slow JNDI lookups? Is there a workaround for this (e.g. would caching the references help)?

什么可能导致频繁的慢速JNDI查找?是否有解决方法(例如缓存参考帮助)?

3 个解决方案