Mantis Bugtracker
  

Viewing Issue Advanced Details Jump to Notes ] View Simple ] Issue History ] Print ]
ID Category Severity Reproducibility Date Submitted Last Update
0002721 [Quercus] major sometimes 06-06-08 11:33 09-08-08 14:18
Reporter paulberto View Status public  
Assigned To ferg
Priority normal Resolution fixed Platform
Status closed   OS
Projection none   OS Version
ETA none Fixed in Version 3.2.1 Product Version 3.1.6
  Product Build
Summary 0002721: mysql connection pool connections are not being put back into the pool when used in PHP (quercus)
Description I had to implement a hack by adding max-active-time to the database parameters in resin-web.xml -- OTHERWISE the connections would hang in open state forever. I can see that they are finished because in mysql i can see the same database connections IDLE.

So right now -- i get a whole lot of these in my logs:
[21:07:27.640] closing pool item from active timeout:PoolItem[jdbc/cam,164,ManagedConnectionImpl]
[21:07:42.701] closing pool item from active timeout:PoolItem[jdbc/cam,296914,ManagedConnectionImpl]

Obviously because it is hitting the max-active-time of 15 seconds which is high .. I wana remove this workaround.
Steps To Reproduce
Additional Information Ended up rewriting all the db calls in java and calling them from a quercus module which fixed a lot of the issues .. also reinforcing the fact that there is a serious bug with php/quercus/mysql.

using the recommended mysql j/connector version 3.1.14 -- also tried the latest version 5.x with no success.

Also -- just to mention -- this is not happening all the time-- only under load.. IE, i am unable to reproduce it with a simple test ... the connections do get put back in the pool with a simple test. Just under load is a problem.



Attached Files

- Relationships

- Notes
(0003163)
paulberto
06-10-08 15:28

This problem is of significant nature. All I see in my logs are:

