Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[question] How to "record" logs for testing purposes #1274

Closed
giltayar opened this issue Dec 20, 2021 · 8 comments
Closed

[question] How to "record" logs for testing purposes #1274

giltayar opened this issue Dec 20, 2021 · 8 comments

Comments

@giltayar
Copy link

We have tests in our app that verify that logs were created and have the correct information.

To do that, we need access to the final logs output by pino. The way we do it now is to use the prettyPrint option in pino to get at these final log JSONs and store them in an array that the test can access later.

Unfortunately, the prettyPrint option is being deprecated, so we need another solution. I looked at transports, and would love to write a transport to do this, but transports run in a worker thread, and there is no way for that worker thread to communicate with the main thread in order for it to pass the logs back to the main thread.

So...

  1. Is there a way for a transport to pass information back to the main thread?
  2. Am I missing something and there is a simpler way to do this?

(And thanks for a wonderful library!)

@giltayar giltayar changed the title How to "record" logs for testing purposes [question] [question] How to "record" logs for testing purposes Dec 20, 2021
@giltayar
Copy link
Author

I noticed that what is returned from .transport() is the ThreadStream, and that ThreadStream has a property called worker, so I can theoretically use that to listen to messages from the transport and receive the final JSON logs that way.

But I have no guarantees on this, and this could change from one version of pino to another.

@mcollina
Copy link
Member

You can keep using pino-pretty directly:

const pino = require('pino')
const pretty = require('pino-pretty')
const logger = pino(pretty())

logger.info('hi')

@giltayar
Copy link
Author

giltayar commented Dec 20, 2021

@mcollina I believe you misunderstood. I do not want to do pinopretty, but rather something else. In pino@6 (and 7), I could do this:

const logs = []

const logger = pino({
  prettyPrint: true,
  prettifier: log => logs.push(log)
})

foo(logger)

expect(logs).to.eql({event: 'dsfjshdf', level: 30, ...})

We used this for testing purposes to see that the function used the logger and output the correct logs (obviously the code below is a simplified version of what we use).

Unfortunately, the prettyPrint option is being deprecated, so we need another solution. I looked at transports, and would love to write a transport to do this, but transports run in a worker thread, and there is no way for that worker thread to communicate with the main thread in order for it to pass the logs back to the main thread.

So...

  1. Is there a way for a transport to pass information back to the main thread?
  2. Am I missing something and there is a simpler way to do this?

@jsumners
Copy link
Member

Pass a custom stream that writes lines to your array.

image

image

@giltayar
Copy link
Author

@jsumners perfect! Thank you!

@marcbachmann
Copy link
Member

marcbachmann commented Dec 21, 2021

Another quite raw snippet that always writes all logs to a capped memory buffer.
And errors are still output to the console.
Maybe it would be nice to put something like that into a module.

  let stream
  if (config.pretty || config.logToMemoryForTests) {
    const requestedLevel = pino.levels.values[config.level]
    pinoConfig.level = 'debug'

    stream = pino.destination()
    stream[pino.symbols.needsMetadataGsym] = true
    const prettifier = config.pretty && require('./dev_string_formatter')()
    const memoryDestination = config.logToMemoryForTests && require('./memory-destination')
    const origWrite = stream.write
    const parse = function (chunk) { try { return JSON.parse(chunk) } catch (err) { return } }
    stream.write = function (chunk) {
      if (memoryDestination) memoryDestination.write(parse(chunk))
      if (this.lastLevel < requestedLevel) return

      if (prettifier) {
        const obj = parse(chunk)
        return origWrite.call(this, obj ? prettifier(obj) : chunk)
      } else {
        return origWrite.call(this, chunk)
      }
    }
  }

memory-destination.js

'use strict'
// Singleton memory destination used for testing
module.exports = {

  // Array<Object>
  //  - each object is a parsed pino log entry
  logs: [],

  // called by pino
  write (chunk) {
    // crude safety that so no more than 100 logs are in memory
    if (this.logs.length >= 100) this.logs.splice(0, 50)
    this.logs.push(chunk)
  },

  reset () {
    const current = this.logs
    this.logs = []
    return current
  }
}

@AmitGazal
Copy link

@jsumners Thanks a lot, it works well!
A small comment: you should pass destination separately from the rest of parameters.
const log = loggerFactory({name: 'test1'}, t.context.dest)

@github-actions
Copy link

github-actions bot commented Feb 2, 2022

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Feb 2, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants