Hi,
again, my tomcat freezes today, and i must stop/start tomcat to get new connections:
i checked MaxDB server and a Running thread causes Timer to block.
the output of command show t_cnt of the running maxdb thread is:
-------------------- T270 USER ( pid = 0 ) --------------- remote_node : 192.168.99.1 remote_pid : 0 dispatcher_cnt: 618065 command_cnt : 99418 exclusive_cnt : 1035660104 self_susp_cnt : 4 Resume count 0 total 155 History [ T2 T2 T2 ] dev_read_io : 177 dev_read_pg : 177 state_vwait : 0 state_vsleep : 45 state_vsusp : 144 rcv_rpl_count : 99418 rcv_rpl_long : 0 avg_rcv_rpl_t : 0.0000 dev_que_len_0 : 177 dev_que_len_1 : 0 dev_que_len>1 : 0 prio_total : 2 prio_from_oth : 2 -------------------------------------------------------------------------------
some of the java blocked thread example is:
"http-80-173" daemon prio=10 tid=0x0000000043edd000 nid=0x7ce8 waiting for monitor entry [0x000000005564c000..0x000000005564da90] java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.tomcat.dbcp.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:917) - waiting to lock <0x00002aaab91895b0> (a org.apache.tomcat.dbcp.pool.impl.GenericObjectPool) at org.apache.tomcat.dbcp.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:96) at org.apache.tomcat.dbcp.dbcp.BasicDataSource.getConnection(BasicDataSource.java:880) at org.exolab.castor.jdo.engine.DatabaseRegistry.createConnection(DatabaseRegistry.java:399) at org.exolab.castor.jdo.engine.TransactionContextImpl.getConnection(TransactionContextImpl.java:203) at org.exolab.castor.persist.TransactionContext.query(TransactionContext.java:644) - locked <0x00002aab12f5a5d8> (a org.exolab.castor.jdo.engine.TransactionContextImpl) at org.exolab.castor.jdo.engine.OQLQueryImpl.execute(OQLQueryImpl.java:458) at org.exolab.castor.jdo.engine.OQLQueryImpl.execute(OQLQueryImpl.java:414) at com.supridatta.bean.DataPersist.consulta(DataPersist.java:536) at com.supridatta.servlet.SupridattaServlet.doConsultarControl(SupridattaServlet.java:730) at com.supridatta.servlet.SupridattaServlet$9.resolve(SupridattaServlet.java:294) at com.supridatta.servlet.SupridattaServlet.processaOperacao(SupridattaServlet.java:144) at com.supridatta.servlet.SupridattaServlet.doAppletControl(SupridattaServlet.java:114) at com.supridatta.servlet.SupridattaServlet.service(SupridattaServlet.java:1747) at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:183) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:568) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
like this exists about 189 java blocked threads all waiting for this one:
"Timer-4" daemon prio=10 tid=0x0000000043ae7000 nid=0x51b3 runnable [0x0000000042128000..0x0000000042128b10] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at com.sap.dbtech.rte.comm.BasicSocketComm.receiveData(BasicSocketComm.java:577) at com.sap.dbtech.rte.comm.BasicSocketComm.receive(BasicSocketComm.java:666) at com.sap.dbtech.rte.comm.JdbcCommunication.execute(JdbcCommunication.java:41) at com.sap.dbtech.jdbc.ConnectionSapDB.execute(ConnectionSapDB.java:536) - locked <0x00002aaabce3bc80> (a com.sap.dbtech.jdbc.ConnectionSapDB) at com.sap.dbtech.jdbc.ConnectionSapDB.execute(ConnectionSapDB.java:461) at com.sap.dbtech.jdbc.ConnectionSapDB.isClosed(ConnectionSapDB.java:746) at com.sap.dbtech.jdbc.trace.Connection.isClosed(Connection.java:400) at org.apache.tomcat.dbcp.dbcp.DelegatingConnection.isClosed(DelegatingConnection.java:346) at org.apache.tomcat.dbcp.dbcp.PoolableConnectionFactory.validateConnection(PoolableConnectionFactory.java:324) at org.apache.tomcat.dbcp.dbcp.PoolableConnectionFactory.validateObject(PoolableConnectionFactory.java:312) at org.apache.tomcat.dbcp.pool.impl.GenericObjectPool.evict(GenericObjectPool.java:1217) - locked <0x00002aaab91895b0> (a org.apache.tomcat.dbcp.pool.impl.GenericObjectPool) at org.apache.tomcat.dbcp.pool.impl.GenericObjectPool$Evictor.run(GenericObjectPool.java:1341) at java.util.TimerThread.mainLoop(Timer.java:512) at java.util.TimerThread.run(Timer.java:462) Locked ownable synchronizers: - None
then seeing all this appears that com.sap.dbtech.jdbc.ConnectionSapDB.isClosed(ConnectionSapDB.java:746) do something that blocks all connections, but i cant understand if T270 is related to this Timer-4 java thread.
any idea?
Clovis Wichoski wrote:>
> Hi,
>
> again, my tomcat freezes today, and i must stop/start tomcat to get new connections:
>
> i checked MaxDB server and a Running thread causes Timer to block.
What makes you think that this is the case?
> the output of command show t_cnt of the running maxdb thread is:
>
>
>
-------------------- T270 USER ( pid = 0 ) --------------- > remote_node : 192.168.99.1 remote_pid : 0 > dispatcher_cnt: 618065 command_cnt : 99418 > exclusive_cnt : 1035660104 self_susp_cnt : 4 > Resume count 0 total 155 History [ T2 T2 T2 ] > dev_read_io : 177 dev_read_pg : 177 > state_vwait : 0 state_vsleep : 45 state_vsusp : 144 > rcv_rpl_count : 99418 rcv_rpl_long : 0 avg_rcv_rpl_t : 0.0000 > dev_que_len_0 : 177 dev_que_len_1 : 0 dev_que_len>1 : 0 > prio_total : 2 prio_from_oth : 2 > -------------------------------------------------------------------------------
What exactly are you referring to in this output?
What looks suspicious to you?
>
"http-80-173" daemon prio=10 tid=0x0000000043edd000 nid=0x7ce8 waiting for monitor entry [0x000000005564c000..0x000000005564da90] > java.lang.Thread.State: BLOCKED (on object monitor) > at org.apache.tomcat.dbcp.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:917) > - waiting to lock <0x00002aaab91895b0> (a org.apache.tomcat.dbcp.pool.impl.GenericObjectPool) >
Ok, so this thread is blocked while waiting for a monitor-synchronization object used in GenericObjectPool.
This has nothing to do with MaxDB.
> like this exists about 189 java blocked threads all waiting for this one:
>
>
"Timer-4" daemon prio=10 tid=0x0000000043ae7000 nid=0x51b3 runnable [0x0000000042128000..0x0000000042128b10] > java.lang.Thread.State: RUNNABLE > at java.net.SocketInputStream.socketRead0(Native Method) > at java.net.SocketInputStream.read(SocketInputStream.java:129) > at com.sap.dbtech.rte.comm.BasicSocketComm.receiveData(BasicSocketComm.java:577) > at com.sap.dbtech.rte.comm.BasicSocketComm.receive(BasicSocketComm.java:666) > at com.sap.dbtech.rte.comm.JdbcCommunication.execute(JdbcCommunication.java:41) > at com.sap.dbtech.jdbc.ConnectionSapDB.execute(ConnectionSapDB.java:536) > - locked <0x00002aaabce3bc80> (a com.sap.dbtech.jdbc.ConnectionSapDB) >
And this one reminds us of the former threads you posted where threads were hanging while reading data from a network socket.
And sure, the JDBC driver needs to do that because you want to access your database over the network
> then seeing all this appears that com.sap.dbtech.jdbc.ConnectionSapDB.isClosed(ConnectionSapDB.java:746) do something that blocks all connections, but i cant understand if T270 is related to this Timer-4 java thread.
The problem here is, that JDBC threads usually don't reveal their process id to the MaxDB kernel.
Therefore you don't see the PID = 1234 in the x_cons output.
One way to handle this would be to have your java programm query some session information right after connection time.
Something like "select * from sessions where own='YES'" and print this into the threads logfile.
That way you can easily figure out which connection belongs to which MaxDB session.
regards,
Lars
Hi, Lars,
in truth i know nothing about this problem, just guessing, i really dont know what i can do to avoid or discover when and why this occurs,since the pool connection control is tomcat dbcp, i post info about T270 because, that was the only MaxDB thread running when the problem occurs, and is common, when i get many BLOCKED threads at java side, exists only one thread at MaxDB running, when i kill this thread, all threads get unblocked, my try with this post is to get more info or insight about this problem as i really dont know how to get information of what command the running thread is, some time in past i activated the command monitor, but for production, that consumes too much temp area, and sometimes, i get thread blocked because command monitor, too strange, but its true.
Today i willl update that database to a newer version as that is a 7.6.03.07 i will update to 7.6.06.10.
best regards
Clóvis
HI Clóvis,
I see what kind of situation you're in.
And I'm sorry to say that I'm not too familiar with analysing JAVA hang situations.
All I can add here (I think) is that I don't see that this is a MaxDB Kernel problem.
If you ask me, I'd try to figure out more about what happens between the JAVA threads system call to the network socket and the MaxDB x_server.
Somewhere in the chain of system components involved with the network communication must be a problem.
To me this would look like this:
JAVA thread -> JAVA VM -> OS Network API -> Network adapter driver -> "Network logic" like adress resolution -> routers -> DB Servers' Network adapter driver -> OS Network API -> X_SERVER
I'm not an expert for most of the components listed, but if would be my problem, I'd try to gain more insight in all of them step-by-step.
Let us know how you proceed with this!
Good luck and best regards,
Lars
p.s.
While I do think it's a good idea to install the latest patch, I doubt that this has any effect to the problem.
Hi Lars,
I updated all things, Java, Linux, MaxDB, i discovered that the problem isnt with network, but with some kind of deadlock at database side, for example:
1) user 1 insert something on table A
2) user 2 starts a long running transaction with poor SQL statement that locks the table A.
3) user 3 opens a connection to run an SQL statement that queries table A.
4) all java threads that need a new JDBC connection get blocked because step 3 never returns a new connection, and DBCP synchronization never goes out.
here is the thread of step 2:
java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at com.sap.dbtech.rte.comm.BasicSocketComm.receiveData(BasicSocketComm.java:577) at com.sap.dbtech.rte.comm.BasicSocketComm.receive(BasicSocketComm.java:666) at com.sap.dbtech.rte.comm.JdbcCommunication.execute(JdbcCommunication.java:41) at com.sap.dbtech.jdbc.ConnectionSapDB.execute(ConnectionSapDB.java:536) - locked <0x00002aab1ed9d560> (a com.sap.dbtech.jdbc.ConnectionSapDB) at com.sap.dbtech.jdbc.ConnectionSapDB.execute(ConnectionSapDB.java:461) at com.sap.dbtech.jdbc.ConnectionSapDB.doConnect(ConnectionSapDB.java:398) at com.sap.dbtech.jdbc.ConnectionSapDB.<init>(ConnectionSapDB.java:109) at com.sap.dbtech.jdbc.DriverSapDB.connect(DriverSapDB.java:222) - locked <0x00002aaabc74ade0> (a com.sap.dbtech.jdbc.DriverSapDB) at org.apache.tomcat.dbcp.dbcp.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:38) at org.apache.tomcat.dbcp.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:294) - locked <0x00002aaabc896988> (a org.apache.tomcat.dbcp.dbcp.PoolableConnectionFactory) at org.apache.tomcat.dbcp.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:974) at org.apache.tomcat.dbcp.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:96) at org.apache.tomcat.dbcp.dbcp.BasicDataSource.getConnection(BasicDataSource.java:880) at org.exolab.castor.jdo.engine.DatabaseRegistry.createConnection(DatabaseRegistry.java:399) at org.exolab.castor.jdo.engine.TransactionContextImpl.getConnection(TransactionContextImpl.java:203) at org.exolab.castor.persist.TransactionContext.query(TransactionContext.java:644) - locked <0x00002aab1e8d9348> (a org.exolab.castor.jdo.engine.TransactionContextImpl) at org.exolab.castor.jdo.engine.OQLQueryImpl.execute(OQLQueryImpl.java:458) at org.exolab.castor.jdo.engine.OQLQueryImpl.execute(OQLQueryImpl.java:414) at com.supridatta.bean.DataPersist.consulta(DataPersist.java:536)
and here is the thread at step 3:
java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.tomcat.dbcp.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:294) - waiting to lock <0x00002aaabc896988> (a org.apache.tomcat.dbcp.dbcp.PoolableConnectionFactory) at org.apache.tomcat.dbcp.pool.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:974) at org.apache.tomcat.dbcp.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:96) at org.apache.tomcat.dbcp.dbcp.BasicDataSource.getConnection(BasicDataSource.java:880) at org.exolab.castor.jdo.engine.DatabaseRegistry.createConnection(DatabaseRegistry.java:399) at org.exolab.castor.jdo.engine.TransactionContextImpl.getConnection(TransactionContextImpl.java:203) at org.exolab.castor.persist.TransactionContext.query(TransactionContext.java:644) - locked <0x00002aab1e898f98> (a org.exolab.castor.jdo.engine.TransactionContextImpl) at org.exolab.castor.jdo.engine.OQLQueryImpl.execute(OQLQueryImpl.java:458) at org.exolab.castor.jdo.engine.OQLQueryImpl.execute(OQLQueryImpl.java:414) at com.supridatta.bean.DataPersist.consulta(DataPersist.java:536)
I inspected the database side, still really running, database results comes, but without releasing the connection, and if i wait the time or no user need a new connection, i never get thread blockeds, appears that MaxDB locks all connections if the newly created connection executes some SQL after acquiring that connection.
I see some blocks too at java finalizer, where one thread running is stucked getting a connection.
all this is just guess, maybe I'm wrong, but for now i will end this thread as we need see how this system will perform with all updates made.
best regards.
Clóvis