[01:18:08.313] com.caucho.quercus.QuercusException: java.io.InterruptedIOException: timeout fd=963 errno=11
[01:18:08.313]
[01:18:08.313] at com.caucho.quercus.program.TextStatement.execute(TextStatement.java:69)
[01:18:08.313] at com.caucho.quercus.program.QuercusProgram.execute(QuercusProgram.java:272)
[01:18:08.313] at com.caucho.quercus.page.InterpretedPage.execute(InterpretedPage.java:70)
[01:18:08.313] at com.caucho.quercus.env.Env.include(Env.java:3735)
[01:18:08.313] at com.caucho.quercus.expr.IncludeExpr.eval(IncludeExpr.java:86)
[01:18:08.313] at com.caucho.quercus.program.ExprStatement.execute(ExprStatement.java:64)
[01:18:08.313] at com.caucho.quercus.program.BlockStatement.execute(BlockStatement.java:105)
[01:18:08.313] at com.caucho.quercus.program.QuercusProgram.execute(QuercusProgram.java:272)
[01:18:08.313] at com.caucho.quercus.page.InterpretedPage.execute(InterpretedPage.java:70)
[01:18:08.313] at com.caucho.quercus.page.QuercusPage.executeTop(QuercusPage.java:119)
[01:18:08.313] at com.caucho.quercus.servlet.ResinQuercusServlet.service(ResinQuercusServlet.java:149)
[01:18:08.313] at com.caucho.quercus.servlet.QuercusServlet.service(QuercusServlet.java:355)
[01:18:08.313] at javax.servlet.http.HttpServlet.service(HttpServlet.java:91)
[01:18:08.313] at com.caucho.server.dispatch.ServletFilterChain.doFilter(ServletFilterChain.java:103)
[01:18:08.313] at com.caucho.server.cache.CacheFilterChain.doFilter(CacheFilterChain.java:150)
[01:18:08.313] at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:187)
[01:18:08.313] at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:266)
[01:18:08.313] at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:270)
[01:18:08.313] at com.caucho.server.port.TcpConnection.run(TcpConnection.java:678)
[01:18:08.313] at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:721)
[01:18:08.313] at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:643)
[01:18:08.313] at java.lang.Thread.run(Thread.java:619)
[01:18:08.313] Caused by: java.io.InterruptedIOException: timeout fd=963 errno=11
[01:18:08.313]
[01:18:08.313] at com.caucho.vfs.JniSocketImpl.writeNative(Native Method)
[01:18:08.313] at com.caucho.vfs.JniSocketImpl.write(JniSocketImpl.java:288)
[01:18:08.313] at com.caucho.vfs.JniStream.write(JniStream.java:124)
[01:18:08.313] at com.caucho.vfs.WriteStream.nextBuffer(WriteStream.java:327)
[01:18:08.313] at com.caucho.server.connection.ResponseStream.writeNext(ResponseStream.java:480)
[01:18:08.313] at com.caucho.server.connection.ToByteResponseStream.write(ToByteResponseStream.java:336)
[01:18:08.313] at com.caucho.vfs.VfsStream.write(VfsStream.java:201)
[01:18:08.313] at com.caucho.vfs.WriteStream.print(WriteStream.java:553)
[01:18:08.313] at com.caucho.vfs.WriteStream.print(WriteStream.java:631)
[01:18:08.313] at com.caucho.quercus.program.TextStatement.execute(TextStatement.java:63)
[01:18:08.313] ... 21 more
[01:18:08.702] java.io.InterruptedIOException: timeout fd=1019 errno=11
[01:18:08.702]
[01:18:08.702] at com.caucho.vfs.JniSocketImpl.writeNative(Native Method)
[01:18:08.702] at com.caucho.vfs.JniSocketImpl.write(JniSocketImpl.java:288)
[01:18:08.702] at com.caucho.vfs.JniStream.write(JniStream.java:124)
[01:18:08.702] at com.caucho.vfs.WriteStream.flushBuffer(WriteStream.java:393)
[01:18:08.702] at com.caucho.server.connection.AbstractHttpResponse.finish(AbstractHttpResponse.java:2201)
[01:18:08.702] at com.caucho.server.connection.AbstractHttpResponse.close(AbstractHttpResponse.java:279)
[01:18:08.702] at com.caucho.server.webapp.RequestDispatcherImpl.forward(RequestDispatcherImpl.java:286)
[01:18:08.702] at com.caucho.server.webapp.RequestDispatcherImpl.forward(RequestDispatcherImpl.java:108)
[01:18:08.702] at com.caucho.server.dispatch.ForwardFilterChain.doFilter(ForwardFilterChain.java:84)
[01:18:08.702] at com.caucho.server.cache.CacheFilterChain.doFilter(CacheFilterChain.java:150)
[01:18:08.702] at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:187)
[01:18:08.702] at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:266)
[01:18:08.702] at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:270)
[01:18:08.702] at com.caucho.server.port.TcpConnection.run(TcpConnection.java:678)
[01:18:08.702] at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:721)
[01:18:08.702] at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:643)
[01:18:08.702] at java.lang.Thread.run(Thread.java:619)
[01:18:09.448] closing pool item from active timeout:PoolItem[jdbc/cam,1037098,ManagedConnectionImpl]
[01:18:09.448] closing pool item from active timeout:PoolItem[jdbc/cam,1037096,ManagedConnectionImpl]
[01:18:09.448] closing pool item from active timeout:PoolItem[jdbc/cam,1037072,ManagedConnectionImpl]
[01:18:09.448] closing pool item from active timeout:PoolItem[jdbc/cam,1036735,ManagedConnectionImpl]
[01:18:09.448] closing pool item from active timeout:PoolItem[jdbc/cam,1036733,ManagedConnectionImpl]
... thousands of times

This is happening only from quercus code ....... Please advise ... At this point it seems that quercus is not fit for any production environment. Please see my notes above .. Perhaps it is due to some other error while processing the php page and then the db connection never gets put back into the pool at the end.. we tried everything including forcing mysql_close().

Unsure if those interuption exceptions have anything to do with it .. This is a very heavily loaded system. We've been using quercus for few weeks now and this problem has been here since day one.

Please advise!!!!
 
(0003409)
ferg
09-08-08 14:18

Refactored the database code to avoid the closing issue.

That log isn't a problem. That's just a normal browser disconnect in the middle of a request.

 

- Issue History
Date Modified Username Field Change
06-06-08 11:33 paulberto New Issue
06-06-08 13:36 nam Project Resin => Quercus
06-10-08 15:28 paulberto Note Added: 0003163
09-08-08 14:18 ferg Note Added: 0003409
09-08-08 14:18 ferg Assigned To  => ferg
09-08-08 14:18 ferg Status new => closed
09-08-08 14:18 ferg Resolution open => fixed
09-08-08 14:18 ferg Fixed in Version  => 3.2.1
09-08-08 14:18 ferg Additional Information Updated


Mantis 1.0.0rc3[^]
Copyright © 2000 - 2005 Mantis Group
33 total queries executed.
28 unique queries executed.
Powered by Mantis Bugtracker