Errors during CommitAsync

[stephane_debart]

Hi,
We are facing some NullPointerExceptions during commit in our application.

java.lang.NullPointerException: null
	at org.neo4j.driver.internal.async.ResultCursorsHolder.retrieveFailure(ResultCursorsHolder.java:51)
	at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:193)
	at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1382)
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481)
	at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471)
	at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708)
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.util.stream.ReferencePipeline.reduce(ReferencePipeline.java:474)
	at org.neo4j.driver.internal.async.ResultCursorsHolder.retrieveNotConsumedError(ResultCursorsHolder.java:45)
	at org.neo4j.driver.internal.ExplicitTransaction.commitAsync(ExplicitTransaction.java:171)

We are using:

• Neo4j 3.4.8 Enterprise Docker image.
• java driver 1.6.3

When this happens, it seems that all write transactions are somehow blocked, they remain open and thus it's no more possible to open new write transactions during about 10 minutes. (read transaction still work properly). So we've just added a transaction timeout but we don't know yest if this will improve things.

There's no clear repro, it just happen about once every 2 days on our servers.
Suggestions are welcome.
Thanks,
Stéphane

[michael_hunger]

Can you share more of your code?

Perhaps you could run a kind of stress-test that could reproduce it more often?

[stephane_debart]

I've just reproduced it today on my local server.
I've run CALL dbms.listTransactions() and there's a transaction which seems to do nothing but has 109 active locks and blocks the other transactions. This explains the second part of the issue ( other write transactions blocked).
I'm still investigating and will come back to you later with more details

