search

neo4j / neo4j-jdbc

Official Neo4j JDBC Driver
http://neo4j.github.io/neo4j-jdbc/
Apache License 2.0
135 stars 53 forks source link

JDBC Driver ConnectionReadTimeoutException #721

Open rfontalva opened 2 months ago

rfontalva commented 2 months ago

Hello, I'm using the JDBC Driver to connect to my AuraDB instance from Denodo. Intermittently but consistently an error will occur with the following error message:

Received exception with message 'org.neo4j.driver.exceptions.ConnectionReadTimeoutException: Connection read timed out due to it taking longer than the server-supplied timeout value via configuration hint.' Received exception with message 'Connection read timed out due to it taking longer than the server-supplied timeout value via configuration hint.'

The error always happen after 60 seconds. I've modified the connection.timeout property to be 900000, but the error persists. Is there anything that can be modified to remove this timeout?

Thanks!

michael-simons commented 2 months ago

@rfontalva Thanks for your report and using the JDBC driver. Is there any more information you can provide, like the query, the amount of data and the approximately size of the data?

@injectives can you take a look, pls?

rfontalva commented 2 months ago

The problem with the issue being intermittent is that it doesn't always fail for the same query, though queries that fetch less data fail less often. Some queries have failed when trying to bring around 800.000 to 1M records, but they have also succeeded. What is constant is the timeout always happens after 60 seconds.

injectives commented 2 months ago

@rfontalva , thanks for reaching out.

I notice the org.neo4j.driver.exceptions.ConnectionReadTimeoutException is from the neo4j-java-driver project. Could you just let us know which version of JDBC driver you are using please?

rfontalva commented 2 months ago

Hi @injectives I'm using version 4.0.10

injectives commented 2 months ago

Just to explain the actual nature of this timeout, it indicates that the server stopped sending anything back within the timeout that it advised to the driver upon connection initialisation (assuming there is no other bug anywhere). The server timeout is documented here: https://neo4j.com/docs/bolt/current/appendix/connection-hints/#hint-recv-timeout-seconds

It would be useful to confirm this by enabling TRACE logging. Is there any chance you could do this assuming this issue happens reasonably consistently? We should get log entries similar to these:

S: SUCCESS
S: 0000
injectives commented 2 months ago

The newer 6.x JDBC driver allows overriding this timeout using the setNetworkTimeout method. While this is an option, it might be useful to find out if the server is actually struggling to respond within the given timeout as it might indicate a resource availability or some other issue.

rfontalva commented 2 months ago

Good, I can try updating to 6.0 to use this new method. Since this is not in a script, how would I set the value with a property instead of using a method? We only have this option available: image

injectives commented 2 months ago

As far as I am aware, setting it via properties is not currently supported. 🤔

injectives commented 2 months ago

I think it would be useful to see the TRACE logs. It sounds like the server-supplied timeout is 60 seconds. All the server has to do is to send NOOP chunks if it needs more time. We should be able to verify this from the logs.

rfontalva commented 2 months ago

You mean from the Neo4J server right? The thing is, when the error happens we only see the failure on the Denodo side, Neo4J doesn't seem to acknowledge that the timeout happened

rfontalva commented 2 months ago

The logs that we get from Denodo look like this: 359726835 [Access(329290)-195063-01.00-ddfmetadata_prod.bv_data_product] ERROR 2024-08-30T11:40:30.002 com.denodo.vdb.engine.wrapper.raw.jdbc.JDBCAccess [] - [*]E org.neo4j.driver.exceptions.ConnectionReadTimeoutException: Connection read timed out due to it taking longer than the server-supplied timeout value via configuration hint., idconnection=190426049

