cancel
Showing results for 
Search instead for 
Did you mean: 

JDBC Blocks again when try to get new connections.

Former Member
0 Kudos

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?

Accepted Solutions (1)

Accepted Solutions (1)

lbreddemann
Active Contributor
0 Kudos

>

> 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

Former Member
0 Kudos

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

lbreddemann
Active Contributor
0 Kudos

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.

Former Member
0 Kudos

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

Answers (0)