2014-02-17 09:54:20 -05:00
|
|
|
bunyan = require('bunyan')
|
|
|
|
|
|
|
|
module.exports = Logger =
|
|
|
|
initialize: (name) ->
|
|
|
|
@logger = bunyan.createLogger
|
|
|
|
name: name
|
|
|
|
serializers: bunyan.stdSerializers
|
|
|
|
return @
|
2016-03-29 07:53:16 -04:00
|
|
|
|
2015-12-08 05:30:18 -05:00
|
|
|
initializeErrorReporting: (sentry_dsn, options) ->
|
2015-06-16 11:50:18 -04:00
|
|
|
raven = require "raven"
|
2015-12-08 05:30:18 -05:00
|
|
|
@raven = new raven.Client(sentry_dsn, options)
|
2017-02-23 04:42:01 -05:00
|
|
|
@lastErrorTimeStamp = 0 # for rate limiting on sentry reporting
|
2017-03-23 09:49:01 -04:00
|
|
|
@lastErrorCount = 0
|
2016-03-29 07:53:16 -04:00
|
|
|
|
|
|
|
captureException: (attributes, message, level) ->
|
2016-04-01 10:35:14 -04:00
|
|
|
# handle case of logger.error "message"
|
|
|
|
if typeof attributes is 'string'
|
2016-04-01 10:52:28 -04:00
|
|
|
attributes = {err: new Error(attributes)}
|
2016-04-01 10:35:14 -04:00
|
|
|
# extract any error object
|
|
|
|
error = attributes.err or attributes.error
|
2018-11-02 11:53:21 -04:00
|
|
|
# avoid reporting errors twice
|
|
|
|
for key, value of attributes
|
|
|
|
return if value instanceof Error && value.reportedToSentry
|
2016-04-01 10:52:28 -04:00
|
|
|
# include our log message in the error report
|
2016-04-01 10:35:14 -04:00
|
|
|
if not error?
|
|
|
|
error = {message: message} if typeof message is 'string'
|
|
|
|
else if message?
|
2016-04-01 10:52:28 -04:00
|
|
|
attributes.description = message
|
2016-04-01 10:35:14 -04:00
|
|
|
# report the error
|
2016-03-29 07:53:16 -04:00
|
|
|
if error?
|
2016-04-01 10:35:14 -04:00
|
|
|
# capture attributes and use *_id objects as tags
|
2016-03-29 07:53:16 -04:00
|
|
|
tags = {}
|
|
|
|
extra = {}
|
|
|
|
for key, value of attributes
|
|
|
|
tags[key] = value if key.match(/_id/) and typeof value == 'string'
|
|
|
|
extra[key] = value
|
|
|
|
# capture req object if available
|
2016-04-01 10:35:14 -04:00
|
|
|
req = attributes.req
|
2016-03-29 07:53:16 -04:00
|
|
|
if req?
|
|
|
|
extra.req =
|
|
|
|
method: req.method
|
|
|
|
url: req.originalUrl
|
|
|
|
query: req.query
|
|
|
|
headers: req.headers
|
|
|
|
ip: req.ip
|
|
|
|
# recreate error objects that have been converted to a normal object
|
|
|
|
if !(error instanceof Error) and typeof error is "object"
|
|
|
|
newError = new Error(error.message)
|
|
|
|
for own key, value of error
|
|
|
|
newError[key] = value
|
|
|
|
error = newError
|
2018-11-06 03:36:54 -05:00
|
|
|
# filter paths from the message to avoid duplicate errors in sentry
|
|
|
|
# (e.g. errors from `fs` methods which have a path attribute)
|
|
|
|
try
|
|
|
|
error.message = error.message.replace(" '#{error.path}'", '') if error.path
|
2016-03-29 07:53:16 -04:00
|
|
|
# send the error to sentry
|
2017-03-03 11:05:56 -05:00
|
|
|
try
|
|
|
|
@raven.captureException(error, {tags: tags, extra: extra, level: level})
|
2018-11-02 11:53:21 -04:00
|
|
|
# put a flag on the errors to avoid reporting them multiple times
|
|
|
|
for key, value of attributes
|
|
|
|
value.reportedToSentry = true if value instanceof Error
|
2017-03-03 11:05:56 -05:00
|
|
|
catch
|
|
|
|
return # ignore any errors
|
2016-03-29 07:53:16 -04:00
|
|
|
|
2017-12-07 04:36:12 -05:00
|
|
|
debug : () ->
|
|
|
|
@logger.debug.apply(@logger, arguments)
|
2014-02-17 09:54:20 -05:00
|
|
|
info : ()->
|
|
|
|
@logger.info.apply(@logger, arguments)
|
|
|
|
log : ()->
|
|
|
|
@logger.info.apply(@logger, arguments)
|
2016-03-29 07:53:16 -04:00
|
|
|
error: (attributes, message, args...)->
|
|
|
|
@logger.error(attributes, message, args...)
|
2017-02-22 10:53:52 -05:00
|
|
|
if @raven?
|
2017-03-23 09:49:01 -04:00
|
|
|
MAX_ERRORS = 5 # maximum number of errors in 1 minute
|
2017-02-22 10:53:52 -05:00
|
|
|
now = new Date()
|
2017-03-23 09:49:01 -04:00
|
|
|
# have we recently reported an error?
|
|
|
|
recentSentryReport = (now - @lastErrorTimeStamp) < 60 * 1000
|
|
|
|
# if so, increment the error count
|
|
|
|
if recentSentryReport
|
|
|
|
@lastErrorCount++
|
|
|
|
else
|
|
|
|
@lastErrorCount = 0
|
2017-02-22 10:53:52 -05:00
|
|
|
@lastErrorTimeStamp = now
|
2017-03-23 09:49:01 -04:00
|
|
|
# only report 5 errors every minute to avoid overload
|
2017-03-29 08:34:55 -04:00
|
|
|
if @lastErrorCount < MAX_ERRORS
|
2017-03-23 09:49:01 -04:00
|
|
|
# add a note if the rate limit has been hit
|
2017-03-29 08:34:55 -04:00
|
|
|
note = if @lastErrorCount+1 is MAX_ERRORS then "(rate limited)" else ""
|
2017-03-23 09:49:01 -04:00
|
|
|
# report the exception
|
|
|
|
@captureException(attributes, message, "error#{note}")
|
2016-03-29 07:53:16 -04:00
|
|
|
err: () ->
|
|
|
|
@error.apply(this, arguments)
|
2014-02-17 09:54:20 -05:00
|
|
|
warn: ()->
|
|
|
|
@logger.warn.apply(@logger, arguments)
|
2016-03-29 07:53:16 -04:00
|
|
|
fatal: (attributes, message, callback) ->
|
|
|
|
@logger.fatal(attributes, message)
|
|
|
|
if @raven?
|
|
|
|
cb = (e) -> # call the callback once after 'logged' or 'error' event
|
|
|
|
callback()
|
|
|
|
cb = () ->
|
|
|
|
@captureException(attributes, message, "fatal")
|
|
|
|
@raven.once 'logged', cb
|
|
|
|
@raven.once 'error', cb
|
|
|
|
else
|
|
|
|
callback()
|
2014-02-17 09:54:20 -05:00
|
|
|
|
|
|
|
Logger.initialize("default-sharelatex")
|