Support configurable logging

This commit makes driver able to log internal events to the configured
logging destination. Produced log messages should give an insight into
what operations are happening inside the driver. Logging destination
can be configured for the driver in the config object:

```
const config = {
  logger: (level, message) => console.log(level + ' ' + message)
};

const driver = neo4j.driver(
 'bolt://localhost',
  neo4j.auth.basic('neo4j', 'password'),
  config
);
```

Property `logger` should be a function that takes two arguments
`level: string` and `message: string`. Log level can now be 'error',
'warn', 'info' or 'debug'. Function should not execute any blocking or
long-running operations because it is often invoked on a hot path.

There exists a predefined logger implementation which outputs timestamp,
log level and message. Example:

```
1527703465096 INFO Direct driver 0 created for server address localhost:7687
```

It is defined in the `neo4j.logger` object and can be used like this:

```
const config = {
  logger: neo4j.logger.console
};

const driver = neo4j.driver(
 'bolt://localhost',
  neo4j.auth.basic('neo4j', 'password'),
  config
);
```

Users of the driver should be able to plug in an existing logging
framework like https://github.com/winstonjs/winston.

Author: lutovich

src/v1/driver.js

@@ -26,6 +26,7 @@ import {DirectConnectionProvider} from './internal/connection-providers';
 import Bookmark from './internal/bookmark';
 import ConnectivityVerifier from './internal/connectivity-verifier';
 import PoolConfig, {DEFAULT_ACQUISITION_TIMEOUT, DEFAULT_MAX_SIZE} from './internal/pool-config';
+import Logger from './internal/logger';
 
 const DEFAULT_MAX_CONNECTION_LIFETIME = 60 * 60 * 1000; // 1 hour
 
@@ -43,6 +44,8 @@ const READ = 'READ';
  */
 const WRITE = 'WRITE';
 
+let idGenerator = 0;
+
 /**
  * A driver maintains one or more {@link Session}s with a remote
  * Neo4j instance. Through the {@link Session}s you can send statements
@@ -66,17 +69,19 @@ class Driver {
   constructor(hostPort, userAgent, token = {}, config = {}) {
     sanitizeConfig(config);
 
+    this._id = idGenerator++;
     this._hostPort = hostPort;
     this._userAgent = userAgent;
-    this._openSessions = {};
-    this._sessionIdGenerator = 0;
+    this._openConnections = {};
     this._token = token;
     this._config = config;
+    this._log = Logger.create(config);
     this._pool = new Pool(
       this._createConnection.bind(this),
       this._destroyConnection.bind(this),
       this._validateConnection.bind(this),
-      PoolConfig.fromDriverConfig(config)
+      PoolConfig.fromDriverConfig(config),
+      this._log
     );
 
     /**
@@ -87,6 +92,15 @@ class Driver {
     this._connectionProvider = null;
 
     this._onCompleted = null;
+
+    this._afterConstruction();
+  }
+
+  /**
+   * @protected
+   */
+  _afterConstruction() {
+    this._log.info(`Direct driver ${this._id} created for server address ${this._hostPort}`);
   }
 
   /**
@@ -118,14 +132,12 @@ class Driver {
    * @access private
    */
   _createConnection(hostPort, release) {
-    let sessionId = this._sessionIdGenerator++;
-    let conn = connect(hostPort, this._config, this._connectionErrorCode());
+    let conn = connect(hostPort, this._config, this._connectionErrorCode(), this._log);
     let streamObserver = new _ConnectionStreamObserver(this, conn);
     conn.initialize(this._userAgent, this._token, streamObserver);
-    conn._id = sessionId;
     conn._release = () => release(hostPort, conn);
 
-    this._openSessions[sessionId] = conn;
+    this._openConnections[conn.id] = conn;
     return conn;
   }
 
@@ -145,12 +157,12 @@ class Driver {
   }
 
   /**
-   * Dispose of a live session, closing any associated resources.
-   * @return {Session} new session.
+   * Dispose of a connection.
+   * @return {Connection} the connection to dispose.
    * @access private
    */
   _destroyConnection(conn) {
-    delete this._openSessions[conn._id];
+    delete this._openConnections[conn.id];
     conn.close();
   }
 
