Neo4j in Azure issue

[snunezmeneses]

Hi everyone, newbie web developer and Neo4j user here.

We're facing an issue with Neo4j Community Edition hosted in Azure. We've developed an API that uses Laudis Neo4j PHP Client and Bolt library.

When using the API in local development, for instance, through Postman, everything works perfect. But when using the API hosted in Azure, we get HTTP status code 500 most of the time. When performing queries used in the API in Neo4j Browser, it also works.

Inspecting the debug.log file, sometimes we find these errors and warnings:

2021-09-01 02:09:13.893+0000 ERROR [o.n.b.t.p.ProtocolHandshaker] Fatal error occurred during protocol handshaking: [id: 0x9582075a, L:/10.0.0.1:7687 - R:/123.456.789.12:34294]
java.lang.SecurityException: An unencrypted connection attempt was made where encryption is required.
	at org.neo4j.bolt.transport.pipeline.ProtocolHandshaker.assertEncryptedIfRequired(ProtocolHandshaker.java:151) ~[neo4j-bolt-4.2.6.jar:4.2.6]
	at org.neo4j.bolt.transport.pipeline.ProtocolHandshaker.channelRead(ProtocolHandshaker.java:89) ~[neo4j-bolt-4.2.6.jar:4.2.6]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.handlerRemoved(ByteToMessageDecoder.java:253) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:515) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:447) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at org.neo4j.bolt.transport.pipeline.AuthenticationTimeoutTracker.channelRead(AuthenticationTimeoutTracker.java:45) [neo4j-bolt-4.2.6.jar:4.2.6]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:795) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:480) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:378) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-all-4.1.63.Final.jar:4.1.63.Final]
	at java.lang.Thread.run(Thread.java:829) [?:?]
2021-09-01 02:09:14.246+0000 DEBUG [i.n.h.s.SslHandler] [id: 0xbe948ddf, L:/10.0.0.1:7687 - R:/123.456.789.12:34294] HANDSHAKEN: protocol:TLSv1.2 cipher suite:TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
2021-09-01 02:09:14.344+0000 DEBUG [o.n.b.t.p.ProtocolHandshaker] Failed Bolt handshake: Bolt versions suggested by client '[org.neo4j.bolt.BoltProtocolVersion@3c2, org.neo4j.bolt.BoltProtocolVersion@3c1, org.neo4j.bolt.BoltProtocolVersion@3c1, org.neo4j.bolt.BoltProtocolVersion@3c1]' are not supported by this server.
2021-09-01 02:24:19.249+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1484, gcTime=0, gcCount=0}
2021-09-01 02:46:03.915+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1499, gcTime=0, gcCount=0}
2021-09-01 04:07:37.441+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1483, gcTime=1484, gcCount=2}
2021-09-01 06:07:34.077+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1492, gcTime=0, gcCount=0}

2021-09-01 08:00:08.712+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1490, gcTime=1511, gcCount=2}
2021-09-01 08:00:10.276+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1463, gcTime=1505, gcCount=3}
2021-09-01 08:00:11.833+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1456, gcTime=1502, gcCount=2}
2021-09-01 08:00:13.387+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1454, gcTime=1506, gcCount=2}
2021-09-01 08:00:14.938+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1451, gcTime=1510, gcCount=2}
2021-09-01 08:00:16.480+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1441, gcTime=1503, gcCount=2}
2021-09-01 08:00:18.040+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1460, gcTime=1522, gcCount=2}
2021-09-01 08:00:19.582+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1441, gcTime=1506, gcCount=2}
2021-09-01 08:00:21.127+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1445, gcTime=1511, gcCount=2}
2021-09-01 08:00:22.690+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1462, gcTime=1514, gcCount=2}
2021-09-01 08:03:19.453+0000 WARN  [o.n.k.i.c.VmPauseMonitorComponent] Detected VM stop-the-world pause: {pauseTime=1450, gcTime=1497, gcCount=2}

