search

tranjith / javamelody

Automatically exported from code.google.com/p/javamelody
0 stars 0 forks source link

Tomcat manager undeploy hangs on javamelody #446

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
We have 3 apps on same tomcat (test server for continuous integration) with 
javamelody dependencies. All apps are redeployed one-by-one. First one 
redeploys just fine, on second one undeploy hangs. I dumped the threads and 
notices something like this:

"http-bio-8888-exec-20" - Thread t@59
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:145)
    at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:114)
    at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
    at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:274)
    at org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:269)
    at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:108)
    at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:66)
    at org.postgresql.jdbc2.AbstractJdbc2Connection.<init>(AbstractJdbc2Connection.java:125)
    at org.postgresql.jdbc3.AbstractJdbc3Connection.<init>(AbstractJdbc3Connection.java:30)
    at org.postgresql.jdbc3g.AbstractJdbc3gConnection.<init>(AbstractJdbc3gConnection.java:22)
    at org.postgresql.jdbc4.AbstractJdbc4Connection.<init>(AbstractJdbc4Connection.java:30)
    at org.postgresql.jdbc4.Jdbc4Connection.<init>(Jdbc4Connection.java:24)
    at org.postgresql.Driver.makeConnection(Driver.java:393)
    at org.postgresql.Driver.connect(Driver.java:267)
    at org.apache.tomcat.dbcp.dbcp.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:38)
    at org.apache.tomcat.dbcp.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:582)
    at org.apache.tomcat.dbcp.dbcp.BasicDataSource.validateConnectionFactory(BasicDataSource.java:1556)
    at org.apache.tomcat.dbcp.dbcp.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:1545)
    at org.apache.tomcat.dbcp.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:1388)
    - locked <16d5144> (a org.apache.tomcat.dbcp.dbcp.BasicDataSource)
    at org.apache.tomcat.dbcp.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at net.bull.javamelody.JdbcWrapper$3.invoke(JdbcWrapper.java:765)
    at net.bull.javamelody.JdbcWrapper$DelegatingInvocationHandler.invoke(JdbcWrapper.java:285)
    at com.sun.proxy.$Proxy581.getConnection(Unknown Source)
    at net.bull.javamelody.JavaInformations.buildDataBaseVersion(JavaInformations.java:386)
    at net.bull.javamelody.JavaInformations.<init>(JavaInformations.java:174)
    at net.bull.javamelody.HtmlController.writeHtmlToLastShutdownFile(HtmlController.java:313)
    at net.bull.javamelody.MonitoringController.writeHtmlToLastShutdownFile(MonitoringController.java:269)
    at net.bull.javamelody.FilterContext.destroy(FilterContext.java:357)
    at net.bull.javamelody.MonitoringFilter.destroy(MonitoringFilter.java:137)
    at org.apache.catalina.core.ApplicationFilterConfig.release(ApplicationFilterConfig.java:313)
    at org.apache.catalina.core.StandardContext.filterStop(StandardContext.java:4866)
    - locked <1f26bfe> (a java.util.HashMap)
    at org.apache.catalina.core.StandardContext.stopInternal(StandardContext.java:5679)
    - locked <5960f9> (a org.apache.catalina.core.StandardContext)
    at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:232)
    - locked <5960f9> (a org.apache.catalina.core.StandardContext)
    at org.apache.catalina.manager.ManagerServlet.undeploy(ManagerServlet.java:1391)
    at org.apache.catalina.manager.ManagerServlet.doGet(ManagerServlet.java:394)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:620)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.catalina.filters.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:108)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:612)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1070)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
    - locked <901ed4> (a org.apache.tomcat.util.net.SocketWrapper)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:744)

   Locked ownable synchronizers:
    - locked <6314b0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

Now this shows that manager undeploy tries to undeploy app and it hangs on 
javamelody trying to do something with database connection... any clues or 
hints what is going?

Original issue reported on code.google.com by maciej.l...@gmail.com on 26 Nov 2014 at 12:34

GoogleCodeExporter commented 9 years ago 
above thread hangs forever, but with state RUNNABLE....

Original comment by maciej.l...@gmail.com on 26 Nov 2014 at 12:42

GoogleCodeExporter commented 9 years ago 
there is also second thread related to "undeploy":

