Oracle

July 21, 2011

DriverManager calls not intended for production

Filed under: Uncategorized — srivenu @ 9:28 am

I was looking into the performance issue in an OC4J application, which occasionally froze for 2-3 minutes. The issue got escalated as the problem frequency increased.

Step 1 : Get a thread dump.
First of all, I needed a series of thread dumps during the freeze for analysis. But the freeze duration was too short. The issue passed off by the time users complained, and the system was checked. So i decided to used dmstool to identify the symptoms during the freeze. If i could identify the symptoms, i schedule a job to thread dump the Jserv processes during the freeze. Using dmstool, i gathered all metrics data for the application at 30 second duration for 1 day. Next day, after correlating with the freeze times reported by the users, i could see a steady spike in the “activeThreads.value” metric which peaked during the freeze. Next, i set up a job which monitored the “activeThreads.value” and perfomed a kill -3 on the java process if it spiked to a certain value.

Step 2 : Analyze the thread dump.
Shown below is a part of that thread dump. I removed several waiting threads as they all waited at the same location. I also renamed our class names to something like abc.def etc. I showed the waiting threads at the top with the blocker at the end.


"AJPRequestHandler-RMICallHandler-623" prio=1 tid=0x089fed00 nid=0x473b waiting for monitor entry [0x9db2e000..0x9db2efa0]
	at java.sql.DriverManager.registerDriver(DriverManager.java:259)
	- waiting to lock  (a java.lang.Class)
	at com.abc.def.pqr.stu(DBConnection.java:33)
	at com.abc.def.ghi.jkl(mno.java:113)
	at com.evermind.server.http.ServletRequestDispatcher.invoke(ServletRequestDispatcher.java:644)
	at com.evermind.server.http.ServletRequestDispatcher.forwardInternal(ServletRequestDispatcher.java:391)
	at com.evermind.server.http.HttpRequestHandler.doProcessRequest(HttpRequestHandler.java:908)
	at com.evermind.server.http.HttpRequestHandler.processRequest(HttpRequestHandler.java:458)
	at com.evermind.server.http.AJPRequestHandler.run(AJPRequestHandler.java:313)
	at com.evermind.server.http.AJPRequestHandler.run(AJPRequestHandler.java:199)
	at oracle.oc4j.network.ServerSocketReadHandler$SafeRunnable.run(ServerSocketReadHandler.java:260)
	at oracle.oc4j.network.ServerSocketAcceptHandler.procClientSocket(ServerSocketAcceptHandler.java:234)
	at oracle.oc4j.network.ServerSocketAcceptHandler.access$700(ServerSocketAcceptHandler.java:29)
	at oracle.oc4j.network.ServerSocketAcceptHandler$AcceptHandlerHorse.run(ServerSocketAcceptHandler.java:879)
	at com.evermind.util.ReleasableResourcePooledExecutor$MyWorker.run(ReleasableResourcePooledExecutor.java:303)
	at java.lang.Thread.run(Thread.java:595)

"AJPRequestHandler-HTTPThreadGroup-622" prio=1 tid=0xa18ac588 nid=0x46e8 waiting for monitor entry [0x9effe000..0x9efff120]
	at java.sql.DriverManager.registerDriver(DriverManager.java:259)
	- waiting to lock  (a java.lang.Class)
	at com.abc.def.pqr.stu(DBConnection.java:33)
	at com.abc.def.ghi.jkl(mno.java:113)
	at com.evermind.server.http.ServletRequestDispatcher.invoke(ServletRequestDispatcher.java:644)
	at com.evermind.server.http.ServletRequestDispatcher.forwardInternal(ServletRequestDispatcher.java:391)
	at com.evermind.server.http.HttpRequestHandler.doProcessRequest(HttpRequestHandler.java:908)
	at com.evermind.server.http.HttpRequestHandler.processRequest(HttpRequestHandler.java:458)
	at com.evermind.server.http.AJPRequestHandler.run(AJPRequestHandler.java:313)
	at com.evermind.server.http.AJPRequestHandler.run(AJPRequestHandler.java:199)
	at oracle.oc4j.network.ServerSocketReadHandler$SafeRunnable.run(ServerSocketReadHandler.java:260)
	at oracle.oc4j.network.ServerSocketAcceptHandler.procClientSocket(ServerSocketAcceptHandler.java:234)
	at oracle.oc4j.network.ServerSocketAcceptHandler.access$700(ServerSocketAcceptHandler.java:29)
	at oracle.oc4j.network.ServerSocketAcceptHandler$AcceptHandlerHorse.run(ServerSocketAcceptHandler.java:879)
	at com.evermind.util.ReleasableResourcePooledExecutor$MyWorker.run(ReleasableResourcePooledExecutor.java:298)
	at java.lang.Thread.run(Thread.java:595)

