devdep update, log async context loss

[websub-hub] / src / service.js

diff --git a/src/service.js b/src/service.js
index 17fa134d738447deb29aa5e889aaf806cb1443f8..2bd57b0c1a704a0f22b8229a8438779f63bdf28f 100644 (file)
--- a/src/service.js
+++ b/src/service.js
@@ -15,12 +15,12 @@ const path = require('path');
 const _fileScope = common.fileScope(__filename);
 
 class Service extends Dingus {
-  constructor(logger, db, options) {
+  constructor(logger, db, options, asyncLocalStorage) {
     super(logger, {
       ...options.dingus,
       ignoreTrailingSlash: false,
     });
-
+    this.asyncLocalStorage = asyncLocalStorage;
     this.manager = new Manager(logger, db, options);
     this.authenticator = new Authenticator(logger, db, options);
     this.sessionManager = new SessionManager(logger, this.authenticator, options);
@@ -52,6 +52,7 @@ class Service extends Dingus {
     this.on(['GET', 'HEAD'], '/admin', this.handlerRedirect.bind(this), `${options.dingus.proxyPrefix}/admin/`);
     this.on(['GET', 'HEAD'], '/admin/', this.handlerGetAdminOverview.bind(this));
     this.on(['GET', 'HEAD'], '/admin/topic/:topicId', this.handlerGetAdminTopicDetails.bind(this));
+    this.on(['GET', 'HEAD'], '/admin/topic/:topicId/history.svg', this.handlerGetHistorySVG.bind(this));
 
     // Private data-editing endpoints
     this.on(['PATCH', 'DELETE'], '/admin/topic/:topicId', this.handlerUpdateTopic.bind(this));
@@ -68,25 +69,27 @@ class Service extends Dingus {
 
   }
 
+
   /**
-   * Wrap the Dingus head handler, to remove the response body from the context,
-   * lest it be logged.
+   * Rearrange logging data.
    * @param {http.ClientRequest} req
    * @param {http.ServerResponse} res
-   * @param {object} ctx
+   * @param {Object} ctx
    */
-  static setHeadHandler(req, res, ctx) {
-    if (req.method === 'HEAD') {
-      Dingus.setHeadHandler(req, res, ctx);
-      const origEnd = res.end.bind(res);
-      res.end = function (data, encoding, ...rest) {
-        const origResult = origEnd(data, encoding, ...rest);
-        delete ctx.responseBody;
-        return origResult;
-      };
+  async preHandler(req, res, ctx) {
+    await super.preHandler(req, res, ctx);
+    const logObject = this.asyncLocalStorage.getStore();
+    // FIXME: for some reason, returning from the super.preHandler sometimes loses async context?
+    // Workaround until cause and solution are found.
+    if (logObject) {
+      logObject.requestId = ctx.requestId;
+      delete ctx.requestId;
+    } else {
+      this.logger.debug(_fileScope('preHandler'), 'lost async context', { req, ctx });
     }
   }
 
+
   /**
    * @param {http.ClientRequest} req
    * @param {http.ServerResponse} res
@@ -94,7 +97,7 @@ class Service extends Dingus {
    */
   async handlerPostRoot(req, res, ctx) {
     const _scope = _fileScope('handlerPostRoot');
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
 
     this.setResponseType(this.responseTypes, req, res, ctx);
     await this.ingestBody(req, res, ctx);
@@ -113,9 +116,9 @@ class Service extends Dingus {
     const responseTypes = [
       Enum.ContentType.TextHTML,
     ];
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
 
-    Service.setHeadHandler(req, res, ctx);
+    Dingus.setHeadHandler(req, res, ctx);
 
     this.setResponseType(responseTypes, req, res, ctx);
 
@@ -132,9 +135,9 @@ class Service extends Dingus {
    */
   async handlerGetHealthcheck(req, res, ctx) {
     const _scope = _fileScope('handlerGetHealthcheck');
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
   
-    Service.setHeadHandler(req, res, ctx);
+    Dingus.setHeadHandler(req, res, ctx);
 
     this.setResponseType(this.responseTypes, req, res, ctx);
 
@@ -149,11 +152,11 @@ class Service extends Dingus {
    */
   async handlerGetInfo(req, res, ctx) {
     const _scope = _fileScope('handlerGetInfo');
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
 
     const responseTypes = [...this.responseTypes, Enum.ContentType.ImageSVG];
 
-    Service.setHeadHandler(req, res, ctx);
+    Dingus.setHeadHandler(req, res, ctx);
 
     this.setResponseType(responseTypes, req, res, ctx);
 
@@ -161,6 +164,20 @@ class Service extends Dingus {
   }
 
 
+  async handlerGetHistorySVG(req, res, ctx) {
+    const _scope = _fileScope('handlerGetHist');
+    this.logger.debug(_scope, 'called', { req, ctx });
+
+    const responseTypes = [Enum.ContentType.ImageSVG];
+
+    Dingus.setHeadHandler(req, res, ctx);
+
+    this.setResponseType(responseTypes, req, res, ctx);
+
+    await this.manager.getHistorySVG(res, ctx);
+  }
+
+
   /**
    * @param {http.ClientRequest} req
    * @param {http.ServerResponse} res
@@ -168,15 +185,15 @@ class Service extends Dingus {
    */
   async handlerGetAdminOverview(req, res, ctx) {
     const _scope = _fileScope('handlerGetAdminOverview');
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
 
-    Service.setHeadHandler(req, res, ctx);
+    Dingus.setHeadHandler(req, res, ctx);
 
     this.setResponseType(this.responseTypes, req, res, ctx);
 
-    await this.authenticator.sessionRequired(req, res, ctx, this.loginPath);
-
-    await this.manager.getAdminOverview(res, ctx);
+    if (await this.authenticator.sessionRequired(req, res, ctx, this.loginPath)) {
+      await this.manager.getAdminOverview(res, ctx);
+    }
   }
 
 
@@ -187,33 +204,28 @@ class Service extends Dingus {
    */
   async handlerGetAdminTopicDetails(req, res, ctx) {
     const _scope = _fileScope('handlerGetAdminTopicDetails');
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
 
-    Service.setHeadHandler(req, res, ctx);
+    Dingus.setHeadHandler(req, res, ctx);
 
     this.setResponseType(this.responseTypes, req, res, ctx);
 
-    await this.authenticator.sessionRequired(req, res, ctx, this.loginPath);
-
-    await this.manager.getTopicDetails(res, ctx);
+    if (await this.authenticator.sessionRequired(req, res, ctx, this.loginPath)) {
+      await this.manager.getTopicDetails(res, ctx);
+    }
   }
 
 
   /**
-   * Similar to super.ingestBody, but if no body was sent, do not parse (and
-   * thus avoid possible unsupported media type error).
-   * Also removes raw body from context, to simplify scrubbing sensitive data from logs.
+   * If no body was sent, do not parse (and thus avoid possible unsupported media type error).
    * @param {http.ClientRequest} req
    * @param {http.ServerResponse} res
    * @param {Object} ctx
    */
   async maybeIngestBody(req, res, ctx) {
-    ctx.rawBody = await this.bodyData(req);
-    const contentType = Dingus.getRequestContentType(req);
-    if (ctx.rawBody) {
-      this.parseBody(contentType, ctx);
-      delete ctx.rawBody;
-    }
+    return super.ingestBody(req, res, ctx, {
+      parseEmptyBody: false,
+    });
   }
 
 
@@ -224,7 +236,7 @@ class Service extends Dingus {
    */
   async handlerUpdateTopic(req, res, ctx) {
     const _scope = _fileScope('handlerUpdateTopic');
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
 
     this.setResponseType(this.responseTypes, req, res, ctx);
 
@@ -243,7 +255,7 @@ class Service extends Dingus {
    */
   async handlerUpdateSubscription(req, res, ctx) {
     const _scope = _fileScope('handlerUpdateSubscription');
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
 
     this.setResponseType(this.responseTypes, req, res, ctx);
 
@@ -262,7 +274,7 @@ class Service extends Dingus {
    */
   async handlerPostAdminProcess(req, res, ctx) {
     const _scope = _fileScope('handlerPostAdminProcess');
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
 
     this.setResponseType(this.responseTypes, req, res, ctx);
 
@@ -280,9 +292,9 @@ class Service extends Dingus {
    */
   async handlerGetAdminLogin(req, res, ctx) {
     const _scope = _fileScope('handlerGetAdminLogin');
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
 
-    Service.setHeadHandler(req, res, ctx);
+    Dingus.setHeadHandler(req, res, ctx);
 
     this.setResponseType(this.responseTypes, req, res, ctx);
 
@@ -298,7 +310,7 @@ class Service extends Dingus {
    */
   async handlerPostAdminLogin(req, res, ctx) {
     const _scope = _fileScope('handlerPostAdminLogin');
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
 
     this.setResponseType(this.responseTypes, req, res, ctx);
 
@@ -318,7 +330,7 @@ class Service extends Dingus {
    */
   async handlerGetAdminLogout(req, res, ctx) {
     const _scope = _fileScope('handlerGetAdminLogout');
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
 
     this.setResponseType(this.responseTypes, req, res, ctx);
 
@@ -336,7 +348,7 @@ class Service extends Dingus {
    */
   async handlerGetAdminIA(req, res, ctx) {
     const _scope = _fileScope('handlerGetAdminIA');
-    this.logger.debug(_scope, 'called', { req: common.requestLogData(req), ctx });
+    this.logger.debug(_scope, 'called', { req, ctx });
 
     this.setResponseType(this.responseTypes, req, res, ctx);