on 11-08-2010 1:41 PM
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?
>
> 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
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.
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
User | Count |
---|---|
83 | |
24 | |
12 | |
9 | |
7 | |
6 | |
5 | |
5 | |
5 | |
4 |
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.