Skip to content

Session Expiring and giving an error #244

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
Prateek218 opened this issue May 19, 2017 · 24 comments
Closed

Session Expiring and giving an error #244

Prateek218 opened this issue May 19, 2017 · 24 comments

Comments

@Prateek218
Copy link

Prateek218 commented May 19, 2017

I' m trying to solve this issue from 2 dyas, but not getting any solution.
Database log

2017-05-18 16:09:16.849+0000 ERROR [o.n.b.t.SocketTransportHandler] Fatal error occurred when handling a client connection: failed to allocate 16777216 byte(s) of direct memory (used: 922746887, max: 934281216) failed to allocate 16777216 byte(s) of direct memory (used: 922746887, max: 934281216)
io.netty.util.internal.OutOfDirectMemoryError: failed to allocate 16777216 byte(s) of direct memory (used: 922746887, max: 934281216)
at io.netty.util.internal.PlatformDependent.incrementMemoryCounter(PlatformDependent.java:624)
at io.netty.util.internal.PlatformDependent.allocateDirectNoCleaner(PlatformDependent.java:578)
at io.netty.buffer.PoolArena$DirectArena.allocateDirect(PoolArena.java:709)
at io.netty.buffer.PoolArena$DirectArena.newChunk(PoolArena.java:698)
at io.netty.buffer.PoolArena.allocateNormal(PoolArena.java:237)
at io.netty.buffer.PoolArena.allocate(PoolArena.java:221)
at io.netty.buffer.PoolArena.allocate(PoolArena.java:141)
at io.netty.buffer.PooledByteBufAllocator.newDirectBuffer(PooledByteBufAllocator.java:262)
at io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:179)
at io.netty.buffer.AbstractByteBufAllocator.directBuffer(AbstractByteBufAllocator.java:170)
at io.netty.buffer.AbstractByteBufAllocator.buffer(AbstractByteBufAllocator.java:107)
at io.netty.handler.ssl.SslHandler.allocate(SslHandler.java:1472)
at io.netty.handler.ssl.SslHandler.allocateOutNetBuf(SslHandler.java:1482)
at io.netty.handler.ssl.SslHandler.wrap(SslHandler.java:519)
at io.netty.handler.ssl.SslHandler.flush(SslHandler.java:490)
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:787)
at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:779)
at io.netty.channel.AbstractChannelHandlerContext.access$1500(AbstractChannelHandlerContext.java:39)
at io.netty.channel.AbstractChannelHandlerContext$WriteAndFlushTask.write(AbstractChannelHandlerContext.java:1148)
at io.netty.channel.AbstractChannelHandlerContext$AbstractWriteTask.run(AbstractChannelHandlerContext.java:1089)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:418)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:454)
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:873)
at java.lang.Thread.run(Unknown Source)
2017-05-18 16:09:16.937+0000 WARN [io.netty.channel.AbstractChannelHandlerContext] Failed to mark a promise as failure because it has succeeded already: DefaultChannelPromise@3c0b7552(success)

server log
{ Error: Connection was closed by server
at Neo4jError.Error (native)
at new Neo4jError (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\error.js:76:132)
at newError (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\error.js:66:10)
at NodeChannel._handleConnectionTerminated (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\ch-node.js:336:41)
at emitNone (events.js:91:20)
at TLSSocket.emit (events.js:185:7)
at endReadableNT (_stream_readable.js:974:12)
at _combinedTickCallback (internal/process/next_tick.js:74:11)
at process._tickCallback (internal/process/next_tick.js:98:9) code: 'ServiceUnavailable' }

@lutovich
Copy link
Contributor

See #187 (comment)

@Prateek218
Copy link
Author

I have updated code their should I update the code here too.

@lutovich
Copy link
Contributor

@Prateek218 I went through your code and have couple suggestions:

  1. the very first session is not closed properly, session.close() call goes after return. code could be changed to this:
session
  .run('match (c:channel) where c.from="yt" return c')
  .then(function (result) {
    session.close(); // <<-- session is closed here
    return result.records.map(function (record) {
      return {
        title: record._fields[0].properties.channelid
      };
    })
  })
...
  1. sessions should not be reused after being closed. please add var session = driver.session() before two last session.run(...) calls. i.e. before:
