93

The title should be pretty self explanetory.

For debugging purposes, I would like express to print the response code and body for every request serviced. Printing the response code is easy enough, but printing the response body is trickier, since it seems the response body is not readily available as a property.

The following does NOT work:

var express = require('express');
var app = express();

// define custom logging format
express.logger.format('detailed', function (token, req, res) {                                    
    return req.method + ': ' + req.path + ' -> ' + res.statusCode + ': ' + res.body + '\n';
});  

// register logging middleware and use custom logging format
app.use(express.logger('detailed'));

// setup routes
app.get(..... omitted ...);

// start server
app.listen(8080);

Of course, I could easily print the responses at the client who emitted the request, but I would prefer doing at the server side too.

PS: If it helps, all my responses are json, but hopefully there is a solution that works with general responses.

13 Answers 13

117

Not sure if it's the simplest solution, but you can write a middleware to intercept data written to the response. Make sure you disable app.compress().

function logResponseBody(req, res, next) {
  var oldWrite = res.write,
      oldEnd = res.end;

  var chunks = [];

  res.write = function (chunk) {
    chunks.push(chunk);

    return oldWrite.apply(res, arguments);
  };

  res.end = function (chunk) {
    if (chunk)
      chunks.push(chunk);

    var body = Buffer.concat(chunks).toString('utf8');
    console.log(req.path, body);

    oldEnd.apply(res, arguments);
  };

  next();
}

app.use(logResponseBody);
13
  • 2
    Similar, slightly more detailed solution in use here: github.com/SummerWish/express-minify/blob/master/minify.js#L270
    – Billy Moon
    Commented Oct 26, 2015 at 23:36
  • 6
    @keegans-hairstyle-82, res.statusCode To all: don't rewrite using arrow functions - oldEnd.apply needs to be rewritten then.
    – reconsio
    Commented Aug 21, 2017 at 11:43
  • 8
    Sometimes the chunks might be strings, so in order to process them without errors, use var body = Buffer.concat(chunks.map(x => (typeof (x) === "string" ? Buffer.from(x, 'binary') : x))).toString('utf8'); Commented Nov 6, 2019 at 20:36
  • 2
    Strangely, the response is captured only when request is made via postman client and not from browser.
    – npr
    Commented Dec 3, 2019 at 10:07
  • 3
    @npr you can intercept header and edit "cache-control" with the code const { rawHeaders, headers } = req; headers["cache-control"] = "no-cache" postman adds this to it's headers automatically. Commented Apr 19, 2021 at 15:29
31

I ran into an issue using the approach suggested by Laurent. Sometimes chunk is a string, and therefore causes problems in the call to Buffer.concat(). Anyways, I found a slight modification fixed things:

function logResponseBody(req, res, next) {
  var oldWrite = res.write,
      oldEnd = res.end;

  var chunks = [];

  res.write = function (chunk) {
    chunks.push(new Buffer(chunk));

    oldWrite.apply(res, arguments);
  };

  res.end = function (chunk) {
    if (chunk)
      chunks.push(new Buffer(chunk));

    var body = Buffer.concat(chunks).toString('utf8');
    console.log(req.path, body);

    oldEnd.apply(res, arguments);
  };

  next();
}

