Errors during CommitAsync

java-driver

(Stephane Debart) #1

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) #2

Can you share more of your code?

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


(Stephane Debart) #3

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) #4

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) #5

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


(Stephane Debart) #6

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

Thanks Michael for your quick answers.


(Stephane Debart) #7

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