pinojs / pino-pretty

🌲Basic prettifier for Pino log lines
MIT License
1.25k stars 147 forks source link

need correct jmespath search filtering syntax #43

Open dkebler opened 5 years ago

dkebler commented 5 years ago

according to readme I am supposed to use http://jmespath.org/tutorial.html syntax for the search key

I just have a little test logger running with prettyPrint enabled. Runs fine except for search key syntax. All the jmespath examples assume not a single line of json but a key with array of json. In my(our) case there is none just a single line of JSON. like {"level":30,"time":1542136015941,"msg":"this is a logged message","pid":4382}

I followed the suggested syntax here http://getpino.io/#/docs/help?id=filter-logs which would be '.level == 60' where I guess . is supposedly taking the place of a proper parent key but I get this error which is not surprising cause at the jmespath site the . does nothing if I put in for example from above {"level":30,"time":1542136015941,"msg":"this is a logged message","pid":4382} (try it yourself)

So need help. Tried several options to no avail.

# this is log of my prettyPrint options in my `const logger = pino({`
pretty=> { translateTime: true,
  colorize: true,
  levelFirst: true,
  search: '.level == 60' }
# then here is error when it logs
file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/jmespath/jmespath.js:1
ParserError: Invalid token (Dot): "."
    at Parser._errorToken (file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/jmespath/jmespath.js:710:23)
mcollina commented 5 years ago

The suggested syntax in http://getpino.io/#/docs/help?id=filter-logs has nothing to do with jmespath. I think you should pass level == 60 in search.

Anyway, can you please upload a full repro with what you are trying to achieve?

dkebler commented 5 years ago

here is github repo with my logger module and example. Clone that to try or use code below see way below for failed runs https://github.com/uCOMmandIt/logger

Module

import pino from 'pino'

let pretty = false
if(process.env.UCI_DEV) {
  pretty = process.env.UCI_LOG_PRETTY || {translateTime:true, colorize:true, levelFirst:true }
  pretty.search = process.env.UCI_LOG_SEARCH
}

console.log('pretty=>',pretty)

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

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

function child (opts) {
  const LOG_OPTS = {
    repo: opts.repo || 'uci-'+ opts.name,
    package: opts.package || '@uci/'+ opts.name,
    file: opts.file || `src/${opts.name}.js`,
    class: opts.class || (opts.name.charAt(0).toUpperCase() + opts.name.slice(1)),
    id: opts.id || opts.name || 'none',
    instance_created:new Date().getTime()
  }
  return logger.child(LOG_OPTS)
}

export default child

Example use

import logger from '../src/logger'
let log = {}

class LOGTEST {
  constructor(opts) {
    log = logger({
      name: 'test',
      id: opts.id,
      file: 'example/example.js',
      class: 'LOGTEST'
    })
  }

}

let test = new LOGTEST({id:'process-test1'})

log.info('this is a logged message')
log.fatal('this is a fatal logged message')

package.json


  "name": "@uci/logger",
  "version": "0.0.6",
  "description": "Parent Logger for all UCI modules",
  "main": "src/logger",
  "scripts": {
    "testw": "mocha -r esmtest/*.test.mjs --watch --recurse --watch-extensions mjs",
    "test": "mocha -r esmtest/*.test.mjs",
    "testci": "istanbul cover ./node_modules/.bin/_mocha  --report lcovonly -- -R spec --recursive && codecov || true",
    "example": "node -r esm example/example",
    "dev": "UCI_DEV=true ./node_modules/.bin/nodemon -r esm example/example",
    "log": "UCI_LOG=true ./node_modules/.bin/nodemon -r esm example/example"
  },
  "author": "David Kebler",
  "license": "MIT",
  "repository": {
    "type": "git",
    "url": "git+https://github.com/uCOMmandIt/uci-changeme.git"
  },
  "keywords": [
    "node.js",
    "I2C",
    "raspberryPi"
  ],
  "bugs": {
    "url": "https://github.com/uCOMmandIt/uci-changeme/issues"
  },
  "homepage": "https://github.com/uCOMmandIt/uci-changeme#readme",
  "dependencies": {
    "pino": "^5.9.0",
    "pino-pretty": "^2.4.0"
  },
  "devDependencies": {
    "chai": "^4.2.0",
    "chai-as-promised": "^7.1.1",
    "codecov": "^3.1.0",
    "esm": "^3.0.84",
    "istanbul": "^0.4.5",
    "mocha": "^5.2.0",
    "nodemon": "^1.18.7"
  }
}