session.run('match (a:video), (b:language) where a.language=b.title merge (b)-[r:video_lang{title:"video_lang"}]-(a) return a,b,r ')

and before:

session.run('match (a:channel), (b:video) where a.channelid={channelParam} AND b.source={channelParam} merge (a)-[r:rel_video{title:"yt"}]->(b) return a,b,r',{channelParam:cron_channel[k].title})

Also what driver and database versions are you using?

Please let us know if those suggestions help.

@Prateek218
Copy link
Author

Prateek218 commented May 19, 2017

Database version is 3.1.1 and driver version is var neo4j = require('neo4j-driver').v1; var db = new neo4j_match.GraphDatabase('http://neo4j:neo4j@localhost:7474');
var driver = neo4j.driver("bolt://localhost:7687", neo4j.auth.basic("neo4j", "neo4j"));
var session = driver.session();

@lutovich
Copy link
Contributor

@Prateek218 do you use npm? could you share package.json? did you try those code changes?

@Prateek218
Copy link
Author

@lutovich Thank you for the help now my issue is resolved.

package.json

{
  "name": "cronyt",
  "version": "1.0.0",
  "description": "",
  "main": "app.js",
  "scripts": {
    "test": "echo \"Error: no test specified\" && exit 1"
  },
  "author": "",
  "license": "ISC",
  "dependencies": {
    "body-parser": "^1.17.1",
    "every-moment": "0.0.1",
    "express": "^4.15.3",
    "express-session": "^1.15.2",
    "moment": "^2.18.1",
    "neo4j": "^2.0.0-RC2",
    "neo4j-driver": "^1.3.0",
    "request": "^2.81.0"
  }
}

@Prateek218
Copy link
Author

Prateek218 commented May 19, 2017

But in sometimes it gives an error and the server keeps on running.

{ Error: Connection was closed by server
    at Neo4jError.Error (native)
    at new Neo4jError (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\error.js:76:132)
    at newError (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\error.js:66:10)
    at NodeChannel._handleConnectionTerminated (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\ch-node.js:336:41)
    at emitNone (events.js:91:20)
    at TLSSocket.emit (events.js:185:7)
    at endReadableNT (_stream_readable.js:974:12)
    at _combinedTickCallback (internal/process/next_tick.js:74:11)
    at process._tickCallback (internal/process/next_tick.js:98:9) code: 'ServiceUnavailable' }

and Sometimes this error is generated and server stops

`C:\Users\Prateek\Desktop\Youtube Cron\app.js:144
  if (err) throw err;
Error: connect ECONNREFUSED 127.0.0.1:7474
    at Object.exports._errnoException (util.js:1022:11)
    at exports._exceptionWithHostPort (util.js:1045:20)
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1087:14)`

Database log

java.io.IOException: An existing connection was forcibly closed by the remote host
	at sun.nio.ch.SocketDispatcher.read0(Native Method)
	at sun.nio.ch.SocketDispatcher.read(Unknown Source)
	at sun.nio.ch.IOUtil.readIntoNativeBuffer(Unknown Source)
	at sun.nio.ch.IOUtil.read(Unknown Source)
	at sun.nio.ch.SocketChannelImpl.read(Unknown Source)
	at io.netty.buffer.PooledUnsafeDirectByteBuf.setBytes(PooledUnsafeDirectByteBuf.java:288)
	at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1100)
	at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:366)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:118)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:651)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:574)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:488)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:450)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:873)
	at java.lang.Thread.run(Unknown Source)

@lutovich
Copy link
Contributor

@Prateek218 I can see you use 127.0.0.1:7474 address in the later case. Port 7474 by default is HTTP port. Did you change bolt port from default 7687 to 7474? Try using 127.0.0.1:7687 if you did not change ports in neo4j.conf file.

Connection was closed by server client error should have a corresponding entry in the database log called debug.log. Do you see smth there for the relevant timeframe?
Do you run your database locally or in some cloud?

@Prateek218
Copy link
Author

Prateek218 commented May 19, 2017

yes in
debug.log it showing this