"AJPRequestHandler-HTTPThreadGroup-620" prio=1 tid=0xa306f4a0 nid=0x46de waiting for monitor entry [0x9ea77000..0x9ea77e20]
	.......................................


"AJPRequestHandler-RMICallHandler-619" prio=1 tid=0x08535340 nid=0x46dd waiting for monitor entry [0xa2a6e000..0xa2a6eda0]
	.......................................

"AJPRequestHandler-RMICallHandler-612" prio=1 tid=0xa22d7018 nid=0x3c70 runnable [0x9e9f6000..0x9e9f6e20]
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at oracle.net.ns.Packet.receive(Unknown Source)
	at oracle.net.ns.DataPacket.receive(Unknown Source)
	at oracle.net.ns.NetInputStream.getNextPacket(Unknown Source)
	at oracle.net.ns.NetInputStream.read(Unknown Source)
	at oracle.net.ns.NetInputStream.read(Unknown Source)
	at oracle.net.ns.NetInputStream.read(Unknown Source)
	at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:978)
	at oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:950)
	at oracle.jdbc.driver.T4CTTIoauthenticate.receiveOauth(T4CTTIoauthenticate.java:618)
	at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:301)
	at oracle.jdbc.driver.PhysicalConnection.(PhysicalConnection.java:346)
	at oracle.jdbc.driver.T4CConnection.(T4CConnection.java:149)
	at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:31)
	at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:543)
	at java.sql.DriverManager.getConnection(DriverManager.java:525)
	- locked  (a java.lang.Class)
	at java.sql.DriverManager.getConnection(DriverManager.java:171)
	- locked  (a java.lang.Class)
	at com.abc.def.dbutilities.abcDBConnection.openOracleConnection(abcDBConnection.java:21)
	at com.abc.def.dao.InsertFeedbackDao.insertabcData(InsertFeedbackDao.java:447)
	at com.abc.def.bos.CloseMailBo.closeMail(CloseMailBo.java:366)
	at com.abc.def.actions.CloseMailAction.execute(CloseMailAction.java:60)
	at org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:484)
	at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:274)
	at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1482)
	at org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:525)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:763)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:856)
	at com.evermind.server.http.ResourceFilterChain.doFilter(ResourceFilterChain.java:64)
	at com.abc.def.ghi.jkl(mno.java:113)
	at com.evermind.server.http.ServletRequestDispatcher.invoke(ServletRequestDispatcher.java:644)
	at com.evermind.server.http.ServletRequestDispatcher.forwardInternal(ServletRequestDispatcher.java:391)
	at com.evermind.server.http.HttpRequestHandler.doProcessRequest(HttpRequestHandler.java:908)
	at com.evermind.server.http.HttpRequestHandler.processRequest(HttpRequestHandler.java:458)
	at com.evermind.server.http.AJPRequestHandler.run(AJPRequestHandler.java:313)
	at com.evermind.server.http.AJPRequestHandler.run(AJPRequestHandler.java:199)
	at oracle.oc4j.network.ServerSocketReadHandler$SafeRunnable.run(ServerSocketReadHandler.java:260)
	at oracle.oc4j.network.ServerSocketAcceptHandler.procClientSocket(ServerSocketAcceptHandler.java:234)
	at oracle.oc4j.network.ServerSocketAcceptHandler.access$700(ServerSocketAcceptHandler.java:29)
	at oracle.oc4j.network.ServerSocketAcceptHandler$AcceptHandlerHorse.run(ServerSocketAcceptHandler.java:879)
	at com.evermind.util.ReleasableResourcePooledExecutor$MyWorker.run(ReleasableResourcePooledExecutor.java:303)
	at java.lang.Thread.run(Thread.java:595)

The thread RMICallHandler-612 is the culprit and has locked out all the other threads. A listener issue and no timeout settings have caused intermittent connections hangs to the abcDBConnection. But the important issue is that this slow connection to database abc has blocked out all the DriverManager.registerDriver calls in other threads connecting to other databases. There in lies the severe limitation of the java.sql.DriverManager calls. Most of the DriverManager calls are all synchronized and are not for use in production. Joe Weinstein has written several notes on these limitations – here is one

All the hanging threads are calling a servlet which queries a small table in the database to apply a security filter. The developer did not know how to include the servlet in the struts framework and was using this connection method just for this servlet. Actually the lookup table used for security filtering was quite small and static and they could have used ServletContext to avoid going to the database for this.

Advertisements

Leave a Comment »

No comments yet.

RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Blog at WordPress.com.

%d bloggers like this: