NullPointerException using javascript neo4j-driver when overflowing connectionPoolSize

[Michał Sitarz]

Hi!

While I was writing unit tests for my app I noticed this exception when testing more concurrent sessions than connectionPoolSize in javascript neo4j-driver.

Versions:

neo4j - dockerized 3.0.1, image neo4j:3.0

neo4j-driver - 1.0.1

nodejs - tested on 6.6.0 and 6.2.1

Error:

2016-09-27 19:21:41.296+0000 ERROR [o.n.b.v.t.BoltProtocolV1] Failed to write response to driver

java.lang.NullPointerException

at org.neo4j.bolt.v1.transport.ChunkedOutput.ensure(ChunkedOutput.java:156)

at org.neo4j.bolt.v1.transport.ChunkedOutput.writeShort(ChunkedOutput.java:90)

at org.neo4j.bolt.v1.packstream.PackStream$Packer.packStructHeader(PackStream.java:304)

at org.neo4j.bolt.v1.messaging.PackStreamMessageFormatV1$Writer.handleSuccessMessage(PackStreamMessageFormatV1.java:145)

at org.neo4j.bolt.v1.messaging.msgprocess.MessageProcessingCallback.completed(MessageProcessingCallback.java:102)

at org.neo4j.bolt.v1.messaging.msgprocess.MessageProcessingCallback.completed(MessageProcessingCallback.java:31)

at org.neo4j.bolt.v1.runtime.internal.SessionStateMachine.after(SessionStateMachine.java:823)

at org.neo4j.bolt.v1.runtime.internal.SessionStateMachine.reset(SessionStateMachine.java:699)

at org.neo4j.bolt.v1.runtime.internal.concurrent.SessionWorkerFacade.lambda$reset$6(SessionWorkerFacade.java:87)

at org.neo4j.bolt.v1.runtime.internal.concurrent.SessionWorker.execute(SessionWorker.java:116)

at org.neo4j.bolt.v1.runtime.internal.concurrent.SessionWorker.run(SessionWorker.java:77)

at java.lang.Thread.run(Thread.java:745)

I can reproduce this error on fresh DB using this code:

const _ = require('lodash'),

      neo4j = require('neo4j-driver').v1;

const driver = neo4j.driver('bolt://localhost:7687',

                            neo4j.auth.basic('neo4j',

                                             'neo4j'),

                            {connectionPoolSize: 1});

for (let i = 0; i < 100; i++) {

  let session = driver.session();

  session

    .run('create (u:User {id: {id}}) return u', {id: _.random(100000)})

    .then(records => {

      console.log('=====================NUMBER'+i+'=======================');

      console.log(records)

      console.log('==============================================');

      session.close();

    })

    .catch(err => {

      console.error(err);

      session.close();

    });

}

The same problem appears using observer:

const _ = require('lodash'),

      neo4j = require('neo4j-driver').v1;

const driver = neo4j.driver('bolt://localhost:7687',

                            neo4j.auth.basic('neo4j',

                                             'neo4j'),

                            {connectionPoolSize: 1});

for (let i = 0; i < 100; i++) {

  let session = driver.session();

  session

    .run('create (u:User {id: {id}}) return u', {id: _.random(100000)})

    .subscribe({

      onNext(record) {

      },

      onCompleted(summary) {

        console.log('finished number ' + i);

        session.close();

      },

      onError(err) {

        console.error(err, 'itaration number' + i);

      }

    });

}

After removing session.close() this problem disappears in both cases.

When using lower number of session e.g. 5, then the same problem appears after few scripts run. However, all records are returned properly.

I wouldn't notice this if next test in my suite sometimes didn't strangely fail with timeout or even exception shown below when using  "match (u:Testing) detach delete u" on afterEach hook.

2016-09-27 20:19:32.868+0000 ERROR [o.n.b.v.r.i.ErrorReporter] Client triggered an unexpected error [UnknownError]: Property[1075,used=false,prev=-1,next=-1] not in use. See debug.log for more details, reference 4c0fb1ed-ee5b-4036-a156-828a206cfc2e.

2016-09-27 20:19:32.868+0000 ERROR [o.n.b.v.r.i.ErrorReporter] Client triggered an unexpected error [UnknownError]: Property[1075,used=false,prev=-1,next=-1] not in use, reference 4c0fb1ed-ee5b-4036-a156-828a206cfc2e. Property[1075,used=false,prev=-1,next=-1] not in use

org.neo4j.kernel.impl.store.InvalidRecordException: Property[1075,used=false,prev=-1,next=-1] not in use

at org.neo4j.kernel.impl.store.record.RecordLoad$1.verify(RecordLoad.java:55)

at org.neo4j.kernel.impl.store.CommonAbstractStore.verifyAfterReading(CommonAbstractStore.java:1240)