java.io.IOException: An existing connection was forcibly closed by the remote host
	at sun.nio.ch.SocketDispatcher.read0(Native Method)
	at sun.nio.ch.SocketDispatcher.read(Unknown Source)
	at sun.nio.ch.IOUtil.readIntoNativeBuffer(Unknown Source)
	at sun.nio.ch.IOUtil.read(Unknown Source)
	at sun.nio.ch.SocketChannelImpl.read(Unknown Source)
	at io.netty.buffer.PooledUnsafeDirectByteBuf.setBytes(PooledUnsafeDirectByteBuf.java:288)
	at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1100)
	at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:366)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:118)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:651)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:574)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:488)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:450)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:873)
	at java.lang.Thread.run(Unknown Source)

right now I m running my code locally

@lutovich
Copy link
Contributor

This stacktrace if for connection that was closed by driver. Database in such cases will print smth like this. There might be messages saying that database will close connection because of some error (like failed auth, etc.).

@Prateek218
Copy link
Author

Prateek218 commented May 19, 2017

ok, I will see to it and get back to you.

@Aurelsicoko
Copy link

I have the exact same issue. I'm using transaction and on every request, I'm committing or rollbacking the transaction, then I'm closing the session. But, sometimes I get this error Error: Connection was closed by server.

Here my package.json:

"dependencies": {
    "aws-sdk": "^2.28.0",
    "bcrypt": "^1.0.2",
    "dataloader": "^1.2.0",
    "file-type": "^4.1.0",
    "graphql": "^0.9.1",
    "graphql-server-hapi": "^0.7.1",
    "graphql-tools": "^0.11.0",
    "graphql-type-json": "^0.1.4",
    "hapi": "^16.1.0",
    "ioredis": "^2.5.0",
    "jsonwebtoken": "^7.1.7",
    "lodash": "^4.13.1",
    "moment": "^2.18.1",
    "neo4j-driver": "^1.2.0",
    "request": "^2.79.0",
    "request-promise": "^4.1.1",
    "sendgrid": "^5.0.0",
    "validate.js": "^0.11.1",
    "vision": "^4.1.1"
  }

@Prateek218
Copy link
Author

@lutovich Now when I'm running my code then sometimes I'm getting these error.

In Database log

2017-05-22 05:19:28.124+0000 WARN  [io.netty.channel.DefaultChannelPipeline] An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception. An existing connection was forcibly closed by the remote host
java.io.IOException: An existing connection was forcibly closed by the remote host
	at sun.nio.ch.SocketDispatcher.read0(Native Method)
	at sun.nio.ch.SocketDispatcher.read(Unknown Source)
	at sun.nio.ch.IOUtil.readIntoNativeBuffer(Unknown Source)
	at sun.nio.ch.IOUtil.read(Unknown Source)
	at sun.nio.ch.SocketChannelImpl.read(Unknown Source)
	at io.netty.buffer.PooledUnsafeDirectByteBuf.setBytes(PooledUnsafeDirectByteBuf.java:288)
	at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1100)
	at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:366)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:118)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:651)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:574)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:488)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:450)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:873)
	at java.lang.Thread.run(Unknown Source)

node log

C:\Users\Prateek\Desktop\Youtube Cron\app.js:147
    if (err) throw err;
             ^

Error: connect ECONNREFUSED 127.0.0.1:7474
    at Object.exports._errnoException (util.js:1018:11)
    at exports._exceptionWithHostPort (util.js:1041:20)
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1086:14)

and sometime it give different error when i run code

like this below

sever side log

C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\packstream.js:453
        throw (0, _error.newError)("Unknown packed value with marker " + marker.toString(16));
                                                                               ^

TypeError: Cannot read property 'toString' of undefined
    at Unpacker.unpack (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\packstream.js:453:80)
    at Unpacker.unpackMap (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\packstream.js:372:24)
    at Unpacker.unpack (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\packstream.js:432:21)
    at node (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\connector.js:142:14)
    at Unpacker.unpackStruct (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\packstream.js:383:16)
    at Unpacker.unpack (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\packstream.js:451:21)
    at Unpacker.unpackList (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\packstream.js:363:25)
    at Unpacker.unpack (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\packstream.js:447:21)
    at Unpacker.unpackStruct (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\packstream.js:387:34)
    at Unpacker.unpack (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\packstream.js:451:21)

and while running code this error is also generated in between and server keep on running and server stops when above error generated.

