I am profiling a Tomcat 8.5 application which uses DBCP as standard pool for Neo4j JDBC Driver connections.
What is strange is when I run Yourkit in 'CPU Profiling' mode, I can see in 'Performance charts' that a lot of sockets are opened when database connections are opened, but these sockets are not closed when database connections are closed. This behavior is confirmed by lsof or ls /proc/my_tomcat_pid/fd | wc -l commands, where I can see file descriptors growing and growing for my application.
However, when I don't run Yourkit with 'CPU Profiling' mode, or when I stop it, the number of sockets opened/closed is stable, and behavior is also confirmed by lsof or ls /proc/my_tomcat_pid/fd | wc -l commands.
Is it a normal behavior and should I really worry about my application unreleasing Neo4j JDBC connections ?
I am using Yourkit 2016.02 version.
Thanks by advance.
Yourkit opening sockets in CPU Profiling mode ?
-
- Posts: 6172
- Joined: Wed Aug 11, 2004 8:37 am
Re: Yourkit opening sockets in CPU Profiling mode ?
Hi,
We are not aware of this behavior.
Version Yourkit 2016.02 is not supported. Please use the latest version 2017.02 instead.
If this problem is reproducible with version 2017.02, could you please provide a snapshot demonstrating it. You may send the snapshot (a download link) and the output of lsof to [email protected]
Best regards,
Anton
We are not aware of this behavior.
Version Yourkit 2016.02 is not supported. Please use the latest version 2017.02 instead.
If this problem is reproducible with version 2017.02, could you please provide a snapshot demonstrating it. You may send the snapshot (a download link) and the output of lsof to [email protected]
Best regards,
Anton
-
- Posts: 3
- Joined: Fri Jan 26, 2018 9:50 pm
Re: Yourkit opening sockets in CPU Profiling mode ?
Hi,
I have downloaded latest version of Yourkit Kava Profiler and I am able to reproduce the problem with a sample code. I have sent an email to [email protected] with a snapshot download link.
Actually the code is really simple : I have a servlet which initialize in a static block a connection to the Tomcat DBCP pool, in order to get connections to Neo4j database via its JDBC driver. The problem is that every time I try to get a connection, a new socket is created (and not closed). I call the servlet with a simple curl command :
.
And I watch the number of sockets created for neo4j db (default port for bolt driver 7687) :
The first problem that I can see is that 'Performance charts' and 'Events' dashboards show contradictory informations for Socket open/close. 'Performance chart' show that new sockets are opened and then closed, but in 'Events' we see that open sockets are accumulating. And lsof shows that sockets created are increasing.
After deep investigation, I found out that disabling 'Database' and 'Database LW' probes in the profiler removes the open sockets creation, and the lsof command shows stable number of sockets created. The open sockets creation is back again when I enable again 'Database' probe. After some debugging, I found out some Yourkit instrumentation classes between Tomcat DBCP Pool getConnection method call, and Neo4j JDBC driver classes :
I wonder if the Yourkit classes are responsible of the Tomcat DBCP pool bypass because it is like we create a new connection every time I ask for it, which is not normal.
Based on these informations, I would like to know if the sockets creation are a consequence of the profiler use, or a real application problem. I can provide the sample code and the Tomcat server libraries if needed.
Thanks by advance.
I have downloaded latest version of Yourkit Kava Profiler and I am able to reproduce the problem with a sample code. I have sent an email to [email protected] with a snapshot download link.
Actually the code is really simple : I have a servlet which initialize in a static block a connection to the Tomcat DBCP pool, in order to get connections to Neo4j database via its JDBC driver. The problem is that every time I try to get a connection, a new socket is created (and not closed). I call the servlet with a simple curl command :
Code: Select all
watch -n 2 curl -v http://localhost:8080/socket
And I watch the number of sockets created for neo4j db (default port for bolt driver 7687) :
Code: Select all
watch 'lsof -p myTomcatPID | grep "localhost:7687" | wc -l'
After deep investigation, I found out that disabling 'Database' and 'Database LW' probes in the profiler removes the open sockets creation, and the lsof command shows stable number of sockets created. The open sockets creation is back again when I enable again 'Database' probe. After some debugging, I found out some Yourkit instrumentation classes between Tomcat DBCP Pool getConnection method call, and Neo4j JDBC driver classes :
Code: Select all
sun.nio.ch.SocketChannelImpl.connect(SocketAddress) SocketChannelImpl.java
sun.nio.ch.SocketAdaptor.connect(SocketAddress, int) SocketAdaptor.java:102
org.neo4j.driver.internal.net.ChannelFactory.connect(SocketChannel, BoltServerAddress, int) ChannelFactory.java:64
org.neo4j.driver.internal.net.ChannelFactory.create(BoltServerAddress, SecurityPlan, int, Logger) ChannelFactory.java:41
org.neo4j.driver.internal.net.SocketClient.start() SocketClient.java:124
org.neo4j.driver.internal.net.SocketConnection.startSocketClient() SocketConnection.java:92
org.neo4j.driver.internal.net.SocketConnection.<init>(BoltServerAddress, SecurityPlan, int, Logging) SocketConnection.java:67
org.neo4j.driver.internal.net.SocketConnector.createConnection(BoltServerAddress, SecurityPlan, int, Logging) SocketConnector.java:77
org.neo4j.driver.internal.net.SocketConnector.connect(BoltServerAddress) SocketConnector.java:50
org.neo4j.driver.internal.net.pooling.SocketConnectionPool$ConnectionSupplier.get() SocketConnectionPool.java:204
org.neo4j.driver.internal.net.pooling.SocketConnectionPool$ConnectionSupplier.get() SocketConnectionPool.java:186
org.neo4j.driver.internal.net.pooling.BlockingPooledConnectionQueue.acquire(Supplier) BlockingPooledConnectionQueue.java:96
org.neo4j.driver.internal.net.pooling.SocketConnectionPool.acquireConnection(BoltServerAddress, BlockingPooledConnectionQueue) SocketConnectionPool.java:137
org.neo4j.driver.internal.net.pooling.SocketConnectionPool.acquire(BoltServerAddress) SocketConnectionPool.java:76
org.neo4j.driver.internal.DirectConnectionProvider.acquireConnection(AccessMode) DirectConnectionProvider.java:45
org.neo4j.driver.internal.NetworkSession.acquireConnection(AccessMode) NetworkSession.java:340
org.neo4j.driver.internal.NetworkSession.beginTransaction(AccessMode) NetworkSession.java:288
org.neo4j.driver.internal.NetworkSession.beginTransaction() NetworkSession.java:175
org.neo4j.jdbc.bolt.BoltDriver.connect(String, Properties) BoltDriver.java:67
org.neo4j.jdbc.Driver.connect(String, Properties) Driver.java:55
java.sql.DriverManager.getConnection(String, Properties, Class) DriverManager.java:664
java.sql.DriverManager.getConnection(String, Properties) DriverManager.java:208
org.neo4j.jdbc.bolt.BoltDatabaseMetaData.<init>(BoltConnection, boolean) BoltDatabaseMetaData.java:51
org.neo4j.jdbc.bolt.BoltDatabaseMetaData.<init>(BoltConnection) BoltDatabaseMetaData.java:42
org.neo4j.jdbc.bolt.BoltConnection.getMetaData() BoltConnection.java:82
org.neo4j.jdbc.bolt.BoltConnection.getMetaData() BoltConnection.java:35
org.apache.tomcat.dbcp.dbcp2.DelegatingConnection.getMetaData() DelegatingConnection.java:421 <2 recursive calls>
com.yourkit.runtime.CallbackProxyImpl.callObjectMethod0(Class, Object, long) CallbackProxyImpl.java:91
com.yourkit.probes.ReflectionUtil.callMethod0(Class, Object, String, CallStatus) ReflectionUtil.java:72
com.yourkit.probes.ReflectionUtil.callMethod0(Object, String) ReflectionUtil.java:117
com.yourkit.probes.builtin.Databases.getConnectionURL(Object) Databases.java:772
com.yourkit.probes.builtin.Databases$1.retrieveResourceName(Object) Databases.java:60
com.yourkit.probes.ResourceRegistry.getResourceName(String, Object) ResourceRegistry.java:303
com.yourkit.probes.ResourceRegistry.openOnExitImpl(long, String, Object, Object, Throwable, FailedEventPolicy) ResourceRegistry.java:150
com.yourkit.probes.MasterResourceRegistry.openOnExit(long, String, Object, Throwable, FailedEventPolicy) MasterResourceRegistry.java:39
com.yourkit.probes.builtin.Databases$DataSource_or_PooledConnection_getConnection_Probe.onExit(long, Object, Object, Throwable) Databases.java:276
org.apache.tomcat.dbcp.dbcp2.PoolingDataSource.getConnection() PoolingDataSource.java:138
org.apache.tomcat.dbcp.dbcp2.BasicDataSource.getConnection() BasicDataSource.java:1543
com.myapp.web.MyServlet.doGet(HttpServletRequest, HttpServletResponse) MyServlet.java:31
javax.servlet.http.HttpServlet.service(HttpServletRequest, HttpServletResponse) HttpServlet.java:635
javax.servlet.http.HttpServlet.service(ServletRequest, ServletResponse) HttpServlet.java:742
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:231
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.apache.tomcat.websocket.server.WsFilter.doFilter(ServletRequest, ServletResponse, FilterChain) WsFilter.java:52
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.apache.catalina.core.StandardWrapperValve.invoke(Request, Response) StandardWrapperValve.java:199
org.apache.catalina.core.StandardContextValve.invoke(Request, Response) StandardContextValve.java:96
org.apache.catalina.authenticator.AuthenticatorBase.invoke(Request, Response) AuthenticatorBase.java:478
org.apache.catalina.core.StandardHostValve.invoke(Request, Response) StandardHostValve.java:140
org.apache.catalina.valves.ErrorReportValve.invoke(Request, Response) ErrorReportValve.java:81
org.apache.catalina.valves.AbstractAccessLogValve.invoke(Request, Response) AbstractAccessLogValve.java:650
org.apache.catalina.core.StandardEngineValve.invoke(Request, Response) StandardEngineValve.java:87
org.apache.catalina.connector.CoyoteAdapter.service(Request, Response) CoyoteAdapter.java:342
org.apache.coyote.http11.Http11Processor.service(SocketWrapperBase) Http11Processor.java:803
org.apache.coyote.AbstractProcessorLight.process(SocketWrapperBase, SocketEvent) AbstractProcessorLight.java:66
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(SocketWrapperBase, SocketEvent) AbstractProtocol.java:868
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun() NioEndpoint.java:1459
org.apache.tomcat.util.net.SocketProcessorBase.run() SocketProcessorBase.java:49
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker) ThreadPoolExecutor.java:1149
java.util.concurrent.ThreadPoolExecutor$Worker.run() ThreadPoolExecutor.java:624
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run() TaskThread.java:61
java.lang.Thread.run() Thread.java:748
Based on these informations, I would like to know if the sockets creation are a consequence of the profiler use, or a real application problem. I can provide the sample code and the Tomcat server libraries if needed.
Thanks by advance.
-
- Posts: 3
- Joined: Fri Jan 26, 2018 9:50 pm
Re: Yourkit opening sockets in CPU Profiling mode ?
I forgot to mention that of course in the sample code the getConnection call is wrapped in a try resources block to auto close it.
-
- Posts: 6172
- Joined: Wed Aug 11, 2004 8:37 am
Re: Yourkit opening sockets in CPU Profiling mode ?
We've answered your email.
-
- Posts: 6172
- Joined: Wed Aug 11, 2004 8:37 am
Re: Yourkit opening sockets in CPU Profiling mode ?
FYI: v2017.02 build 75 with the fix is available for download.