fix(config): restore custom logger feature

docs/agent-api.asciidoc

@@ -339,6 +339,7 @@ require('elastic-apm-node').start({
 Set the verbosity level for the agent.
 Note that this does not have any influence on the types of errors that are sent to the APM Server.
 This only controls how chatty the agent is in your logs.
+This only applies when not using a custom logger.
 
 Possible levels are: `trace`, `debug`, `info`, `warn`, `error`, and `fatal`.
 

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
   }