command run with no search (nr is alias for npm run) nr dev output

> @uci/logger@0.0.6 dev /home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger
> UCI_DEV=true ./node_modules/.bin/nodemon -r esm example/example

[nodemon] 1.18.7
[nodemon] to restart at any time, enter `rs`
[nodemon] watching: *.*
[nodemon] starting `node -r esm example/example src/logger.js`
pretty=> { translateTime: true,
  colorize: true,
  levelFirst: true,
  search: undefined }
INFO  [2018-12-04 17:44:18.587 +0000] (UCI/21116 on trantor): this is a logged message
    repo: "uci-test"
    package: "@uci/test"
    file: "example/example.js"
    class: "LOGTEST"
    id: "process-test1"
    instance_created: 1543945458586
FATAL [2018-12-04 17:44:18.589 +0000] (UCI/21116 on trantor): this is a fatal logged message
    repo: "uci-test"
    package: "@uci/test"
    file: "example/example.js"
    class: "LOGTEST"
    id: "process-test1"
    instance_created: 1543945458586
[nodemon] clean exit - waiting for changes before restart

command run witl level search/filter UCI_LOG_SEARCH='level == 60' nr dev console output

> @uci/logger@0.0.6 dev /home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger
> UCI_DEV=true ./node_modules/.bin/nodemon -r esm example/example

[nodemon] 1.18.7
[nodemon] to restart at any time, enter `rs`
[nodemon] watching: *.*
[nodemon] starting `node -r esm example/example src/logger.js`
pretty=> { translateTime: true,
  colorize: true,
  levelFirst: true,
  search: 'level == 60' }
file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/jmespath/jmespath.js:1
ParserError: Invalid token (Number): "60"
    at Parser._errorToken (file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/jmespath/jmespath.js:710:23)
    at Parser.nud (file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/jmespath/jmespath.js:614:18)
    at Parser.expression (file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/jmespath/jmespath.js:519:27)
    at Parser._parseComparator (file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/jmespath/jmespath.js:773:26)
    at Parser.led (file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/jmespath/jmespath.js:680:25)
    at Parser.expression (file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/jmespath/jmespath.js:523:27)
    at Parser.parse (file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/jmespath/jmespath.js:498:26)
    at Object.search (file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/jmespath/jmespath.js:1659:25)
    at pretty (file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/pino-pretty/index.js:106:29)
    at Object.write (file:///home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger/node_modules/pino/lib/tools.js:259:25)

doesn't like the 60.

Tried this alternative key search and it filters it all (should show both logs as they both have key:value class:LOGTEST) UCI_LOG_SEARCH='class == LOGTEST' nr dev

> @uci/logger@0.0.6 dev /home/david/AllData/hacking/active-dev-repos/uci/lib/uci-logger
> UCI_DEV=true ./node_modules/.bin/nodemon -r esm example/example

[nodemon] 1.18.7
[nodemon] to restart at any time, enter `rs`
[nodemon] watching: *.*
[nodemon] starting `node -r esm example/example src/logger.js`
pretty=> { translateTime: true,
  colorize: true,
  levelFirst: true,
  search: 'class == LOGTEST' }
[nodemon] clean exit - waiting for changes before restart

Conclusion: search does not work with numbers, search filters all records regardless of key:value ?? stuck here. Why is this not working as documented/expected?

mcollina commented 5 years ago

You should probably escape numbers, you might have to use ` to escape them (see http://jmespath.org/examples.html#filters-and-multiselect-hashes).

dkebler commented 5 years ago

see my other run not using a key:value that is a number. I'll try but It's more than just escaping a number. My other example doesn't work either. If you can find some time can you try my repo/example to see if you can get it to work.

dkebler commented 5 years ago

ok escaping number worked. what about my other example run? UCI_LOG_SEARCH='class == LOGTEST' nr dev which should show both logs as they both have the same key:value

dkebler commented 5 years ago

ok. it appears that ALL values must be escaped

UCI_LOG_SEARCH='class == `LOGTEST`' nr dev

works

the pino-pretty docs should be edited to indcate this.

mcollina commented 5 years ago

Would you mind in sending a PR?

dkebler commented 5 years ago

now that I look at the example in the pino-pretty readme I see the escaped characters. maybe one line warning below it saying that ALL values must be escaped with `\ `
and this issue would never have happened. thx

mcollina commented 5 years ago

I think it’s still worthwhile to update the README in that sense