lrlna/pino-colada

cute ndjson formatter for pino 🌲🍹

pino-colada 🍹

A cute ndjson formatter for pino.

Usage

Pipe a server that uses pino into pino-colada for logging.

node server.js | pino-colada

pino-colada

After parsing input from server.js, pino-colada returns a stream and pipes it over to process.stdout. It will output a timestamp, a log level in a form of an emoji, and a message.

Usage as pino prettifier

const pino = require('pino')
const logger = pino({
  prettyPrint: {},
  prettifier: require('pino-colada')
})

logger.info('hi')

Log Output Format

pino-colada has a few special-case formatting modes that are enabled by passing certain keys into pino when the data is logged. Errors, for instance, should print out the error message and the stack trace. But not all errors will contain the appropriate keys (such as an error return from a promise).

Below is an example log message to demonstrate how pino-colada processes the data:

10:01:31 🚨 MyNamespace MyFunction Encountered an internal server error GET 500 /test 230B 45ms
Error: Mock Error message triggered.
    at testHandler (/home/user/index.js:175:20)
    at /home/user/index.js:398:11
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
{
  "err": {
    "msg": "Mock Error message triggered."
  }
}

Given the following pino log,

{"level":30,"time":1639403408545,"pid":37661,"hostname":"Irinas-MacBook-Pro.local","name":"http","message":"response","method":"GET","url":"/error","statusCode":500,"elapsed":3,"contentLength":0,"v":1}

pino-colada produces the following output:

14:46:04 ✨ http --> GET 500 /error 0B 3ms

The output corresponds to pino's ndjson. Here are is an annotated explanation of how pino-colada formats the logs:

14:46:04 ✨ http --> GET 500 /error 0B 3ms
         ┬  ─┬─  ─┬─ ─┬─ ─┬─ ───┬── ┬  ─┬─
         |   |    |   |   |     |   |   |
────┬─── |   |    |   |   |     |   |   |
    ╰── "time"    |   |   |     |   |   |
         |   |    |   |   |     |   |   |
         ╰── "level"  |   |     |   |   | 
             |    |   |   |     |   |   |
             ╰── "name"   |     |   |   |
                  |   |   |     |   |   |
                  ╰── "message" |   |   |
                      |   |     |   |   |
                      ╰── "method"  |   |
                          |     |   |   |
                          ╰── "statusCode"
                                |   |   |
                                ╰── "url"
                                    |   |
                                    ╰── "contentLength"
                                        ╰── "elapsed"/"responseTime"

A few notes on the formatting:

• We use these emojis to represent the "level":
  • level 10, trace: '🔍'
  • level 20, debug: '🐛',
  • level 30, info: '✨',
  • level 40, warn: '⚠️',
  • level 50, error: '🚨',
  • level 60, fatal: '💀'.
• If the "message" value is request or response, we convert it to <-- and --> respectively.
• If "stack" property is present, pino-colada will print the stack trace following the formatted error log.

Install

npm install pino-colada

Related content

• pino
• merry
• garnish
• @studio/log
• pino-http
• hapi-pino

License

MIT

pino-colada's Issues

pino-colada swallows errors

