fix(config): restore custom logger feature

lib/agent.js

@@ -5,7 +5,7 @@ var parseUrl = require('url').parse
 var path = require('path')
 
 var afterAll = require('after-all-results')
-var debug = require('debug')('elastic-apm')
+var consoleLogLevel = require('console-log-level')
 var ElasticAPMHttpClient = require('elastic-apm-http-client')
 var isError = require('core-util-is').isError
 var ancestors = require('require-ancestors')
@@ -15,7 +15,6 @@ var config = require('./config')
 var connect = require('./middleware/connect')
 var Filters = require('./filters')
 var Instrumentation = require('./instrumentation')
-var logger = require('./logger')
 var parsers = require('./parsers')
 var request = require('./request')
 var stackman = require('./stackman')
@@ -62,13 +61,22 @@ Agent.prototype.buildSpan = function () {
 }
 
 Agent.prototype._config = function (opts) {
+  if (opts && opts.logger) {
+    this.logger = opts.logger
+    delete opts.logger
+  }
+
   this._conf = config(opts)
 
   this._conf.serverHost = this._conf.serverUrl
     ? parseUrl(this._conf.serverUrl).hostname
     : 'localhost'
 
-  logger.init({level: this._conf.logLevel})
+  if (!this.logger) {
+    this.logger = consoleLogLevel({
+      level: this._conf.logLevel
+    })
+  }
 }
 
 Agent.prototype.start = function (opts) {
@@ -79,14 +87,14 @@ Agent.prototype.start = function (opts) {
   this._filters.config(this._conf)
 
   if (!this._conf.active) {
-    logger.info('Elastic APM agent is inactive due to configuration')
+    this.logger.info('Elastic APM agent is inactive due to configuration')
     return this
   } else if (!this._conf.serviceName) {
-    logger.error('Elastic APM isn\'t correctly configured: Missing serviceName')
+    this.logger.error('Elastic APM isn\'t correctly configured: Missing serviceName')
     this._conf.active = false
     return this
   } else if (!/^[a-zA-Z0-9 _-]+$/.test(this._conf.serviceName)) {
-    logger.error('Elastic APM isn\'t correctly configured: serviceName "%s" contains invalid characters! (allowed: a-z, A-Z, 0-9, _, -, <space>)', this._conf.serviceName)
+    this.logger.error('Elastic APM isn\'t correctly configured: serviceName "%s" contains invalid characters! (allowed: a-z, A-Z, 0-9, _, -, <space>)', this._conf.serviceName)
     this._conf.active = false
     return this
   } else if (process.env.DEBUG) {
@@ -99,7 +107,7 @@ Agent.prototype.start = function (opts) {
       var pkg = require(path.join(basedir, 'package.json'))
     } catch (e) {}
 
-    debug('agent configured correctly %o', {
+    this.logger.debug('agent configured correctly %o', {
       pid: process.pid,
       ppid: process.ppid,
       arch: process.arch,
@@ -152,7 +160,7 @@ Agent.prototype.setTag = function (key, value) {
 
 Agent.prototype.addFilter = function (fn) {
   if (typeof fn !== 'function') {
-    logger.error('Can\'t add filter of type %s', typeof fn)
+    this.logger.error('Can\'t add filter of type %s', typeof fn)
     return
   }
 
@@ -234,7 +242,7 @@ Agent.prototype.captureError = function (err, opts, cb) {
       // from. This can make it easier to debug async stack traces.
       stackman.callsites(captureLocation, function (_err, callsites) {
         if (_err) {
-          debug('error while getting capture location callsites: %s', _err.message)
+          agent.logger.debug('error while getting capture location callsites: %s', _err.message)
         }
 
         var next = afterAll(function (_, frames) {
@@ -254,7 +262,7 @@ Agent.prototype.captureError = function (err, opts, cb) {
 
         if (callsites) {
           callsites.forEach(function (callsite) {
-            parsers.parseCallsite(callsite, true, agent._conf, next())
+            parsers.parseCallsite(callsite, true, agent, next())
           })
         }
       })
@@ -264,7 +272,7 @@ Agent.prototype.captureError = function (err, opts, cb) {
   }
 
   function send (error) {
-    logger.info('logging error %s with Elastic APM', id)
+    agent.logger.info('logging error %s with Elastic APM', id)
     request.errors(agent, [error], cb)
   }
 }
@@ -281,7 +289,7 @@ Agent.prototype.handleUncaughtExceptions = function (cb) {
   }
 
   this._uncaughtExceptionListener = function (err) {
-    debug('Elastic APM caught unhandled exception: %s', err.message)
+    agent.logger.debug('Elastic APM caught unhandled exception: %s', err.message)
     agent.captureError(err, {handled: false}, function () {
       cb ? cb(err) : process.exit(1)
     })

lib/instrumentation/http-shared.js

@@ -3,16 +3,15 @@
 var url = require('url')
 
 var endOfStream = require('end-of-stream')
-var debug = require('debug')('elastic-apm')
 
 exports.instrumentRequest = function (agent, moduleName) {
   return function (orig) {
     return function (event, req, res) {
       if (event === 'request') {
-        debug('intercepted request event call to %s.Server.prototype.emit', moduleName)
+        agent.logger.debug('intercepted request event call to %s.Server.prototype.emit', moduleName)
 
         if (isRequestBlacklisted(agent, req)) {
-          debug('ignoring blacklisted request to %s', req.url)
+          agent.logger.debug('ignoring blacklisted request to %s', req.url)
           // don't leak previous transaction
           agent._instrumentation.currentTransaction = null
         } else {
@@ -79,16 +78,16 @@ exports.traceOutgoingRequest = function (agent, moduleName) {
       var span = agent.buildSpan()
       var id = span && span.transaction.id
 
-      debug('intercepted call to %s.request %o', moduleName, {id: id})
+      agent.logger.debug('intercepted call to %s.request %o', moduleName, {id: id})
 
       var req = orig.apply(this, arguments)
       if (!span) return req
       if (req._headers.host === agent._conf.serverHost) {
-        debug('ignore %s request to intake API %o', moduleName, {id: id})
+        agent.logger.debug('ignore %s request to intake API %o', moduleName, {id: id})
         return req
       } else {
         var protocol = req.agent && req.agent.protocol
-        debug('request details: %o', {protocol: protocol, host: req._headers.host, id: id})
+        agent.logger.debug('request details: %o', {protocol: protocol, host: req._headers.host, id: id})
       }
 
       var name = req.method + ' ' + req._headers.host + url.parse(req.path).pathname
@@ -98,7 +97,7 @@ exports.traceOutgoingRequest = function (agent, moduleName) {
       return req
 
       function onresponse (res) {
-        debug('intercepted http.ClientRequest response event %o', {id: id})
+        agent.logger.debug('intercepted http.ClientRequest response event %o', {id: id})
 
         // Inspired by:
         // https://github.com/nodejs/node/blob/9623ce572a02632b7596452e079bba066db3a429/lib/events.js#L258-L274
@@ -119,7 +118,7 @@ exports.traceOutgoingRequest = function (agent, moduleName) {
         }
 
         function onEnd () {
-          debug('intercepted http.IncomingMessage end event %o', {id: id})
+          agent.logger.debug('intercepted http.IncomingMessage end event %o', {id: id})
           span.end()
         }
       }

lib/instrumentation/index.js

@@ -4,11 +4,9 @@ var fs = require('fs')
 var path = require('path')
 
 var AsyncValuePromise = require('async-value-promise')
-var debug = require('debug')('elastic-apm')
 var hook = require('require-in-the-middle')
 var semver = require('semver')
 
-var logger = require('../logger')
 var Queue = require('../queue')
 var request = require('../request')
 var Transaction = require('./transaction')
@@ -32,7 +30,8 @@ Instrumentation.prototype.start = function () {
 
   var qopts = {
     flushInterval: this._agent._conf.flushInterval,
-    maxQueueSize: this._agent._conf.maxQueueSize
+    maxQueueSize: this._agent._conf.maxQueueSize,
+    logger: this._agent.logger
   }
   this._queue = new Queue(qopts, function onFlush (transactions, done) {
     AsyncValuePromise.all(transactions).then(function (transactions) {
@@ -48,7 +47,7 @@ Instrumentation.prototype.start = function () {
     require('./patch-async')(this)
   }
 
-  debug('shimming Module._load function')
+  this._agent.logger.debug('shimming Module._load function')
   hook(MODULES, function (exports, name, basedir) {
     var pkg, version
 
@@ -57,14 +56,14 @@ Instrumentation.prototype.start = function () {
       try {
         version = JSON.parse(fs.readFileSync(pkg)).version
       } catch (e) {
-        debug('could not shim %s module: %s', name, e.message)
+        self._agent.logger.debug('could not shim %s module: %s', name, e.message)
         return exports
       }
     } else {
       version = process.versions.node
     }
 
-    debug('shimming %s@%s module', name, version)
+    self._agent.logger.debug('shimming %s@%s module', name, version)
     return require('./modules/' + name)(exports, self._agent, version)
   })
 }
@@ -73,12 +72,12 @@ Instrumentation.prototype.addEndedTransaction = function (transaction) {
   if (this._started) {
     var queue = this._queue
 
-    debug('adding transaction to queue %o', {id: transaction.id})
+    this._agent.logger.debug('adding transaction to queue %o', {id: transaction.id})
 
     var payload = new AsyncValuePromise()
 
     payload.catch(function (err) {
-      logger.error('error encoding transaction %s: %s', transaction.id, err.message)
+      this._agent.logger.error('error encoding transaction %s: %s', transaction.id, err.message)
     })
 
     // encode the transaction as early as possible in an attempt to free up
@@ -92,7 +91,7 @@ Instrumentation.prototype.addEndedTransaction = function (transaction) {
 
     queue.add(payload)
   } else {
-    debug('ignoring transaction %o', {id: transaction.id})
+    this._agent.logger.debug('ignoring transaction %o', {id: transaction.id})
   }
 }
 
@@ -101,25 +100,34 @@ Instrumentation.prototype.startTransaction = function (name, type) {
 }
 
 Instrumentation.prototype.endTransaction = function () {
-  if (!this.currentTransaction) return debug('cannot end transaction - no active transaction found')
+  if (!this.currentTransaction) {
+    this._agent.logger.debug('cannot end transaction - no active transaction found')
+    return
+  }
   this.currentTransaction.end()
 }
 
 Instrumentation.prototype.setDefaultTransactionName = function (name) {
   var trans = this.currentTransaction
-  if (!trans) return debug('no active transaction found - cannot set default transaction name')
+  if (!trans) {
+    this._agent.logger.debug('no active transaction found - cannot set default transaction name')
+    return
+  }
   trans.setDefaultName(name)
 }
 
 Instrumentation.prototype.setTransactionName = function (name) {
   var trans = this.currentTransaction
-  if (!trans) return debug('no active transaction found - cannot set transaction name')
+  if (!trans) {
+    this._agent.logger.debug('no active transaction found - cannot set transaction name')
+    return
+  }
   trans.name = name
 }
 
 Instrumentation.prototype.buildSpan = function () {
   if (!this.currentTransaction) {
-    debug('no active transaction found - cannot build new span')
+    this._agent.logger.debug('no active transaction found - cannot build new span')
     return null
   }
 
@@ -149,7 +157,7 @@ Instrumentation.prototype.bindFunction = function (original) {
 Instrumentation.prototype._recoverTransaction = function (trans) {
   if (this.currentTransaction === trans) return
 
-  debug('recovering from wrong currentTransaction %o', {
+  this._agent.logger.debug('recovering from wrong currentTransaction %o', {
     wrong: this.currentTransaction ? this.currentTransaction.id : undefined,
     correct: trans.id
   })

lib/instrumentation/modules/bluebird.js

@@ -1,6 +1,5 @@
 'use strict'
 
-var debug = require('debug')('elastic-apm')
 var semver = require('semver')
 
 var shimmer = require('../shimmer')
@@ -14,22 +13,22 @@ module.exports = function (bluebird, agent, version) {
   var ins = agent._instrumentation
 
   if (!semver.satisfies(version, '>=2 <4')) {
-    debug('bluebird version %s not supported - aborting...', version)
+    agent.logger.debug('bluebird version %s not supported - aborting...', version)
     return bluebird
   }
 
-  debug('shimming bluebird.prototype functions:', BLUEBIRD_FNS)
+  agent.logger.debug('shimming bluebird.prototype functions:', BLUEBIRD_FNS)
   massWrap(bluebird.prototype, BLUEBIRD_FNS, wrapThen)
 
   // Calling bluebird.config might overwrite the
   // bluebird.prototype._attachCancellationCallback function with a new
   // function. We need to hook into this new function
-  debug('shimming bluebird.config')
+  agent.logger.debug('shimming bluebird.config')
   wrap(bluebird, 'config', function wrapConfig (original) {
     return function wrappedConfig () {
       var result = original.apply(this, arguments)
 
-      debug('shimming bluebird.prototype._attachCancellationCallback')
+      agent.logger.debug('shimming bluebird.prototype._attachCancellationCallback')
       wrap(bluebird.prototype, '_attachCancellationCallback', function wrapAttachCancellationCallback (original) {
         return function wrappedAttachCancellationCallback (onCancel) {
           if (arguments.length !== 1) return original.apply(this, arguments)
@@ -49,15 +48,15 @@ module.exports = function (bluebird, agent, version) {
   //
   //   while :; do node test/instrumentation/modules/bluebird/bluebird.js || exit $?; done
   if (semver.satisfies(version, '<3')) {
-    debug('shimming bluebird.each')
+    agent.logger.debug('shimming bluebird.each')
     wrap(bluebird, 'each', function wrapEach (original) {
       return function wrappedEach (promises, fn) {
         if (arguments.length !== 2) return original.apply(this, arguments)
         return original.call(this, promises, ins.bindFunction(fn))
       }
     })
 
-    debug('shimming bluebird.prototype.each')
+    agent.logger.debug('shimming bluebird.prototype.each')
     wrap(bluebird.prototype, 'each', function wrapEach (original) {
       return function wrappedEach (fn) {
         if (arguments.length !== 1) return original.apply(this, arguments)

lib/instrumentation/modules/elasticsearch.js

@@ -1,13 +1,11 @@
 'use strict'
 
-var debug = require('debug')('elastic-apm')
-
 var shimmer = require('../shimmer')
 
 var searchRegexp = /_search$/
 
 module.exports = function (elasticsearch, agent, version) {
-  debug('shimming elasticsearch.Transport.prototype.request')
+  agent.logger.debug('shimming elasticsearch.Transport.prototype.request')
   shimmer.wrap(elasticsearch.Transport && elasticsearch.Transport.prototype, 'request', wrapRequest)
 
   return elasticsearch
@@ -20,7 +18,7 @@ module.exports = function (elasticsearch, agent, version) {
       var path = params && params.path
       var query = params && params.query
 
-      debug('intercepted call to elasticsearch.Transport.prototype.request %o', {id: id, method: method, path: path})
+      agent.logger.debug('intercepted call to elasticsearch.Transport.prototype.request %o', {id: id, method: method, path: path})
 
       if (span && method && path) {
         span.start('Elasticsearch: ' + method + ' ' + path, 'db.elasticsearch.request')
@@ -47,7 +45,7 @@ module.exports = function (elasticsearch, agent, version) {
           return p
         }
       } else {
-        debug('could not instrument elasticsearch request %o', {id: id})
+        agent.logger.debug('could not instrument elasticsearch request %o', {id: id})
         return original.apply(this, arguments)
       }
     }

lib/instrumentation/modules/express-graphql.js

@@ -1,11 +1,10 @@
 'use strict'
 
-var debug = require('debug')('elastic-apm')
 var semver = require('semver')
 
 module.exports = function (graphqlHTTP, agent, version) {
   if (!semver.satisfies(version, '^0.6.1') || typeof graphqlHTTP !== 'function') {
-    debug('express-graphql version %s not supported - aborting...', version)
+    agent.logger.debug('express-graphql version %s not supported - aborting...', version)
     return graphqlHTTP
   }