{ Error: Connection was closed by server
    at Neo4jError.Error (native)
    at new Neo4jError (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\error.js:76:132)
    at newError (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\error.js:66:10)
    at NodeChannel._handleConnectionTerminated (C:\Users\Prateek\Desktop\Youtube Cron\node_modules\neo4j-driver\lib\v1\internal\ch-node.js:336:41)
    at emitNone (events.js:91:20)
    at TLSSocket.emit (events.js:185:7)
    at endReadableNT (_stream_readable.js:974:12)
    at _combinedTickCallback (internal/process/next_tick.js:80:11)
    at process._tickCallback (internal/process/next_tick.js:104:9) code: 'ServiceUnavailable' } 

@Prateek218
Copy link
Author

Hi @lutovich,
I was debugging the code and finally all errors are resolved and the one error I'm getting is this on server side

C:\Users\Prateek\Desktop\Youtube Cron\app.js:147
    if (err) throw err;
             ^

Error: connect ECONNREFUSED 127.0.0.1:7474
    at Object.exports._errnoException (util.js:1018:11)
    at exports._exceptionWithHostPort (util.js:1041:20)
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1086:14)

and on Database log same error is generated as I have already mentioned above.

@Aurelsicoko
Copy link

Aurelsicoko commented May 22, 2017

@Prateek218 I got this one sometimes too. I worked on a large app, and this issue happens in every environment (local, dev, staging, prod). I'm using a query builder which takes care to close transaction and session on every request. That's why I'm pretty sure it's not due to my code but the issue comes from the driver itself.

@Prateek218
Copy link
Author

@Aurelsicoko ok, then you can ask to @lutovich he will help you as I'm new to neo4j and as well as node.
if you don't have any problem then you can share query builder code which takes care to close transaction and session on every request. It will help me too.

@Prateek218
Copy link
Author

Prateek218 commented May 23, 2017

Hi @lutovich and @Aurelsicoko,
Do you know how to get data in chunk from Neo4j.
like when 1st time request DB then it send 50 values and when 2nd time request DB then it gives next 50 values and so on.
Please help me and tell me how to do this?

@lutovich
Copy link
Contributor

Hi @Prateek218,

You can use Cypher's SKIP and LIMIT to do pagination.

Hope this helps.

@lutovich
Copy link
Contributor

@Prateek218, @Aurelsicoko could you please try to set connectionPoolSize setting to zero?
This can be done via regular settings when driver is created:

neo4j.driver(
        "bolt://server:port",
        neo4j.auth.basic("user", "password"),
        {connectionPoolSize: 0}
)

I think if errors go away this might mean something (load balancer, etc.) in the environment is killing idle connections. The we'd need to add ping or connection liveness check to the connection pool.

Looking forward to your reply!

@Prateek218
Copy link
Author

But I'm using another neo4j driver.

neo4j_match 			  = 	require('neo4j');
var db = new neo4j_match.GraphDatabase('http://neo4j:1234567@localhost:7474');

can you tell me how to set {connectionPollSize: 0} in this driver which I'm using currently.
Thank You

@lutovich
Copy link
Contributor

@Prateek218 your code is not using this driver. It uses neo4j package instead of neo4j-driver. However code mentioned here does use neo4j-driver. I honestly know nothing about neo4j package.

So {connectionPoolSize: 0} only makes sense for neo4j-driver package and can only be used for driver created with smth like:

var neo4j = require('neo4j-driver').v1;
var driver = neo4j.driver("bolt://localhost");

@Aurelsicoko do you think you could try setting connection pool size to zero?

@lutovich
Copy link
Contributor

Closing because of inactivity. Please update the issue if the problem still exists.

@Aurelsicoko
Copy link

@lutovich Sorry for the lack of response, I forgot to keep you up-to-date. We handled the issue by re-sending the request when it failed. I'm no longer working on this project so I can't tell you if {connectionPollSize: 0} is fixing the issue. However, I checked this morning and this option wasn't set...

@lutovich
Copy link
Contributor

@Aurelsicoko thank you for the update. Setting connection pool size to zero was suggested in order to verify if the driver is forcing the database to handle too many connections and fail with OOM. It is not really a fix. I think this fix for neo4j might be relevant. It will be available in neo4j 3.4.0 soon (currently available in release candidate builds).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants