expressWinston.logger({ requestFilter }) does not filter out request body

[awwong1]

I am having issues filtering out requests.

Dependencies

Verified this happening on Node v9.2.0 (stable) and Node v8.10.0 (lts).

// package.json dependencies
{
    "express": "^4.16.2",
    "express-winston": "^2.5.0",
    "winston": "^2.4.0"
}

Issue

Given the following configuration:

const winstonLoggerConfig = {
  transports: [
    new winston.transports.Console({
      json: true,
      colorize: false
    })
  ],
  meta: true,
  msg: "HTTP {{req.method}} {{req.url}}",
  requestWhitelist: [...expressWinston.requestWhitelist, "body"],

  // requestFilter also does not work?
  requestFilter: (req, propName) => {
    if (propName === "body") {
      return { operationName: "NO-OP", ...((req || {})[propName] || {}), variables: undefined };
    }
    return req[propName];
  },
  expressFormat: false,
  colorize: false
};

Expected Output

I expect my req.body to remove the variables property and have a default property set for operationName:

{
  "res": {
    "statusCode": 200
  },
  "req": {
    "url": "/graphql",
    "headers": {
      "host": "localhost:3000",
      "connection": "keep-alive",
      "content-length": "395",
      "accept": "*/*",
      "origin": "http://localhost:3001",
      "authorization": "null",
      "user-agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36",
      "content-type": "application/json",
      "dnt": "1",
      "referer": "http://localhost:3001/sign-in",
      "accept-encoding": "gzip, deflate, br",
      "accept-language": "en-CA,en-GB;q=0.9,en-US;q=0.8,en;q=0.7"
    },
    "method": "POST",
    "httpVersion": "1.1",
    "originalUrl": "/graphql",
    "query": {},
    "body": {
      "operationName": "SignInMutation",
      "query": "mutation SignInMutation($email: String!, $password: String!) {\n  signinUser(email: {email: $email, password: $password}) {\n    token\n    user {\n      _id\n      username\n      createdAt\n      updatedAt\n      email\n      emailVerified\n      __typename\n    }\n    __typename\n  }\n}\n"
    }
  },
  "responseTime": 337,
  "level": "info",
  "message": "HTTP POST /graphql"
}

Actual Output

Unforunately req.body keeps the variables property:

{
  "res": {
    "statusCode": 200
  },
  "req": {
    "url": "/graphql",
    "headers": {
      "host": "localhost:3000",
      "connection": "keep-alive",
      "content-length": "395",
      "accept": "*/*",
      "origin": "http://localhost:3001",
      "authorization": "null",
      "user-agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36",
      "content-type": "application/json",
      "dnt": "1",
      "referer": "http://localhost:3001/sign-in",
      "accept-encoding": "gzip, deflate, br",
      "accept-language": "en-CA,en-GB;q=0.9,en-US;q=0.8,en;q=0.7"
    },
    "method": "POST",
    "httpVersion": "1.1",
    "originalUrl": "/graphql",
    "query": {},
    "body": {
      "operationName": "SignInMutation",
      "variables": {
        "email": "test@test.tld",
        "password": "supersecret"
      },
      "query": "mutation SignInMutation($email: String!, $password: String!) {\n  signinUser(email: {email: $email, password: $password}) {\n    token\n    user {\n      _id\n      username\n      createdAt\n      updatedAt\n      email\n      emailVerified\n      __typename\n    }\n    __typename\n  }\n}\n"
    }
  },
  "responseTime": 337,
  "level": "info",
  "message": "HTTP POST /graphql"
}

Also req.body does not set a default value for operationName:

{
  "res": {
    "statusCode": 204
  },
  "req": {
    "url": "/graphql",
    "headers": {
      "host": "localhost:3000",
      "connection": "keep-alive",
      "access-control-request-method": "POST",
      "origin": "http://localhost:3001",
      "user-agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36",
      "access-control-request-headers": "authorization,content-type",
      "accept": "*/*",
      "dnt": "1",
      "referer": "http://localhost:3001/sign-in",
      "accept-encoding": "gzip, deflate, br",
      "accept-language": "en-CA,en-GB;q=0.9,en-US;q=0.8,en;q=0.7"
    },
    "method": "OPTIONS",
    "httpVersion": "1.1",
    "originalUrl": "/graphql",
    "query": {}
  },
  "responseTime": 1,
  "level": "info",
  "message": "HTTP OPTIONS /graphql"
}

Links

• Commit hash: udia-software/udia-server@d5dbcd5
• TravisCI build showing logging errors: https://travis-ci.org/udia-software/udia-server/jobs/350503545

[pocesar]

use bodyBlacklist / bodyWhitelist for that. make sure your logger is after body-parser

[crellison]

@awwong1 It looks like your requestFilter is returning an object instead of a value, as it is intended, which may be messing with your output. What if you tried the following:

const requestFilter = (req, propName) => {
  if (propName === "body") {
    const newBody = {
      operationName: "NO-OP",
      ...((req || {})[propName] || {}),
    };
    delete newBody.variables;
    return newBody[propName]
  }
  return req[propName];
};

[awwong1]

Thanks for the reply, I've moved away from using express-winston. I'll close this issue due to the two provided solutions (I haven't verified)