If you log with log.fatal(err, 'something went wrong') you only see `something went wrong' in your log. It would be better if you got your stacktrace so you can see where the error occurred. (It does seem to log objects given post the error message, just not pre)

consider more accessible colors?

Heya, first off thank you for this awesome tool and contribution to the pino ecosystem!

This formatter made it easy and fun to remove the conditional pretty-printing logic from our app in favor of pure, pluggable, ndjson output. Excellent idea and much appreciated contribution.

To the crux of this issue: I'd like to propose dropping dim modifiers from log statements to make the output more accessible. Dim red for error statements is particularly troubling and is the main change I'll champion here.

Totally understand that there are a lot of host environment settings that play into the rendering of these things. The demo screenshot in the README is beautiful and, while I couldn't figure out what terminal theme was used when capturing it, I took the following screenshots to highlight renderings in iTerm2 w/ default dark theme and Hyperterm with the top 2-most downloaded themes (pokemon and solarized-dark)

Using this script to generate the output: https://gist.github.com/knksmith57/7b673fe77429534a93f2c7ea5ff61c20

1. iTerm2 default dark theme:

2. Hyperterm default theme:

3. Hyperterm solarized-dark theme:

4. Hyperterm pokemon theme w/ pikachu:

5. Hyperterm pokemon theme w/ gengar:

What do you think?

Thanks again!

check for 0 time elapsed on bundle size

using pino-colada at "pretty" in pino instance

What would it take to use the 'main' source file (exported function) as the pretty printer when creating a pino instance. I'm avoiding command-line pipes and using environment variables to control pretty printing.

So something like this....which doesn't work.

import pino from 'pino'
import colada from 'pino-colada'
// import serializeError from 'serialize-error'

let pretty = {}
if(process.env.UCI_DEV || process.env.DEBUG) {
  pretty = colada
  // pretty = pino.pretty()
  // pretty.pipe(process.stdout)
}

let LOG = process.env.UCI_LOG || process.env.UCI_DEV || process.env.DEBUG

const logger = pino({
  name: 'UCI',
  enabled: !!LOG,
  safe: true,
  serializers: {
    req: pino.stdSerializers.req,
    res: pino.stdSerializers.res
  }
},pretty)

export default logger

Programmatic use doesn't work properly

When using pino-colada programmatically as per the docs:

const pino = require('pino')
const logger = pino({
  prettifier: require('pino-colada')
})

logger.info('hi')

Nothing happens. When I add prettyPrint to the options it starts working:

const pino = require('pino')
const logger = pino({
  prettyPrint: {},
  prettifier: require('pino-colada')
})

logger.info('hi')

... but only for the first log line. All others after that are the default "raw" JSON

log bundle size performance dot zip

neat idea to check whether bundle size is within tcp constraints --https://twitter.com/davidmarkclem/status/843777314496430080

2.2.0 doesn't work

Hello,
I tried to update from 2.1.0 to 2.2.0 and pino-colada fails with the error env: node\r: No such file or directory.

Small googling revealed it's connected with line endings: https://stackoverflow.com/questions/30344858/node-script-executable-not-working-on-mac-env-node-r-no-such-file-or-directo

Thank you

OS: macOs Big Sur 11.2.3
node: 14.17.6

How to use in fastify

Hi,

I got so confused when reading through pino, pino-pretty, pino-colada docs...

I tried this:

const app = fastify({
  logger: {
    level: 'info',
    prettifier: require('pino-colada')
  }
})

with no luck.. And I really don't want to do the | thing.. I just want the app to print the pretty logs. Is that possible?

Add types for TypeScript usage

Just as it says in the title. They can be distributed as part of the package or contributed to DefinitelyTyped.

stream.on is not a function

Hi,
in fastify-cli we have a report of this error with the v1.6.0 release:

To reproduce:

npx fastify-cli generate pretty
cd pretty/
npm i
// edit the package.json adding "-P" flag in the start script
npm start 
// now we have the error

// to solve:
npm ls pino-colada
// you should see 1.6.0

// installing previous version works:
npm i [email protected]
npm start
// all works fine

There are some fixes we should apply to our code base?
We use pino-colada here:
https://github.com/fastify/fastify-cli/blob/b6e7caba7e8f2644f5243f9d94902faacfbda886/start.js#L98-L102

Thanks

The stack trace:

  stream.on('close', function () {
         ^
TypeError: stream.on is not a function
    at destroyer (C:\Users\behem\workspaceFastify\asd\boooom\node_modules\pump\index.js:26:10)
    at C:\Users\behem\workspaceFastify\asd\boooom\node_modules\pump\index.js:70:12
    at Array.map (<anonymous>)
    at pump (C:\Users\behem\workspaceFastify\asd\boooom\node_modules\pump\index.js:67:26)
    at runFastify (C:\Users\behem\workspaceFastify\asd\boooom\node_modules\fastify-cli\start.js:101:5)
    at start (C:\Users\behem\workspaceFastify\asd\boooom\node_modules\fastify-cli\start.js:50:10)

Original issue ref: fastify/fastify-cli#235

prettyPrint is deprecated

Change prettifier to customPrettifiers in the readme

output more info

server-sink produces a whole bunch of info besides message. I think it'd be good to output more data, akin to how garnish operates

{ name: 'http',
  message: 'request',
  method: 'GET',
  remoteAddress: '::1',
  url: '/' }
{ name: 'http',
  message: 'response',
  method: 'GET',
  url: '/',
  statusCode: 200,
  elapsed: 55,
  contentLength: 242 }

Support use as a Pino transport

pretty-print & prettifier the new recommended way of integrating a prettifier via API is using a pino.transport. pino-pretty supports this so can probably checked to see an example of how.

Allow for something a bit more verbose

Hey !

First thanks for pino-colada, it's really great !

However, I have a small usage issue with it, because while pino-colada removing most of the verbose stuff especially regarding requests is awesome, it would be great to have at least small objects with few properties outputed, at least in a verbose like mode (maybe with a threshold on the number of non object subprops )

@lrlna Are you open to such a feature ? Would you want to implement it, or would you prefer a PR ?

Deprecated dependencies

Maybe it's a good idea to remove pad-left and pad-right and replace it with build in String.prototype.padStart and String.prototype.padEnd.
https://www.npmjs.com/package/left-pad