@@ -224,9 +236,11 @@ class Driver {
    * @return undefined
    */
   close() {
-    for (let sessionId in this._openSessions) {
-      if (this._openSessions.hasOwnProperty(sessionId)) {
-        this._openSessions[sessionId].close();
+    this._log.info(`Driver ${this._id} closing`);
+
+    for (let connectionId in this._openConnections) {
+      if (this._openConnections.hasOwnProperty(connectionId)) {
+        this._openConnections[connectionId].close();
       }
       this._pool.purgeAll();
     }

src/v1/index.js

@@ -68,6 +68,14 @@ const auth = {
 };
 const USER_AGENT = "neo4j-javascript/" + VERSION;
 
+/**
+ * Object containing predefined logger implementations. These are expected to be used as values of the driver config's <code>logger</code> property.
+ * @property {function(level: string, message: string)} console the logger function that outputs timestamp, log level and message to <code>console.log()</code>
+ */
+const logger = {
+  console: (level, message) => console.log(`${global.Date.now()} ${level.toUpperCase()} ${message}`)
+};
+
 /**
  * Construct a new Neo4j Driver. This is your main entry point for this
  * library.
@@ -172,6 +180,13 @@ const USER_AGENT = "neo4j-javascript/" + VERSION;
  *       // Default value for this option is <code>false</code> because native JavaScript numbers might result
  *       // in loss of precision in the general case.
  *       disableLosslessIntegers: false,
+ *
+ *       // Specify the logger function for this driver. Function should take two arguments:
+ *       //   1) <code>level</code> - string representing the log level. Supported levels are: 'error', 'warn', 'info' and 'debug'
+ *       //   2) <code>message</code> - string representing the log message.
+ *       // Function should not execute any blocking or long-running operations because it is often executed on a hot path.
+ *       // No logging is done by default. See <code>neo4j.logger</code> object that contains predefined logger implementations.
+ *       logger: (level, message) => console.log(level + ' ' + message),
  *     }
  *
  * @param {string} url The URL for the Neo4j database, for instance "bolt://localhost"
@@ -280,6 +295,7 @@ const forExport = {
   integer,
   Neo4jError,
   auth,
+  logger,
   types,
   session,
   error,
@@ -301,6 +317,7 @@ export {
   integer,
   Neo4jError,
   auth,
+  logger,
   types,
   session,
   error,

src/v1/internal/ch-node.js

@@ -372,7 +372,6 @@ class NodeChannel {
     if( this._pending !== null ) {
       this._pending.push( buffer );
     } else if( buffer instanceof NodeBuffer ) {
-      // console.log( "[Conn#"+this.id+"] SEND: ", buffer.toString() );
       this._conn.write( buffer._buffer );
     } else {
       throw newError( "Don't know how to write: " + buffer );

src/v1/internal/connection-providers.js

@@ -60,7 +60,7 @@ export class DirectConnectionProvider extends ConnectionProvider {
 
 export class LoadBalancer extends ConnectionProvider {
 
-  constructor(hostPort, routingContext, connectionPool, loadBalancingStrategy, driverOnErrorCallback) {
+  constructor(hostPort, routingContext, connectionPool, loadBalancingStrategy, driverOnErrorCallback, log) {
     super();
     this._seedRouter = hostPort;
     this._routingTable = new RoutingTable([this._seedRouter]);
@@ -69,6 +69,7 @@ export class LoadBalancer extends ConnectionProvider {
     this._driverOnErrorCallback = driverOnErrorCallback;
     this._hostNameResolver = LoadBalancer._createHostNameResolver();
     this._loadBalancingStrategy = loadBalancingStrategy;
+    this._log = log;
     this._useSeedRouter = false;
   }
 
@@ -111,6 +112,7 @@ export class LoadBalancer extends ConnectionProvider {
     if (!currentRoutingTable.isStaleFor(accessMode)) {
       return Promise.resolve(currentRoutingTable);
     }
+    this._log.info(`Routing table is stale for ${accessMode}: ${currentRoutingTable}`);
     return this._refreshRoutingTable(currentRoutingTable);
   }
 
@@ -235,6 +237,7 @@ export class LoadBalancer extends ConnectionProvider {
 
     // make this driver instance aware of the new table
     this._routingTable = newRoutingTable;
+    this._log.info(`Updated routing table ${newRoutingTable}`);
   }
 
   static _forgetRouter(routingTable, routersArray, routerIndex) {