Include database connection ID in log messages

Database assigns IDs to all incoming connections and can send them
back to the client in Bolt V3. IDs are sent in SUCCESS response
for HELLO message. Clients can use those IDs for logging to for better
connection traceability. The same ID is returned in the output of
`dbms.listConnections` procedure.

This commit makes driver extract connection ID form the SUCCESS
response and include it in logged messages.

Author: lutovich

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>