at org.neo4j.kernel.impl.store.CommonAbstractStore.readIntoRecord(CommonAbstractStore.java:1064)

at org.neo4j.kernel.impl.store.CommonAbstractStore.getRecord(CommonAbstractStore.java:1042)

at org.neo4j.kernel.impl.transaction.state.Loaders$2.load(Loaders.java:165)

at org.neo4j.kernel.impl.transaction.state.Loaders$2.load(Loaders.java:145)

at org.neo4j.kernel.impl.transaction.state.RecordChanges.getOrLoad(RecordChanges.java:72)

at org.neo4j.kernel.impl.transaction.state.PropertyDeleter.deletePropertyChain(PropertyDeleter.java:45)

at org.neo4j.kernel.impl.transaction.state.TransactionRecordState.getAndDeletePropertyChain(TransactionRecordState.java:336)

at org.neo4j.kernel.impl.transaction.state.TransactionRecordState.nodeDelete(TransactionRecordState.java:322)

at org.neo4j.kernel.impl.storageengine.impl.recordstorage.TransactionToRecordStateVisitor.visitDeletedNode(TransactionToRecordStateVisitor.java:89)

at org.neo4j.storageengine.api.txstate.TxStateVisitor$Delegator.visitDeletedNode(TxStateVisitor.java:220)

at org.neo4j.kernel.api.txstate.TransactionCountingStateVisitor.visitDeletedNode(TransactionCountingStateVisitor.java:100)

at org.neo4j.kernel.impl.api.state.TxState$12.visitRemoved(TxState.java:339)

at org.neo4j.kernel.impl.api.state.TxState$12.visitRemoved(TxState.java:335)

at org.neo4j.kernel.impl.util.diffsets.SuperDiffSets.accept(SuperDiffSets.java:70)

at org.neo4j.kernel.impl.util.diffsets.DiffSets.accept(DiffSets.java:41)

at org.neo4j.kernel.impl.api.state.TxState.accept(TxState.java:274)

at org.neo4j.kernel.impl.storageengine.impl.recordstorage.RecordStorageEngine.createCommands(RecordStorageEngine.java:304)

at org.neo4j.kernel.impl.api.KernelTransactionImplementation.commit(KernelTransactionImplementation.java:431)

at org.neo4j.kernel.impl.api.KernelTransactionImplementation.close(KernelTransactionImplementation.java:380)

at org.neo4j.bolt.v1.runtime.internal.SessionStateMachine$State$3.commitTransaction(SessionStateMachine.java:187)

at org.neo4j.bolt.v1.runtime.internal.SessionStateMachine$State$4.discardAll(SessionStateMachine.java:258)

at org.neo4j.bolt.v1.runtime.internal.SessionStateMachine$State$4.pullAll(SessionStateMachine.java:237)

at org.neo4j.bolt.v1.runtime.internal.SessionStateMachine.pullAll(SessionStateMachine.java:664)

at org.neo4j.bolt.v1.runtime.internal.concurrent.SessionWorkerFacade.lambda$pullAll$4(SessionWorkerFacade.java:74)

at org.neo4j.bolt.v1.runtime.internal.concurrent.SessionWorker.execute(SessionWorker.java:116)

at org.neo4j.bolt.v1.runtime.internal.concurrent.SessionWorker.executeBatch(SessionWorker.java:102)

at org.neo4j.bolt.v1.runtime.internal.concurrent.SessionWorker.run(SessionWorker.java:82)

at java.lang.Thread.run(Thread.java:745)

And error returned to client:

Structure {

  signature: 127,

  fields: 

   [ { code: 'Neo.DatabaseError.General.UnknownError',

       message: 'An unexpected failure occurred, see details in the database logs, reference number 4c0fb1ed-ee5b-4036-a156-828a206cfc2e.' } ] }

When I don't use tests that runs more sessions than connectionPoolSize and without afterEach hook, then everything is OK.

So to summarize:

1) I hit NullPointerException in DB when running more sessions than connectionPoolSize

2) After hitting NullPointerException, next test which is simple transaction will timeout.

3) using afterEach hook that deletes all test nodes, sometimes I get UnknownError on client and InvalidRecordException in DB

So how can I make sure that this sort of problems doesn't occur on my server when requests will increase so much that there will be more sessions than connectionPoolSize?

Thanks!
Michal

[Michael Hunger]

Could you please paste this as an github issue for the java driver?

--
You received this message because you are subscribed to the Google Groups "Neo4j" group.
To unsubscribe from this group and stop receiving emails from it, send an email to neo4j+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Michał Sitarz]

Sure, I guess you meant javascript driver?

To unsubscribe from this group and stop receiving emails from it, send an email to neo4j+un...@googlegroups.com.

[Michael Hunger]

Yup

Von meinem iPhone gesendet