Merge pull request #380 from lutovich/1.7-logging

Support configurable logging

Author: ali-ince

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,11 +236,19 @@ 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`);
+
+    try {
+      // purge all idle connections in the connection pool
       this._pool.purgeAll();
+    } finally {
+      // then close all connections driver has ever created
+      // it is needed to close connections that are active right now and are acquired from the pool
+      for (let connectionId in this._openConnections) {
+        if (this._openConnections.hasOwnProperty(connectionId)) {
+          this._openConnections[connectionId].close();
+        }
+      }
     }
   }
 }

src/v1/index.js

@@ -68,6 +68,20 @@ const auth = {
 };
 const USER_AGENT = "neo4j-javascript/" + VERSION;
 
+/**
+ * Object containing predefined logging configurations. These are expected to be used as values of the driver config's <code>logging</code> property.
+ * @property {function(level: ?string): object} console the function to create a logging config that prints all messages to <code>console.log</code> with
+ * timestamp, level and message. It takes an optional <code>level</code> parameter which represents the maximum log level to be logged. Default value is 'info'.
+ */
+const logging = {
+  console: level => {
+    return {
+      level: level,
+      logger: (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 +186,22 @@ 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 logging configuration for the driver. Object should have two properties <code>level</code> and <code>logger</code>.
+ *       //
+ *       // Property <code>level</code> represents the logging level which should be one of: 'error', 'warn', 'info' or 'debug'. This property is optional and
+ *       // its default value is 'info'. Levels have priorities: 'error': 0, 'warn': 1, 'info': 2, 'debug': 3. Enabling a certain level also enables all
+ *       // levels with lower priority. For example: 'error', 'warn' and 'info' will be logged when 'info' level is configured.
+ *       //
+ *       // Property <code>logger</code> represents the logging function which will be invoked for every log call with an acceptable level. The function should
+ *       // take two string arguments <code>level</code> and <code>message</code>. The 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.logging</code> object that contains predefined logging implementations.
+ *       logging: {
+ *         level: 'info',
+ *         logger: (level, message) => console.log(level + ' ' + message)
+ *       },
  *     }
  *
  * @param {string} url The URL for the Neo4j database, for instance "bolt://localhost"
@@ -280,6 +310,7 @@ const forExport = {
   integer,
   Neo4jError,
   auth,
+  logging,
   types,
   session,
   error,
@@ -301,6 +332,7 @@ export {
   integer,
   Neo4jError,
   auth,
+  logging,
   types,
   session,
   error,

src/v1/internal/ch-node.js

@@ -369,7 +369,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) {