app.use(logResponseBody);
4
  • I just realized that I did it somehow in very short way. But deleted the code since it was printing byte array. I should have converted it to string. :( Commented Feb 5, 2016 at 11:03
  • Doing that, will I lost the original res behavior (res.write, res.send, res.end ...)? Would this be avoided by applying oldEnd.apply(res, arguments)? Thank you very much. Commented Jul 8, 2019 at 19:02
  • Disclaimer that this will get very ugly if you are uploading files in your application. It will log every chunk of eg. a 200KB file (which is a lot of logging) and will also slow down file upload. Make sure to guard the logger not to log responses for request that come from eg. an /fileUpload path
    – user10706046
    Commented Aug 22, 2019 at 13:54
  • @Drew Do you know how can I send the different response.json from res.end function
    – Loki
    Commented Jul 3 at 1:15
28

The above accepted code has issues with ES6. Use the below code

function logReqRes(req, res, next) {
  const oldWrite = res.write;
  const oldEnd = res.end;

  const chunks = [];

  res.write = (...restArgs) => {
    chunks.push(Buffer.from(restArgs[0]));
    oldWrite.apply(res, restArgs);
  };

  res.end = (...restArgs) => {
    if (restArgs[0]) {
      chunks.push(Buffer.from(restArgs[0]));
    }
    const body = Buffer.concat(chunks).toString('utf8');

    console.log({
      time: new Date().toUTCString(),
      fromIP: req.headers['x-forwarded-for'] || 
      req.connection.remoteAddress,
      method: req.method,
      originalUri: req.originalUrl,
      uri: req.url,
      requestData: req.body,
      responseData: body,
      referer: req.headers.referer || '',
      ua: req.headers['user-agent']
    });

    // console.log(body);
    oldEnd.apply(res, restArgs);
  };

  next();
}

module.exports = logReqRes;
3
24

This solution might not be heavyweight enough for some use cases, but I think it's the simplest. It's also typescript compatible. If you only want logging for JSON responses, all you have to do is substitute the send method with the json method in the code below. Note, I took inspiration from Jonathan Turnock's answer, but made it simpler.

app.use((req, res, next) => {
    let send = res.send;
    res.send = c => {
        console.log(`Code: ${res.statusCode}`);
        console.log("Body: ", c);
        res.send = send;
        return res.send(c);
    }
    next();
});

1
17

You can use express-winston and configure using:

expressWinston.requestWhitelist.push('body');
expressWinston.responseWhitelist.push('body');

Example in coffeescript:

expressWinston.requestWhitelist.push('body')
expressWinston.responseWhitelist.push('body')
app.use(expressWinston.logger({
      transports: [
        new winston.transports.Console({
          json: true,
          colorize: true
        })
      ],
      meta: true, // optional: control whether you want to log the meta data about the request (default to true)
      msg: "HTTP {{req.method}} {{req.url}}", // optional: customize the default logging message. E.g. "{{res.statusCode}} {{req.method}} {{res.responseTime}}ms {{req.url}}"
      expressFormat: true, // Use the default Express/morgan request formatting, with the same colors. Enabling this will override any msg and colorStatus if true. Will only output colors on transports with colorize set to true
      colorStatus: true, // Color the status code, using the Express/morgan color palette (default green, 3XX cyan, 4XX yellow, 5XX red). Will not be recognized if expressFormat is true
      ignoreRoute: function (req, res) { return false; } // optional: allows to skip some log messages based on request and/or response
    }));
3
  • 1
    doesn't log response
    – grabantot
    Commented Jul 21, 2018 at 4:00
  • In my opinion this is the cleanest solution, and in my code it does work perfectly: the only difference is that I placed the "responseWhitelist.push('body');" after app.use. app.use(expressWinston.logger({ winstonInstance: LogHelper })); expressWinston.requestWhitelist.push('body'); expressWinston.responseWhitelist.push('body'); Commented Jan 3, 2019 at 11:22
  • The whitelisting functions don't work for me for some reason.
    – robcsi
    Commented Apr 20, 2021 at 8:31
12

I found the simplest solution to this problem was to add a body property to the res object when sending the response, which can later be accessed by the logger. I add this to my own namespace that I maintain on the req and res objects to avoid naming collisions. e.g.

res[MY_NAMESPACE].body = ...

I have a utility method that formats all responses to my standardized API/JSON response, so adding this one liner there exposed the response body when the logging gets triggered by onFinished event of res.

2
  • 4
    I find this to be the most elegant solution. There is even a consideration for this in the response object: expressjs.com/en/api.html#res.locals
    – metaphist
    Commented Sep 30, 2019 at 18:13
  • but doesn't this mean you have to add it in every endpoint? or is there a middleware solution here?
    – Nben
    Commented Jul 31 at 6:10
12

Most of the suggestions seemed a little sledgehammer, Spent some time with this issue tonight and wrote up my findings after digging into a few libs to help make something bespoke.

//app.js
...
app.use(requestLoggerMiddleware({ logger: console.log }));

app.get(["/", "/api/health"], (req, res) => {
    res.send({ message: "OK", uptime: process.uptime() });
...
});
// middleware.js
/**
 * Interceptor function used to monkey patch the res.send until it is invoked
 * at which point it intercepts the invokation, executes is logic such as res.contentBody = content
 * then restores the original send function and invokes that to finalize the req/res chain.
 *
 * @param res Original Response Object
 * @param send Original UNMODIFIED res.send function
 * @return A patched res.send which takes the send content, binds it to contentBody on
 * the res and then calls the original res.send after restoring it
 */
const resDotSendInterceptor = (res, send) => (content) => {
    res.contentBody = content;
    res.send = send;
    res.send(content);
};

/**
 * Middleware which takes an initial configuration and returns a middleware which will call the
 * given logger with the request and response content.
 *
 * @param logger Logger function to pass the message to
 * @return Middleware to perform the logging
 */
const requestLoggerMiddleware = ({ logger }) => (req, res, next) => {
    logger("RECV <<<", req.method, req.url, req.hostname);
    res.send = resDotSendInterceptor(res, res.send);
    res.on("finish", () => {
        logger("SEND >>>", res.contentBody);
    });
    next();
};

module.exports = { requestLoggerMiddleware };

Full working example and article in the git repo https://github.com/JonathanTurnock/ReqResLoggingExample

3
9

I actually made this nifty little npm to solve this exact problem, hope you like it!

https://www.npmjs.com/package/morgan-body

morgan-body in action!

6

Typescript solution based on Laurent's answer:

import { NextFunction, Request, Response } from 'express-serve-static-core';
//...

app.use(logResponseBody);

function logResponseBody(req: Request, res: Response, next: NextFunction | undefined) {
    const [oldWrite, oldEnd] = [res.write, res.end];
    const chunks: Buffer[] = [];

    (res.write as unknown) = function(chunk) {
        chunks.push(Buffer.from(chunk));
        (oldWrite as Function).apply(res, arguments);
    };

    res.end = function(chunk) {
        if (chunk) {
            chunks.push(Buffer.from(chunk));
        }
        const body = Buffer.concat(chunks).toString('utf8');
        console.log(new Date(), `  ↪ [${res.statusCode}]: ${body}`);
        (oldEnd as Function).apply(res, arguments);
    };
    if (next) {
      next();
    }
}
5

May be this would help someone who is looking to get the response logged So, we use the middleware to intercept the request just before being served to the client. Then if we are using res.send method to send the data, override the method in the middleware and make sure to console log the body. If you are planning to use res.send alone then this should work fine, but incase if you use res.end or res.sendFile, then overwrite those methods and log only the required things (obviously logging the entire octet stream of file should never be logged for perfomance purposes.

Here I use pino as the logger. Created it as singleton service.

// LoggingResponseRouter.js

var loggingResponseRouter = require('express').Router();
var loggingService = require('./../service/loggingService');
var appMethodInstance = require('./../constants/appMethod');
var path = require('path');
var fs = require('fs');
var timeZone = require('moment-timezone');
var pino = require('pino')();


loggingResponseRouter.use((req, res, next) => {

    // set the fileName it needs to log
    appMethodInstance.setFileName(__filename.substring(__filename.lastIndexOf(path.sep) + 1, __filename.length - 3));
    //loggingService.debugAndInfolog().info('logging response body', appMethodInstance.getFileName()); 
    let send = res.send;
    res.send = function(body){
        loggingService.debugAndInfolog().info('Response body before sending: ', body);
        send.call(this, body);
    }
    next();
});
module.exports = loggingResponseRouter;

Main file - Main.js

const corsRouter = require('./app/modules/shared/router/corsRouter');
const logRequestRouter = require('./app/modules/shared/router/loggingRequestRouter');
const loggingResponseRouter = require('./app/modules/shared/router/loggingResponseRouter');
const express = require('express');
var path = require('path');
const app = express();


// define bodyparser middleware
const bodyParser = require('body-parser');

const port = process.env.PORT || 3000;

// Now use the middleware prior to any others
app.use(bodyParser.json());
// use this to read url form encoded values as wwell
app.use(bodyParser.urlencoded({extended:true}));
console.log('before calling cors router in main js');
app.use(corsRouter);
app.use(logRequestRouter);
app.use(loggingResponseRouter);


app.get('/api', (req, res) => {
    console.log('inside api call');
    res.send('aapi');
});


app.listen(port, () => {
    console.log('starting the server');
});

And this is the loggingService - loggingService.js

var pino = require('pino');
var os = require('os');
var appMethodInstance = require('./../constants/appMethod'); 
var pinoPretty = require('pino-pretty');
var moment = require('moment');
var timeZone = require('moment-timezone');


class Logger{
    constructor(){
        this.appName = 'Feedback-backend';
        this.filenameval = '';

    }

    getFileName(){
        console.log('inside get filename');
        console.log(appMethodInstance.getFileName());
        if(appMethodInstance.getFileName() === null || appMethodInstance.getFileName() === undefined){
            this.filenameval = 'bootstrapping...'
        }else {
            this.filenameval = appMethodInstance.getFileName();
        }
        console.log('end');
        return this.filenameval;
    }

    debugAndInfolog(){
        return pino({
                    name: 'feedback-backend',
                    base: {
                        pid: process.pid,
                        fileName: this.getFileName(),
                        moduleName: 'modulename',
                        timestamp: timeZone().tz('America/New_York').format('YYYY-MM-DD HH:mm:ss.ms'),

                        hostName: os.hostname()
                    },
                    level: 'info',
                    timestamp: timeZone().tz('America/New_York').format('YYYY-MM-DD HH:mm:ss.ms'),
                    messageKey: 'logMessage',
                    prettyPrint: {
                        messageKey: 'logMessage'
                    }
    });
}

errorAndFatalLog(){

    return pino({
        name: 'feedback-backend',
        base: {
            pid: process.pid,
            fileName: this.getFileName(),
            moduleName: 'modulename',
            timestamp: timeZone().tz('America/New_York').format('YYYY-MM-DD HH:mm:ss.ms'),
            hostName: os.hostname()
        },
        level: 'error',
        timestamp: timeZone().tz('America/New_York').format('YYYY-MM-DD HH:mm:ss.ms'),
        prettyPrint: {
            messageKey: 'FeedbackApp'
        }
    });
}
}




module.exports = new Logger(); 
4

I have similar need to this question.

Based on accepted answer, I modify it with proxy and trace response body only when it's json.

const traceMiddleware = (req, res, next) => {
  const buffers = []
  const proxyHandler = {
    apply(target, thisArg, argumentsList) {
      const contentType = res.getHeader('content-type')
      if (
        typeof contentType === 'string' && contentType.includes('json') && argumentsList[0]
      ) {
        buffers.push(argumentsList[0])
      }
      return target.call(thisArg, ...argumentsList)
    }
  }
  res.write = new Proxy(res.write, proxyHandler)
  res.end = new Proxy(res.end, proxyHandler)
  res.on('finish', () => {
    // tracing logic inside
    trace(req, res, Buffer.concat(buffers).toString('utf8'))
  })
  next()
}
1

I tried to create the simplest typescript solution for Request and Response JSON Body log and that works fine with tsoa framework.

Note: Its also works in no body request/response cases.

import express, { Request, Response, NextFunction, Application } from 'express';

function logRequestResponseMiddleware(req: Request, res: Response, next: NextFunction): void {
    settingLogRequest(req);
    settingLogResponse(req, res);
    next();
}

function settingLogRequest(req: Request): void {
    // use a proper logging library here
    console.debug({
        'url': req.url,
        'method': req.method,
        'bodyRequest': req.body,
        'headers': req.headers,
    });
}

function settingLogResponse(req: Request, res: Response): void {
    const copyJSON = res.json;
    let responseBody: any = undefined;
    res.json = (jsonBody: any) => {
        res.json = copyJSON;
        responseBody = jsonBody;
        return res.json(jsonBody);
    };
    const copyEnd = res.end;
    res.end = (args: any) => {
        res.end = copyEnd;
        // use a proper logging library here
        console.debug({
            'url': req.url,
            'method': req.method,
            'bodyRequest': req.body,
            'statusCode': res.statusCode,
            'bodyResponse': responseBody,
        });
        return res.end(args);
    };
}

const app: Application = express();
app.use(logRequestResponseMiddleware);

I use it with tsoa framework.

Bellow the tsoa response handler (routes.ts):

} else if (data !== null && data !== undefined) {
    response.status(statusCode || 200).json(data);
} else {
    response.status(statusCode || 204).end();
}
0

A little late to the party but here's my simple solution for intercepting any express functions you want:

function _interceptFuncAndStoreAttribute(res, originalFuncName, attributeName) {
  // move original function to a modified name
  const modifiedFuncName = originalFuncName + "_original"
  res[modifiedFuncName] = res[originalFuncName]
  // replace original function with new function that stores attribute and 
  // calls the original function
  res[originalFuncName] = (args) => {
    // set desired attribute
    res[attributeName] = args
    // call original function
    return res[modifiedFuncName](args)  
  };
}

function logRequests(req, res, next) {
  /** Function to log all incoming requests and the server's response */
  
  // Intercept res.send and store content in res.responseBody
  _interceptFuncAndStoreAttribute(res, "send", "responseBody")
  // Intercept res.status and res.sendStatus and store content in res.responseStatus
  _interceptFuncAndStoreAttribute(res, "status", "responseStatus")
  _interceptFuncAndStoreAttribute(res, "sendStatus", "responseStatus")

  // Make log with request and response on finish
  res.on('finish', () => {
    console.log('Req:', req.method, req.url, 'body:', req.body, 'Res:', res.responseStatus, res.responseBody)
  });

  next();
}

router.use(logRequests)

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.