java.lang.RuntimeException: org.neo4j.driver.exceptions.ConnectionReadTimeoutException: Connection read timed out due to it taking longer than the server-supplied timeout value via configuration hint.

   at org.neo4j.jdbc.bolt.impl.BoltNeo4jConnectionImpl.initTransaction(BoltNeo4jConnectionImpl.java:356) ~[neo4j-jdbc-driver-4.0.10.jar:?]

   at org.neo4j.jdbc.bolt.impl.BoltNeo4jConnectionImpl.createStatement(BoltNeo4jConnectionImpl.java:241) ~[neo4j-jdbc-driver-4.0.10.jar:?]

   at org.neo4j.jdbc.bolt.impl.BoltNeo4jConnectionImpl.createStatement(BoltNeo4jConnectionImpl.java:229) ~[neo4j-jdbc-driver-4.0.10.jar:?]

   at org.apache.commons.dbcp2.DelegatingConnection.createStatement(DelegatingConnection.java:257) ~[commons-dbcp2.jar:2.9.0]

   at com.denodo.vdb.engine.wrapper.raw.jdbc.adapter.SQLPlugin.getStatement(Unknown Source) ~[denodo-vdp-server.jar:8.0.8]

   at com.denodo.vdb.engine.wrapper.raw.jdbc.JDBCAccess.a3(Unknown Source) ~[denodo-vdp-server.jar:8.0.8]

   at com.denodo.vdb.engine.wrapper.raw.jdbc.JDBCAccess.doRun(Unknown Source) ~[denodo-vdp-server.jar:8.0.8]

   at com.denodo.vdb.engine.wrapper.RawAccess.run(Unknown Source) ~[denodo-vdp-server.jar:8.0.8]

   at com.denodo.vdb.engine.thread.WorkWrapper.a3(Unknown Source) ~[denodo-vdp-server.jar:8.0.8]

   at com.denodo.vdb.engine.thread.ReusableThread.d3(Unknown Source) ~[denodo-vdp-server.jar:8.0.8]

   at com.denodo.vdb.engine.thread.ReusableThread.run(Unknown Source) ~[denodo-vdp-server.jar:8.0.8]

Caused by: org.neo4j.driver.exceptions.ConnectionReadTimeoutException: Connection read timed out due to it taking longer than the server-supplied timeout value via configuration hint.

   at org.neo4j.driver.internal.util.Futures.blockingGet(Futures.java:111) ~[neo4j-jdbc-driver-4.0.10.jar:?]

   at org.neo4j.driver.internal.InternalSession.beginTransaction(InternalSession.java:90) ~[neo4j-jdbc-driver-4.0.10.jar:?]

   at org.neo4j.driver.internal.InternalSession.beginTransaction(InternalSession.java:85) ~[neo4j-jdbc-driver-4.0.10.jar:?]

   at org.neo4j.jdbc.bolt.impl.BoltNeo4jConnectionImpl.initTransaction(BoltNeo4jConnectionImpl.java:353) ~[neo4j-jdbc-driver-4.0.10.jar:?]

   ... 10 more

   Suppressed: org.neo4j.driver.exceptions.ServiceUnavailableException: Connection to the database terminated. Connection read timed out due to it takin
injectives commented 2 months ago

Is it possible to set logging level to TRACE in Denodo somehow? As far as I know, JDBC 4.x driver uses Neo4j Java Driver internally and its logging is set to integrate with SLF4J.

rfontalva commented 2 months ago

Yes, I think so. Let me run some tests and share the logs with you again. I've also requested the AuraDB team the logs from their server and will share that when I have it.

injectives commented 2 months ago

Basically, we need the Neo4j Java Driver TRACE logs. I assume there should be a way of setting it via SLF4j in Denodo, but this needs checking.

injectives commented 2 months ago

I think checking the client logs would be a good place to start. We should be able to confirm if the server actually struggles to respond in time or if there is something else in the logs. If it is server, then AuraDB team might be able to advice further.

rfontalva commented 2 months ago

Hello, sorry for the delay in response. The logs don't have any information similar to the one shared in the documentation link above. It's a standard log4j output. neo4jdrivererror.log

I think that, if we were able to modify the connection.recv_timeout_seconds we should be able to fix this, but the AuraDB team says that this property is not configured in the neo4j.conf files, only seems to be in the driver. Is there a way to expose this property so we can overwrite it?

rfontalva commented 2 months ago

Hello team, reaching back as there hasn't been any updates on this subject. I enabled the trace logging in the client and this is the output received vdp4errorlogTRACE.log The first log is for a successfull query and the second one failed. I still don't understand where we should see an output like the one you shared in the docs.

Any ideas at which part of the neo4j.conf file the connection_recv_timeout property is set?