{"action":"created","issue":{"url":"https://api.github.com/repos/pinojs/pino/issues/420","repository_url":"https://api.github.com/repos/pinojs/pino","labels_url":"https://api.github.com/repos/pinojs/pino/issues/420/labels{/name}","comments_url":"https://api.github.com/repos/pinojs/pino/issues/420/comments","events_url":"https://api.github.com/repos/pinojs/pino/issues/420/events","html_url":"https://github.com/pinojs/pino/pull/420","id":327060409,"number":420,"title":"Add redact API as first class citizen + faster redaction than pino-noir","user":{"login":"davidmarkclements","id":1190716,"avatar_url":"https://avatars1.githubusercontent.com/u/1190716?v=4","gravatar_id":"","url":"https://api.github.com/users/davidmarkclements","html_url":"https://github.com/davidmarkclements","followers_url":"https://api.github.com/users/davidmarkclements/followers","following_url":"https://api.github.com/users/davidmarkclements/following{/other_user}","gists_url":"https://api.github.com/users/davidmarkclements/gists{/gist_id}","starred_url":"https://api.github.com/users/davidmarkclements/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/davidmarkclements/subscriptions","organizations_url":"https://api.github.com/users/davidmarkclements/orgs","repos_url":"https://api.github.com/users/davidmarkclements/repos","events_url":"https://api.github.com/users/davidmarkclements/events{/privacy}","received_events_url":"https://api.github.com/users/davidmarkclements/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":4,"created_at":"2018-05-28T15:24:22Z","updated_at":"2018-05-28T19:12:13Z","closed_at":null,"author_association":"MEMBER","pull_request":{"url":"https://api.github.com/repos/pinojs/pino/pulls/420","html_url":"https://github.com/pinojs/pino/pull/420","diff_url":"https://github.com/pinojs/pino/pull/420.diff","patch_url":"https://github.com/pinojs/pino/pull/420.patch"},"body":"This integrates pino with [fast-redact](http://github.com/davidmarkclements/fast-redact) which is a generic version of `pino-noir` but adds 16x less over head to serialization (28% overhead with `pino-noir` vs 2% overhead with `fast-redact`)\r\n\r\n`fast-redact`  will only work with Node 6+ because of its use of `Proxy` to validate paths, this is why it's appropriate for pino v5.\r\n\r\nThe proposal is:\r\n\r\n* Redaction is a first class citizen in Pino v5\r\n* In Pino v4, `pino-noir` remains as the method of redaction\r\n* This also enables (fast) intermediate wildcards (e.g. a.*.c) which `pino-noir` doesn't have\r\n\r\nThese factors together with the speed improvements should further incentivize upgrading to v5.\r\n\r\nThe PR adds `redact` and `censor` options (`censor` defaults to `[Redacted]`)\r\n\r\n```js\r\nrequire('pino')({\r\n  redact: ['req.headers.cookie'],\r\n  censor: 'hidden :D'\r\n})\r\n```\r\n\r\nThis API solves leaky abstraction in pino-noir (having to pass in the standard serializers), \r\nand side steps the issue of needing to tag a serializer that.. well.. actually serializes. After spending some time thinking about it, imnho it's the cleanest and fastest way to integrate (we don't have to worry about whether `safe` is false etc etc)\r\n\r\n## Redact benchmarks\r\n\r\nOverhead of redaction is very low, sometimes redaction is faster – I chose a run where it's not faster. At any rate, redaction is within noise.\r\n\r\n```sh\r\nnode benchmarks/redact.bench\r\n```\r\n\r\n```\r\nbenchPinoNoRedact*10000: 349.224ms\r\nbenchPinoRedact*10000: 350.569ms\r\nbenchPinoUnsafeNoRedact*10000: 327.524ms\r\nbenchPinoUnsafeRedact*10000: 330.655ms\r\nbenchPinoExtremeNoRedact*10000: 205.040ms\r\nbenchPinoExtremeRedact*10000: 215.273ms\r\nbenchPinoUnsafeExtremeNoRedact*10000: 193.195ms\r\nbenchPinoUnsafeExtremeRedact*10000: 193.174ms\r\n```\r\n\r\n## Server overhead\r\n\r\nWhen linking this branch into `pino-http` and then redacting a Cookie header the overhead is within noise, it's hard to verify exactly without using an isolated machine - but  the redacting server is frequently faster by a few %. This is probably because the non-redacting server because it's serializing and writing fewer bytes but also, this redaction may be triggering further V8 optimizations (see benchmarks). Even setting the `censor` to the same content as the Cookie header yields either more or similar req/s as having no redaction.\r\n\r\nThis is the redacting server:\r\n```js\r\nvar http = require('http')\r\nvar server = http.createServer(handle)\r\n\r\nvar logger = require('../')({\r\n  redact: ['req.headers.cookie']\r\n})\r\n\r\nfunction handle (req, res) {\r\n  logger(req, res)\r\n  res.end('hello world')\r\n}\r\n\r\nserver.listen(3000)\r\n```\r\n\r\nThis is the `autocannon` command (using higher duration and connections to try to reduce the noise to signal ratio):\r\n\r\n```sh\r\nautocannon -d60 -c50 -H Cookie=\"SESSID=298zf09hf012fh2; csrftoken=u32t4o3tb3gg43; _gat=1;\" localhost:3000\r\n```\r\n\r\nResults for the redacting server are:\r\n```\r\nStat         Avg     Stdev  Max\r\nLatency (ms) 2.63    0.77   39.75\r\nReq/Sec      15985.8 987.5  18209\r\nBytes/Sec    1.77 MB 111 kB 2.02 MB\r\n```\r\n\r\nIf we take redaction out, results are:\r\n\r\n```\r\nLatency (ms) 2.75     0.73    28.55\r\nReq/Sec      15728.87 744.53  18668\r\nBytes/Sec    1.75 MB  86.1 kB 2.07 MB\r\n```\r\n\r\nOver several runs results fluctuate, essentially adding redaction to a server is within noise.\r\n\r\n## Comparison Benchmarks\r\n\r\nThe global cost of adding redaction is adding a `stringifiers` object and checking if `stringifiers[key]` exists before using `this.stringify`. \r\n\r\n`benchmarks/object.bench.js` for just the pino benchmarks\r\n\r\n### This branch:\r\n\r\n```\r\nbenchPinoObj*10000: 299.598ms\r\nbenchPinoUnsafeObj*10000: 265.580ms\r\nbenchPinoExtremeObj*10000: 143.180ms\r\nbenchPinoUnsafeExtremeObj*10000: 140.752ms\r\n```\r\n\r\n### next-major\r\n\r\n```\r\nbenchPinoObj*10000: 301.574ms\r\nbenchPinoUnsafeObj*10000: 275.551ms\r\nbenchPinoExtremeObj*10000: 158.657ms\r\nbenchPinoUnsafeExtremeObj*10000: 145.294ms\r\n```\r\n\r\nThe cost of this change is approximately zero.\r\n\r\n\r\n## Tests and Docs\r\n\r\nI'll add tests and docs once we're in agreement on API\r\n\r\n\r\n\r\n\r\n\r\n\r\n"},"comment":{"url":"https://api.github.com/repos/pinojs/pino/issues/comments/392588959","html_url":"https://github.com/pinojs/pino/pull/420#issuecomment-392588959","issue_url":"https://api.github.com/repos/pinojs/pino/issues/420","id":392588959,"user":{"login":"mcollina","id":52195,"avatar_url":"https://avatars0.githubusercontent.com/u/52195?v=4","gravatar_id":"","url":"https://api.github.com/users/mcollina","html_url":"https://github.com/mcollina","followers_url":"https://api.github.com/users/mcollina/followers","following_url":"https://api.github.com/users/mcollina/following{/other_user}","gists_url":"https://api.github.com/users/mcollina/gists{/gist_id}","starred_url":"https://api.github.com/users/mcollina/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/mcollina/subscriptions","organizations_url":"https://api.github.com/users/mcollina/orgs","repos_url":"https://api.github.com/users/mcollina/repos","events_url":"https://api.github.com/users/mcollina/events{/privacy}","received_events_url":"https://api.github.com/users/mcollina/received_events","type":"User","site_admin":false},"created_at":"2018-05-28T19:12:13Z","updated_at":"2018-05-28T19:12:13Z","author_association":"MEMBER","body":"I'm +1 with the current approach. the other one is too confusing."}}
{"actor":{"display_login":"mcollina"}}