{"action":"created","issue":{"url":"https://api.github.com/repos/TryGhost/Ghost/issues/7116","repository_url":"https://api.github.com/repos/TryGhost/Ghost","labels_url":"https://api.github.com/repos/TryGhost/Ghost/issues/7116/labels{/name}","comments_url":"https://api.github.com/repos/TryGhost/Ghost/issues/7116/comments","events_url":"https://api.github.com/repos/TryGhost/Ghost/issues/7116/events","html_url":"https://github.com/TryGhost/Ghost/issues/7116","id":166919831,"number":7116,"title":"Feature: Logging","user":{"login":"kirrg001","id":1160712,"avatar_url":"https://avatars.githubusercontent.com/u/1160712?v=3","gravatar_id":"","url":"https://api.github.com/users/kirrg001","html_url":"https://github.com/kirrg001","followers_url":"https://api.github.com/users/kirrg001/followers","following_url":"https://api.github.com/users/kirrg001/following{/other_user}","gists_url":"https://api.github.com/users/kirrg001/gists{/gist_id}","starred_url":"https://api.github.com/users/kirrg001/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/kirrg001/subscriptions","organizations_url":"https://api.github.com/users/kirrg001/orgs","repos_url":"https://api.github.com/users/kirrg001/repos","events_url":"https://api.github.com/users/kirrg001/events{/privacy}","received_events_url":"https://api.github.com/users/kirrg001/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/TryGhost/Ghost/labels/feature","name":"feature","color":"9FBB58"}],"state":"open","locked":false,"assignee":{"login":"kirrg001","id":1160712,"avatar_url":"https://avatars.githubusercontent.com/u/1160712?v=3","gravatar_id":"","url":"https://api.github.com/users/kirrg001","html_url":"https://github.com/kirrg001","followers_url":"https://api.github.com/users/kirrg001/followers","following_url":"https://api.github.com/users/kirrg001/following{/other_user}","gists_url":"https://api.github.com/users/kirrg001/gists{/gist_id}","starred_url":"https://api.github.com/users/kirrg001/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/kirrg001/subscriptions","organizations_url":"https://api.github.com/users/kirrg001/orgs","repos_url":"https://api.github.com/users/kirrg001/repos","events_url":"https://api.github.com/users/kirrg001/events{/privacy}","received_events_url":"https://api.github.com/users/kirrg001/received_events","type":"User","site_admin":false},"assignees":[{"login":"kirrg001","id":1160712,"avatar_url":"https://avatars.githubusercontent.com/u/1160712?v=3","gravatar_id":"","url":"https://api.github.com/users/kirrg001","html_url":"https://github.com/kirrg001","followers_url":"https://api.github.com/users/kirrg001/followers","following_url":"https://api.github.com/users/kirrg001/following{/other_user}","gists_url":"https://api.github.com/users/kirrg001/gists{/gist_id}","starred_url":"https://api.github.com/users/kirrg001/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/kirrg001/subscriptions","organizations_url":"https://api.github.com/users/kirrg001/orgs","repos_url":"https://api.github.com/users/kirrg001/repos","events_url":"https://api.github.com/users/kirrg001/events{/privacy}","received_events_url":"https://api.github.com/users/kirrg001/received_events","type":"User","site_admin":false}],"milestone":null,"comments":7,"created_at":"2016-07-21T21:16:34Z","updated_at":"2016-10-03T09:06:25Z","closed_at":null,"body":"# Logging\r\n\r\n### goals\r\n- full logging which outputs to stdout/stderr as we do now (and better!)\r\n- ability to provide an adapter in future, to customise the destination/output of the logging system\r\n- error levels\r\n- application levels\r\n- delete logic in `errors/index.js`\r\n\r\n### reasons why we have to change things\r\n- we need a consistent way to a log into a file/stdout --> right now we use `morgan` to log requests and a custom logging (chalk and console.log) for errors\r\n- we want to log more then just a single line `GET URL StatusCode` for requests (especially in development mode)\r\n- what we want to achieve is printing all logs (request/response/errors) in the same format (which i think can be `JSON`)\r\n- we need to tidy up (or remove) `/errors/index.js`, because it's doing more then it needs to do, is way to complicated in my opinion (we export ~15functions) and we want to differ the errors from a logging unit\r\n- we want to create a real logging adapter (which can be replaced)\r\n- this adapter can/should be used in each Ghost microservice\r\n- we want to handle and tidy up context/help for errors\r\n- we don't have proper levels (application levels, error levels, error codes)\r\n- log into file has the background: if we log stdout into the process, the process will grow over time. if we log into a file, we can rotate on that log file an delete after x days (this is helpful for each blog running in production)\r\n- remove the `logger` from migrations\r\n- more reasoning/descriptions can be found in #2001 and #6526 \r\n\r\n### bunyan vs. winston vs. debug\r\nAs already discussed, `debug` is a nice npm tool to get debug logs per file with auto-includes milliseconds between each debug log. \r\nBut our big goal is creating a logging unit, which can do more then just printing debug logs.\r\nI've used `winston` in the past and we've switched to `bunyan`, because the `bunyan` API is easier to use, easier to read and it has the advantage of nice JSON prints. That's why i would go with `bunyan`.\r\n\r\n\r\n## create a default logging adapter\r\n`server/logging/default.js`\r\n\r\nDevelopers should easily add custom loggers, if they prefer a different logger.\r\nIt should provide functions like `info`, `error`, `warn`, and `debug`.\r\n\r\n**info**\r\n- with info you can just log a single line like \"ghost server is starting\"\r\n- with info you can also log complex json objects like request/response\r\n\r\n**error**\r\n- accepts an error object and optional request/response object\r\n\r\n**warn**\r\n- accepts only a string\r\n\r\n**debug**\r\n- accepts a single JSON object\r\n- accepts a single string\r\n\r\n\r\n```\r\n  var logging = require('/logging'); \r\n  logging.error({ err: err, req: req, res: res });\r\n  logging.info('server starts now...'); \r\n  logging.info({ req: req, res: res }); \r\n```\r\n\r\n## output\r\n\r\nRight now our server print looks like (only stdout):\r\n\r\n```\r\nGET / 200 140.121 ms - -\r\nGET /assets/js/jquery.fitvids.js?v=4d853bd599 200 17.077 ms - -\r\nGET /assets/js/index.js?v=4d853bd599 200 16.385 ms - -\r\nGET /assets/css/screen.css?v=4d853bd599 200 19.621 ms - -\r\n```\r\n\r\nThis print is managed by `morgan`, which is configured in `middlewares/index.js`. We will delete this.\r\nInstead we will auto log requests/responses/errors.\r\n\r\n```\r\n  expressApp1.use(logging.utils.express);\r\n  expressApp2.use(logging.utils.express);\r\n```\r\n\r\n```\r\nfunction express\r\n  res.once('finish', function() {\r\n    if (req.err) {\r\n      logging.error({ req: req, res: res, err: req.err });\r\n    }\r\n    else {\r\n       logging.info({ req: req, res: res });\r\n     }     \r\n  });\r\n  \r\n   next();\r\n});\r\n```\r\n\r\nWhich can look like (transport: stdout)\r\n![Image1](https://docs.google.com/uc?id=0B1ieTi3APpJrel81ajJpdDdXbWs)\r\n![Image2](https://drive.google.com/uc?id=0B1ieTi3APpJrbnBTd0lGT1poSTQ)\r\n![Image3](https://drive.google.com/uc?id=0B1ieTi3APpJrYlhEVlpqcTZ1Y28)\r\n![Image4](https://drive.google.com/uc?id=0B1ieTi3APpJrdTVIQ2pLLTN6T28)\r\n\r\nWhich can look like (transport: file)\r\n![Image5](https://drive.google.com/uc?id=0B1ieTi3APpJrVGYwNjQwZDJiQ3M)\r\n\r\nWe could extend our upcoming Ghost CLI to offer: `ghost-cli log` (which will prettify the `.log` file)\r\n\r\n## log into file\r\nWe should be able to configure the transport (file, stdout)\r\nWe can start defining the transport per env.\r\n\r\n**production**\r\nfile only\r\n\r\n**staging** \r\nfile only\r\n\r\n**development**\r\nstdout only\r\n\r\n## application levels\r\nEvery env is by default in level info.\r\nYou can either force starting it different mode (debug) by changing the config or using `NODE_LEVEL`.\r\n\r\n## error levels\r\nEach error will be default in level \"normal\".\r\nWe can define an error as critical, which get's treated differently in Ghost(Pro).\r\n\r\n## time diffs\r\nWe can add time diffs between logs, like the npm module `debug` is offering. Not high prio.\r\n\r\n## ensure we don't log credentials\r\nFilter attributes.\r\n\r\n## bring help/context into errors\r\nRight now we pass context and help as different parameters.\r\nWe want to achieve having context and help as part of an error.\r\n\r\n## show debug logs in testing mode\r\n`NODE_LEVEL=debug grunt test` or `grunt test -d (--debug)`\r\nShould show print outs like errors."},"comment":{"url":"https://api.github.com/repos/TryGhost/Ghost/issues/comments/251059211","html_url":"https://github.com/TryGhost/Ghost/issues/7116#issuecomment-251059211","issue_url":"https://api.github.com/repos/TryGhost/Ghost/issues/7116","id":251059211,"user":{"login":"kirrg001","id":1160712,"avatar_url":"https://avatars.githubusercontent.com/u/1160712?v=3","gravatar_id":"","url":"https://api.github.com/users/kirrg001","html_url":"https://github.com/kirrg001","followers_url":"https://api.github.com/users/kirrg001/followers","following_url":"https://api.github.com/users/kirrg001/following{/other_user}","gists_url":"https://api.github.com/users/kirrg001/gists{/gist_id}","starred_url":"https://api.github.com/users/kirrg001/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/kirrg001/subscriptions","organizations_url":"https://api.github.com/users/kirrg001/orgs","repos_url":"https://api.github.com/users/kirrg001/repos","events_url":"https://api.github.com/users/kirrg001/events{/privacy}","received_events_url":"https://api.github.com/users/kirrg001/received_events","type":"User","site_admin":false},"created_at":"2016-10-03T09:06:25Z","updated_at":"2016-10-03T09:06:25Z","body":"@twgraham Hey thanks for suggestions.\r\n\r\n> For node applications, my team has used log4js-node (https://github.com/nomiddlename/log4js-node). It's been pretty good to us, and for those who are Java developers also, it will be familiar. It's ability to easily allow developers to configure logging and add 'appenders' makes it extremely convenient to log to any output you might think of (it comes with plenty OOB but you can also write your own).\r\n\r\nBunyan supports streams, which looks like the same then \"appenders\".\r\n\r\n\r\n> One other suggestion I would make here, and this is critical - try find/build into a logging framework a request context. That is, on each user request, create a guid which is passed through to each subsequent log call in the system. This is especially useful for developers when you have many concurrent requests, or your system is distributed. (btw, i don't want to open a can of worms, but someone said microservices? why does ghost need a microservice architecture? i know... probably a question for another thread)\r\n\r\nI assume you are talking about a `correlationId`?\r\n"}}
{"actor":{"display_login":"kirrg001"}}