"ContainerBackgroundProcessor[StandardEngine[Catalina]]" - Thread t@30
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:145)
    at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:114)
    at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
    at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:274)
    at org.postgresql.core.v3.ConnectionFactoryImpl.doAuthentication(ConnectionFactoryImpl.java:269)
    at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:108)
    at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:66)
    at org.postgresql.jdbc2.AbstractJdbc2Connection.<init>(AbstractJdbc2Connection.java:125)
    at org.postgresql.jdbc3.AbstractJdbc3Connection.<init>(AbstractJdbc3Connection.java:30)
    at org.postgresql.jdbc3g.AbstractJdbc3gConnection.<init>(AbstractJdbc3gConnection.java:22)
    at org.postgresql.jdbc4.AbstractJdbc4Connection.<init>(AbstractJdbc4Connection.java:30)
    at org.postgresql.jdbc4.Jdbc4Connection.<init>(Jdbc4Connection.java:24)
    at org.postgresql.Driver.makeConnection(Driver.java:393)
    at org.postgresql.Driver.connect(Driver.java:267)
    at org.apache.tomcat.dbcp.dbcp.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:38)
    at org.apache.tomcat.dbcp.dbcp.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:582)
    at org.apache.tomcat.dbcp.dbcp.BasicDataSource.validateConnectionFactory(BasicDataSource.java:1556)
    at org.apache.tomcat.dbcp.dbcp.BasicDataSource.createPoolableConnectionFactory(BasicDataSource.java:1545)
    at org.apache.tomcat.dbcp.dbcp.BasicDataSource.createDataSource(BasicDataSource.java:1388)
    - locked <1d80e55> (a org.apache.tomcat.dbcp.dbcp.BasicDataSource)
    at org.apache.tomcat.dbcp.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at net.bull.javamelody.JdbcWrapper$3.invoke(JdbcWrapper.java:765)
    at net.bull.javamelody.JdbcWrapper$DelegatingInvocationHandler.invoke(JdbcWrapper.java:285)
    at com.sun.proxy.$Proxy581.getConnection(Unknown Source)
    at net.bull.javamelody.JavaInformations.buildDataBaseVersion(JavaInformations.java:386)
    at net.bull.javamelody.JavaInformations.<init>(JavaInformations.java:174)
    at net.bull.javamelody.HtmlController.writeHtmlToLastShutdownFile(HtmlController.java:313)
    at net.bull.javamelody.MonitoringController.writeHtmlToLastShutdownFile(MonitoringController.java:269)
    at net.bull.javamelody.FilterContext.destroy(FilterContext.java:357)
    at net.bull.javamelody.MonitoringFilter.destroy(MonitoringFilter.java:137)
    at org.apache.catalina.core.ApplicationFilterConfig.release(ApplicationFilterConfig.java:313)
    at org.apache.catalina.core.StandardContext.filterStop(StandardContext.java:4866)
    - locked <1951559> (a java.util.HashMap)
    at org.apache.catalina.core.StandardContext.stopInternal(StandardContext.java:5679)
    - locked <4d402d> (a org.apache.catalina.core.StandardContext)
    at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:232)
    - locked <4d402d> (a org.apache.catalina.core.StandardContext)
    at org.apache.catalina.core.ContainerBase.removeChild(ContainerBase.java:1028)
    at org.apache.catalina.startup.HostConfig.undeploy(HostConfig.java:1498)
    at org.apache.catalina.startup.HostConfig.checkResources(HostConfig.java:1425)
    - locked <acb1f4> (a org.apache.catalina.startup.HostConfig)
    at org.apache.catalina.startup.HostConfig.check(HostConfig.java:1646)
    at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:328)
    at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:117)
    at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:90)
    at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1374)
    at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1546)
    at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1556)
    at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1524)
    at java.lang.Thread.run(Thread.java:744)

   Locked ownable synchronizers:
    - None

Original comment by maciej.l...@gmail.com on 26 Nov 2014 at 12:47

GoogleCodeExporter commented 9 years ago 
What is going on is that, when the webapp is undeployed, javamelody writes a 
"last_shutdown.html" file with a report at that time.
For this, it gets informations such as database version. And in your case, the 
datasource needed to create a new connection. But that connection to your 
postgresql database was hanging for some time. Perhaps, it was because of a 
network issue.

Original comment by evernat@free.fr on 28 Nov 2014 at 4:40

GoogleCodeExporter commented 9 years ago 
yes I can see that, but the problem is that postgresql and database is on the 
same server, so there cannot be any network issues. also - datasource for 
javamelody is not configured any way (no myDataSource jndi/bean, no javamelody 
spring context loaded). So why it tries to connect database, what database 
exactly and why it hangs?

Original comment by maciej.l...@gmail.com on 29 Nov 2014 at 5:14

GoogleCodeExporter commented 9 years ago 
javamelody does not use a database to store data and it can't imagine alone the 
datasource and the postgresql database.
I suggest that you check your tomcat's configuration and webapp's 
configuration, you will certainly find a datasource. And this forgotten 
datasource is probably misconfigured so that it can't connect.

I am interested for your info, even to say that you will not have more info.

Original comment by evernat@free.fr on 9 Dec 2014 at 3:03

GoogleCodeExporter commented 9 years ago 
No response from the reporter, so resolving as incomplete/invalid.

I hope that you have found your datasource configuration to find a solution.

Original comment by evernat@free.fr on 13 Jan 2015 at 3:12

GoogleCodeExporter commented 9 years ago 
Sorry, I had no time to check your suggestions. Feel free to close the issue, 
if I find something new I will just reopen it.

Original comment by maciej.l...@gmail.com on 13 Jan 2015 at 3:14