Merge pull request #419 from lutovich/1.7-connection-id

Include database connection ID in log messages

Author: zhenlineo

src/v1/internal/connection.js

@@ -68,6 +68,9 @@ export default class Connection {
     this._chunker = new Chunker( channel );
     this._log = log;
 
+    // connection from the database, returned in response for HELLO message and might not be available
+    this._dbConnectionId = null;
+
     // bolt protocol is initially not initialized
     this._protocol = null;
 
@@ -388,7 +391,8 @@ export default class Connection {
   }
 
   toString() {
-    return `Connection ${this.id}`;
+    const dbConnectionId = this._dbConnectionId || '';
+    return `Connection [${this.id}][${dbConnectionId}]`;
   }
 
   _packable(value) {
@@ -424,13 +428,21 @@ class InitializationObserver {
   }
 
   onCompleted(metadata) {
-    // read server version from the response metadata
-    const serverVersion = metadata ? metadata.server : null;
-    if (!this._connection.server.version) {
-      this._connection.server.version = serverVersion;
-      const version = ServerVersion.fromString(serverVersion);
-      if (version.compareTo(VERSION_3_2_0) < 0) {
-        this._connection.protocol().packer().disableByteArrays();
+    if (metadata) {
+      // read server version from the response metadata, if it is available
+      const serverVersion = metadata.server;
+      if (!this._connection.server.version) {
+        this._connection.server.version = serverVersion;
+        const version = ServerVersion.fromString(serverVersion);
+        if (version.compareTo(VERSION_3_2_0) < 0) {
+          this._connection.protocol().packer().disableByteArrays();
+        }
+      }
+
+      // read database connection id from the response metadata, if it is available
+      const dbConnectionId = metadata.connection_id;
+      if (!this._connection._dbConnectionId) {
+        this._connection._dbConnectionId = dbConnectionId;
       }
     }
 

test/internal/node/direct.driver.boltkit.test.js

@@ -332,4 +332,44 @@ describe('direct driver with stub server', () => {
       });
     });
   });
+
+  it('should include database connection id in logs', done => {
+    if (!boltStub.supported) {
+      done();
+      return;
+    }
+
+    const server = boltStub.start('./test/resources/boltstub/hello_run_exit.script', 9001);
+
+    boltStub.run(() => {
+      const messages = [];
+      const logging = {
+        level: 'debug',
+        logger: (level, message) => messages.push(message)
+      };
+
+      const driver = boltStub.newDriver('bolt://127.0.0.1:9001', {logging: logging});
+      const session = driver.session();
+
+      session.run('MATCH (n) RETURN n.name').then(result => {
+        const names = result.records.map(record => record.get(0));
+        expect(names).toEqual(['Foo', 'Bar']);
+        session.close(() => {
+          driver.close();
+          server.exit(code => {
+            expect(code).toEqual(0);
+
+            // logged messages should contain connection_id supplied by the database
+            const containsDbConnectionIdMessage = messages.find(message => message.match(/Connection \[[0-9]+]\[bolt-123456789]/));
+            if (!containsDbConnectionIdMessage) {
+              console.log(messages);
+            }
+            expect(containsDbConnectionIdMessage).toBeTruthy();
+
+            done();
+          });
+        });
+      }).catch(error => done.fail(error));
+    });
+  });
 });

test/resources/boltstub/hello_run_exit.script

@@ -0,0 +1,12 @@
+!: BOLT 3
+!: AUTO RESET
+
+C: HELLO {"credentials": "password", "scheme": "basic", "user_agent": "neo4j-javascript/0.0.0-dev", "principal": "neo4j"}
+S: SUCCESS {"server": "Neo4j/9.9.9", "connection_id": "bolt-123456789"}
+C: RUN "MATCH (n) RETURN n.name" {} {}
+   PULL_ALL
+S: SUCCESS {"fields": ["n.name"]}
+   RECORD ["Foo"]
+   RECORD ["Bar"]
+   SUCCESS {}
+S: <EXIT>