╒═════════════════╤══════════╤══════════╤══════════════════════════╤══════════╤═════════════════╤════════════════╤════════════════╤══════════════════════════════════════════════════════════════════════╤═════════════════╤═══════════════════════════════╤══════════════════════════════════════════════════════════════════════╤═══════════════════╤═══════════════╤════════════════╤════════════════╤════════════════╤══════════════════════╤══════════╤════════════╕
│"transactionId"  │"username"│"metaData"│"startTime"               │"protocol"│"clientAddress"  │"requestUri"    │"currentQueryId"│"currentQuery"                                                        │"activeLockCount"│"status"                       │"resourceInformation"                                                 │"elapsedTimeMillis"│"cpuTimeMillis"│"waitTimeMillis"│"idleTimeMillis"│"allocatedBytes"│"allocatedDirectBytes"│"pageHits"│"pageFaults"│
╞═════════════════╪══════════╪══════════╪══════════════════════════╪══════════╪═════════════════╪════════════════╪════════════════╪══════════════════════════════════════════════════════════════════════╪═════════════════╪═══════════════════════════════╪══════════════════════════════════════════════════════════════════════╪═══════════════════╪═══════════════╪════════════════╪════════════════╪════════════════╪══════════════════════╪══════════╪════════════╡
│"transaction-280"│"neo4j"   │{}        │"2018-11-23T11:06:51.789Z"│"bolt"    │"127.0.0.1:53042"│"127.0.0.1:7687"│"query-527"     │"MATCH (a1:CustomerFolder) WHERE a1.flamid = {from_id} CREATE (a1)-[a2│29               │"Blocked by: [transaction-206]"│{"waitTimeMillis":383721,"lockMode":"EXCLUSIVE","resourceType":"NODE",│383811             │0              │383722          │89              │0               │0                     │1296      │0           │
│                 │          │          │                          │          │                 │                │                │:File{flamid:{arcProp0}}]->(a3:FolderFile{`Valid Documents`:{vertexPro│                 │                               │"resourceIds":[836]}                                                  │                   │               │                │                │                │                      │          │            │
│                 │          │          │                          │          │                 │                │                │p0},FileType:{vertexProp1},CustomerHasManager:{vertexProp2},`Next expi│                 │                               │                                                                      │                   │               │                │                │                │                      │          │            │
│                 │          │          │                          │          │                 │                │                │ration date`:{vertexProp3},FileState:{vertexProp4},`Capitalization tab│                 │                               │                                                                      │                   │               │                │                │                │                      │          │            │
│                 │          │          │                          │          │                 │                │                │le`:{vertexProp5},DccpApprovalRequired:{vertexProp6},RequiredFields:{v│                 │                               │                                                                      │                   │               │                │                │                │                      │          │            │
│                 │          │          │                          │          │                 │                │                │ertexProp7},FileStateChangedBy:{vertexProp8},CreatedBy:{vertexProp9},C│                 │                               │                                                                      │                   │               │                │                │                │                      │          │            │
│                 │          │          │                          │          │                 │                │                │reation:{vertexProp10},RiskScore:{vertexProp11},`Beneficiary owners ca│                 │                               │                                                                      │                   │               │                │                │                │                      │          │            │
│                 │          │          │                          │          │                 │                │                │pitalization`:{vertexProp12},`Last modification`:{vertexProp13},FileSt│                 │                               │                                                                      │                   │               │                │                │                │                      │          │            │
│                 │          │          │                          │          │                 │                │                │ateChange:{vertexProp14},flamid:{vertexProp15},`Validated ereputation │                 │                               │                                                                      │                   │               │                │                │                │                      │          │            │
│                 │          │          │                          │          │                 │                │                │results`:{vertexProp16},LastModifiedBy:{vertexProp17},`Available erepu│                 │                               │                                                                      │                   │               │                │                │                │                      │          │            │
│                 │          │          │                          │          │                 │                │                │tation results`:{vertexProp18},Complete:{vertexProp19},Name:{vertexPro│                 │                               │                                                                      │                   │               │                │                │                │                      │          │            │
│                 │          │          │                          │          │                 │                │                │p20}}) RETURN a1 AS startNode, a2 AS relationship, a3 AS endNode"     │                 │                               │                                                                      │                   │               │                │                │                │                      │          │            │
├─────────────────┼──────────┼──────────┼──────────────────────────┼──────────┼─────────────────┼────────────────┼────────────────┼──────────────────────────────────────────────────────────────────────┼─────────────────┼───────────────────────────────┼──────────────────────────────────────────────────────────────────────┼───────────────────┼───────────────┼────────────────┼────────────────┼────────────────┼──────────────────────┼──────────┼────────────┤
│"transaction-206"│"neo4j"   │{}        │"2018-11-23T11:02:43.385Z"│""        │""               │""              │""              │""                                                                    │109              │"Running"                      │{}                                                                    │632219             │0              │0               │632219          │0               │0                     │9075      │1           │
├─────────────────┼──────────┼──────────┼──────────────────────────┼──────────┼─────────────────┼────────────────┼────────────────┼──────────────────────────────────────────────────────────────────────┼─────────────────┼───────────────────────────────┼──────────────────────────────────────────────────────────────────────┼───────────────────┼───────────────┼────────────────┼────────────────┼────────────────┼──────────────────────┼──────────┼────────────┤
│"transaction-434"│"neo4j"   │{}        │"2018-11-23T11:13:15.599Z"│"bolt"    │"127.0.0.1:53884"│"127.0.0.1:7687"│"query-681"     │"CALL dbms.listTransactions()"                                        │0                │"Running"                      │{}                                                                    │5                  │0              │0               │5               │0               │0                     │1516      │0           │
└─────────────────┴──────────┴──────────┴──────────────────────────┴──────────┴─────────────────┴────────────────┴────────────────┴──────────────────────────────────────────────────────────────────────┴─────────────────┴───────────────────────────────┴──────────────────────────────────────────────────────────────────────┴───────────────────┴───────────────┴────────────────┴────────────────┴────────────────┴──────────────────────┴──────────┴────────────┘

[stephane_debart]

I'm now able to reproduce it more often but unfortunately not always.
It's difficult to share the code here as this code is split across several libraries....
But I can give you more details.

Our application uses the java driver.
All cypher queries are executed through transaction.runAsync.

The problem seems to occur when we are performing several parallel updates (of different nodes) in the same transaction.
All updates are successful but is some cases the commitAsync fails as mentioned.

As I'm now able to reproduce quite easily, do you see any log I could activate to give you more information ?
Thanks,
Stéphane

[michael_hunger]

Would you mind raising this as a bug on the GitHub repository, linking back here?

GitHub

neo4j/neo4j-java-driver

Neo4j Bolt driver for Java. Contribute to neo4j/neo4j-java-driver development by creating an account on GitHub.

[stephane_debart]

Done: https://github.com/neo4j/neo4j-java-driver/issues/547

Thanks Michael for your quick answers.

[stephane_debart]

These errors were due to an incorrect usage of the java driver on our side.