And sometimes, these:

2021-08-31 09:57:06.167+0000 DEBUG [o.n.c.i.CommunityCompilerFactory] [neo4j/b518cd96] Discarded stale plan from the plan cache after 4911256 seconds. Reason: NodesWithLabelCardinality(Some(LabelId(6))) changed from 10.0 to 54.0, which is a divergence of 0.8148148148148148 which is greater than threshold 5.913461844779836E-4. Metadata: MATCH (o:Offer), (o)-->(ot:OfferType {type: "takeover"}), (o)-[Status]->(stat:Status), (o)-[User]->(u:User), (o)-[Structure]->(struc:Structure), (o)-[Contact]->(c:Contact), (o)-[TerritorialContact]->(tc:TerritorialContact), (o)-[Subject]->(s:Subject), (o)-[Favorite]->(f:Favorite), (o)-[Location]->(lo:Location), (o)-[Filled]->(fill:Filled)
  WHERE stat.status <> "Deleted"
CALL {
  WITH o AS o, ot AS ot
  WITH o AS o, ot AS ot
    WHERE ot.type = "takeover"
  MATCH (o)-[ActivityType]->(at:ActivityType), (o)-[ErpCategory]->(erp:ErpCategory)
  RETURN DISTINCT o{activityType: at.activityType, erpCategory: erp.erpCategory} AS props
  UNION
  WITH o AS o, ot AS ot
  WITH o AS o, ot AS ot
    WHERE ot.type = "job"
  MATCH (o)-[Company]->(co:Company), (o)-[ContractType]->(ct:ContractType), (o)-[ContractCharacteristics]->(cc:ContractCharacteristics), (o)-[Executive]->(e:Executive), (o)-[TradeType]->(tt:TradeType), (o)-[Skill]->(sk:Skill)
  RETURN DISTINCT o{companyId: co.id, contractType: ct.contractType, contractCharacteristics: cc.contractCharacteristics, skills: collect(sk.skill), executive: e.executive, trade: tt.tradeType} AS props
  UNION
  WITH o AS o, ot AS ot
  WITH o AS o, ot AS ot
    WHERE ot.type = "realEstate"
  MATCH (o)-[PropertyType]->(prop:PropertyType), (o)-[ProjectType]->(proj:ProjectType)
  RETURN DISTINCT o{propertyType: prop.propertyType, projectType: proj.projectType} AS props
}
RETURN o{.*, type: ot.type, status: stat.status, moderationMessage: o.moderationMessage, producerId: u.id, structureId: struc.id, contactId: c.id, territorialContactId: tc.id, subject: s.subject, favorite: f.favorite, city: lo.city, zipCode: lo.zipCode, filled: fill.filled, props} AS offers
  ORDER BY o.title ASCENDING
  SKIP 0
  LIMIT 10

Moreover, when I try to launch the Cypher shell, I get this error:

Connection to the database terminated. Please ensure that your database is listening on the correct host and port and that you have compatible encryption settings both on Neo4j server and driver. Note that the default encryption setting has changed in Neo4j 4.0.

We've updated Laudis Neo4j PHP Client and Bolt library versions, but it didn't help.

Would anyone have an idea on how to solve this?

Please let me know if I didn't post this issue in the correct category.
Thank you very much in advance !

[sameer_gijare14]

Hello
Looks like you are missing the very first version of Java driver in Neo4j.Please install it in your library and then test your code
Important note: Please do not delete that driver.
Thanking you
Sameer S Gijare

[snunezmeneses · Accepted solution]

Hi @sameer.gijare14,

Thank you very much for your reply. I actually just solved this problem by enabling the GC Logging in the neo4j.conf file:
Uncomment the line #dbms.logs.gc.enabled=true, and restart the server (in my case, sudo systemctl restart neo4j).

Now everything's working correctly.

I hope this help others experiencing the same issue.