Oops. Stupid user error. My thread dumper method was dumping each thread trace as many times as there were lines in the thread trace. So a 65-line trace created 65 copies... What a mess I've made.
On Fri, Jul 31, 2015 at 5:01 PM, Mike Kienenberger <mkien...@gmail.com> wrote: > ] > So I'm reviewing a dump of the threads when I run out of connections > in my connection pool, and I think I've found the problem. > > I don't understand what's going on. While the oracle driver is > reading data, some kind of thread wrapper > [org.apache.tomcat.util.threads.TaskThread$WrappingRunnable] inside of > tomcat is triggered, and this re-executes the entire servlet stack > again. It almost seems as if the oracle connection to the database > is hitting the tomcat server instead of the database. > > This is not the only thread displaying this behaviour. The entire > thread dump was 100,000 lines and this thread dump was only 4300 lines > long, so it's a mind-boggling amount of data to sift through. > > Here's the start... > > [...] > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) > at > org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) > at java.lang.Thread.run(Thread.java:745) > [repeats at least 65 more times...] > [And here we start repeating again...^^^^....] > at java.net.SocketInputStream.socketRead0(Native Method) > at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) > at java.net.SocketInputStream.read(SocketInputStream.java:170) > at java.net.SocketInputStream.read(SocketInputStream.java:141) > at oracle.net.ns.Packet.receive(Packet.java:300) > at oracle.net.ns.DataPacket.receive(DataPacket.java:106) > at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:315) > at oracle.net.ns.NetInputStream.read(NetInputStream.java:260) > at oracle.net.ns.NetInputStream.read(NetInputStream.java:185) > at oracle.net.ns.NetInputStream.read(NetInputStream.java:102) > at > oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:124) > at > oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:80) > at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1137) > at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:290) > at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:192) > at oracle.jdbc.driver.T4C7Ocommoncall.doOCOMMIT(T4C7Ocommoncall.java:75) > at oracle.jdbc.driver.T4CConnection.doCommit(T4CConnection.java:617) > at > oracle.jdbc.driver.PhysicalConnection.commit(PhysicalConnection.java:3901) > at > oracle.jdbc.driver.PhysicalConnection.commit(PhysicalConnection.java:3907) > at > org.apache.cayenne.conn.ConnectionWrapper.commit(ConnectionWrapper.java:136) > at > org.apache.cayenne.access.InternalTransaction.processCommit(InternalTransaction.java:73) > at > org.apache.cayenne.access.ExternalTransaction.commit(ExternalTransaction.java:97) > at > org.apache.cayenne.access.DataDomain.runInTransaction(DataDomain.java:878) > at > org.apache.cayenne.access.DataDomain.onSyncNoFilters(DataDomain.java:814) > at > org.apache.cayenne.access.DataDomain$DataDomainSyncFilterChain.onSync(DataDomain.java:1031) > at org.apache.cayenne.access.DataDomain.onSync(DataDomain.java:785) > at > org.apache.cayenne.access.DataContext.flushToParent(DataContext.java:817) > at > org.apache.cayenne.access.DataContext.commitChanges(DataContext.java:756) > at > com.gvea.applications.epay.cayenne.BaseDAOCayenne.update(BaseDAOCayenne.java:338) > at > com.gvea.applications.epay.cayenne.EbppDAOCayenne.update(EbppDAOCayenne.java:84) > at > com.gvea.ebpp.business.CayennePageStateLogger.log(CayennePageStateLogger.java:42) > at > com.gvea.struts.ebpp.framework.Application.onDoRequest(Application.java:302) > at > com.gvea.servlet.pageStateCache.PageStateManager.onDoRequest(PageStateManager.java:648) > at > com.gvea.servlet.pageStateCache.PageStateCacheServlet.doRequest(PageStateCacheServlet.java:174) > at > com.gvea.servlet.pageStateCache.PageStateCacheServlet.doPost(PageStateCacheServlet.java:131) > at javax.servlet.http.HttpServlet.service(HttpServlet.java:648) > at javax.servlet.http.HttpServlet.service(HttpServlet.java:729) > at > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:291) > at > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) > at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) > at > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) > at > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) > at com.gvea.servlet.filter.LoggingFilter.doFilter(LoggingFilter.java:66) > at > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) > at > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) > at > fr.xebia.servlet.filter.XForwardedFilter.doFilter(XForwardedFilter.java:899) > at > fr.xebia.servlet.filter.XForwardedFilter.doFilter(XForwardedFilter.java:915) > at > org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) > at > org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) > at > org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) > at > org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106) > at > org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502) > at > org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142) > at > org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) > at > org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:610) > at > org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88) > at > org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:518) > at > org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091) > at > org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:668) > at > org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) > at > org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1517) > at > org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1474) > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) > at > org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) > at java.lang.Thread.run(Thread.java:745) > > [Start of the thread above] > > > On Fri, Jun 12, 2015 at 11:21 AM, Mike Kienenberger <mkien...@gmail.com> > wrote: >> Hmm. I just remembered that I have a second infrequently-accessed >> database which is also configured. >> >> So I'd really have 3 runtimes * 2 connection pools, so that explains 6 of >> the 8. >> >> Not sure where the other two are from unless I have a 4th runtime that >> I've overlooked. >> >> >> On Cayenne 4, yes, that's one of my goals this summer -- upgrade to >> Cayenne 4. Probably won't happen until July, though. >> >> >> I'm going to add something that will dump all threads when this >> exception is hit. >> >> On Fri, Jun 12, 2015 at 11:15 AM, Andrus Adamchik >> <and...@objectstyle.org> wrote: >>> >>>> On Jun 12, 2015, at 6:09 PM, Mike Kienenberger <mkien...@gmail.com> wrote: >>>> >>>> And, interestingly enough, I only have 8 "PoolManagerCleanup" threads, >>>> and not the 9 that I expected. Maybe they are create-on-demand and >>>> one of my runtimes hasn't needed it yet? >>> >>> There should be 3 actually. One per PoolManager, not one per connection. So >>> something may be going on there. >>> >>> FWIW 4.0.M3 (master branch) has a completely new non-blocking alternative >>> to PoolManager. The cleanup process is also more sane there. >>> >>> Andrus >>>
