logging-manager.js 6.4 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221
  1. /*
  2. * decaffeinate suggestions:
  3. * DS101: Remove unnecessary use of Array.from
  4. * DS102: Remove unnecessary code created because of implicit returns
  5. * DS203: Remove `|| {}` from converted for-own loops
  6. * DS205: Consider reworking code to avoid use of IIFEs
  7. * DS207: Consider shorter variations of null checks
  8. * Full docs: https://github.com/decaffeinate/decaffeinate/blob/master/docs/suggestions.md
  9. */
  10. const bunyan = require('bunyan');
  11. const request = require('request');
  12. const LOG_METHODS = [
  13. 'debug', 'info', 'log', 'error', 'err', 'warn', 'fatal'
  14. ]
  15. class Logger {
  16. constructor(name) {
  17. const isProduction = (process.env['NODE_ENV'] || '').toLowerCase() === 'production';
  18. this.defaultLevel = process.env['LOG_LEVEL'] || (isProduction ? "warn" : "debug");
  19. this.loggerName = name;
  20. this.logger = bunyan.createLogger({
  21. name,
  22. serializers: bunyan.stdSerializers,
  23. level: this.defaultLevel
  24. });
  25. if (isProduction) {
  26. // check for log level override on startup
  27. this.checkLogLevel();
  28. // re-check log level every minute
  29. const checkLogLevel = () => this.checkLogLevel();
  30. setInterval(checkLogLevel, 1000 * 60);
  31. }
  32. return this;
  33. }
  34. checkLogLevel() {
  35. const options = {
  36. headers: {
  37. "Metadata-Flavor": "Google"
  38. },
  39. uri: `http://metadata.google.internal/computeMetadata/v1/project/attributes/${this.loggerName}-setLogLevelEndTime`
  40. };
  41. return request(options, (err, response, body) => {
  42. if (parseInt(body) > Date.now()) {
  43. return this.logger.level('trace');
  44. } else {
  45. return this.logger.level(this.defaultLevel);
  46. }
  47. });
  48. }
  49. initializeErrorReporting(sentry_dsn, options) {
  50. const raven = require("raven");
  51. this.raven = new raven.Client(sentry_dsn, options);
  52. this.lastErrorTimeStamp = 0; // for rate limiting on sentry reporting
  53. return this.lastErrorCount = 0;
  54. }
  55. captureException(attributes, message, level) {
  56. // handle case of logger.error "message"
  57. let key, value;
  58. if (typeof attributes === 'string') {
  59. attributes = {err: new Error(attributes)};
  60. }
  61. // extract any error object
  62. let error = attributes.err || attributes.error;
  63. // avoid reporting errors twice
  64. for (key in attributes) {
  65. value = attributes[key];
  66. if (value instanceof Error && value.reportedToSentry) { return; }
  67. }
  68. // include our log message in the error report
  69. if ((error == null)) {
  70. if (typeof message === 'string') { error = {message}; }
  71. } else if (message != null) {
  72. attributes.description = message;
  73. }
  74. // report the error
  75. if (error != null) {
  76. // capture attributes and use *_id objects as tags
  77. const tags = {};
  78. const extra = {};
  79. for (key in attributes) {
  80. value = attributes[key];
  81. if (key.match(/_id/) && (typeof value === 'string')) { tags[key] = value; }
  82. extra[key] = value;
  83. }
  84. // capture req object if available
  85. const { req } = attributes;
  86. if (req != null) {
  87. extra.req = {
  88. method: req.method,
  89. url: req.originalUrl,
  90. query: req.query,
  91. headers: req.headers,
  92. ip: req.ip
  93. };
  94. }
  95. // recreate error objects that have been converted to a normal object
  96. if (!(error instanceof Error) && (typeof error === "object")) {
  97. const newError = new Error(error.message);
  98. for (key of Object.keys(error || {})) {
  99. value = error[key];
  100. newError[key] = value;
  101. }
  102. error = newError;
  103. }
  104. // filter paths from the message to avoid duplicate errors in sentry
  105. // (e.g. errors from `fs` methods which have a path attribute)
  106. try {
  107. if (error.path) { error.message = error.message.replace(` '${error.path}'`, ''); }
  108. } catch (error1) {}
  109. // send the error to sentry
  110. try {
  111. this.raven.captureException(error, {tags, extra, level});
  112. // put a flag on the errors to avoid reporting them multiple times
  113. return (() => {
  114. const result = [];
  115. for (key in attributes) {
  116. value = attributes[key];
  117. if (value instanceof Error) { result.push(value.reportedToSentry = true); } else {
  118. result.push(undefined);
  119. }
  120. }
  121. return result;
  122. })();
  123. } catch (error2) {
  124. return;
  125. }
  126. }
  127. }
  128. debug() {
  129. return this.logger.debug.apply(this.logger, arguments);
  130. }
  131. info(){
  132. return this.logger.info.apply(this.logger, arguments);
  133. }
  134. log(){
  135. return this.logger.info.apply(this.logger, arguments);
  136. }
  137. error(attributes, message, ...args){
  138. this.logger.error(attributes, message, ...Array.from(args));
  139. if (this.raven != null) {
  140. const MAX_ERRORS = 5; // maximum number of errors in 1 minute
  141. const now = new Date();
  142. // have we recently reported an error?
  143. const recentSentryReport = (now - this.lastErrorTimeStamp) < (60 * 1000);
  144. // if so, increment the error count
  145. if (recentSentryReport) {
  146. this.lastErrorCount++;
  147. } else {
  148. this.lastErrorCount = 0;
  149. this.lastErrorTimeStamp = now;
  150. }
  151. // only report 5 errors every minute to avoid overload
  152. if (this.lastErrorCount < MAX_ERRORS) {
  153. // add a note if the rate limit has been hit
  154. const note = (this.lastErrorCount+1) === MAX_ERRORS ? "(rate limited)" : "";
  155. // report the exception
  156. return this.captureException(attributes, message, `error${note}`);
  157. }
  158. }
  159. }
  160. err() {
  161. return this.error.apply(this, arguments);
  162. }
  163. warn(){
  164. return this.logger.warn.apply(this.logger, arguments);
  165. }
  166. fatal(attributes, message, callback) {
  167. if (callback == null) { callback = function() {}; }
  168. this.logger.fatal(attributes, message);
  169. if (this.raven != null) {
  170. var cb = function(e) { // call the callback once after 'logged' or 'error' event
  171. callback();
  172. return cb = function() {};
  173. };
  174. this.captureException(attributes, message, "fatal");
  175. this.raven.once('logged', cb);
  176. return this.raven.once('error', cb);
  177. } else {
  178. return callback();
  179. }
  180. }
  181. }
  182. let defaultLogger
  183. // initialize default logger if not already initialized
  184. if (!global.__logger_sharelatex__default_logger__) {
  185. global.__logger_sharelatex__default_logger__ = defaultLogger = new Logger("default-sharelatex")
  186. }
  187. else {
  188. defaultLogger = global.__logger_sharelatex__default_logger__
  189. }
  190. // support old interface for creating new Logger instances
  191. Logger.initialize = function initialize(name) {
  192. return new Logger(name)
  193. }
  194. // add a static method for each log method that will use the default logger
  195. for (const logMethod of LOG_METHODS) {
  196. Logger[logMethod] = function () {
  197. return defaultLogger[logMethod].apply(defaultLogger, arguments)
  198. }
  199. }
  200. // return default logger
  201. Logger.defaultLogger = function defaultLogger () {
  202. return defaultLogger
  203. }
  204. module.exports = Logger