chore: better logging #2221
chore: better logging #2221
Conversation
✅ Deploy Preview for netlify-plugin-nextjs-static-root-demo ready!
To edit notification comments on pull requests, go to your Netlify site configuration. |
✅ Deploy Preview for netlify-plugin-nextjs-nx-monorepo-demo ready!
To edit notification comments on pull requests, go to your Netlify site configuration. |
✅ Deploy Preview for next-plugin-edge-middleware ready!
To edit notification comments on pull requests, go to your Netlify site configuration. |
✅ Deploy Preview for netlify-plugin-nextjs-export-demo ready!
To edit notification comments on pull requests, go to your Netlify site configuration. |
✅ Deploy Preview for next-i18next-demo ready!
To edit notification comments on pull requests, go to your Netlify site configuration. |
github-actions
bot
added
the
type: chore
✅ Deploy Preview for next-plugin-canary ready!
To edit notification comments on pull requests, go to your Netlify site configuration. |
✅ Deploy Preview for netlify-plugin-nextjs-demo ready!
To edit notification comments on pull requests, go to your Netlify site configuration. |
✅ Deploy Preview for nextjs-plugin-custom-routes-demo ready!
To edit notification comments on pull requests, go to your Netlify site configuration. |
✅ Deploy Preview for netlify-plugin-nextjs-next-auth-demo ready!
To edit notification comments on pull requests, go to your Netlify site configuration. |
| @@ -0,0 +1,3 @@ | |||
| // Winston supports JSON by default but this is using a custom formatter | |||
| // It only gives the message and not the timestamp or log level | |||
| export { logger as default } from './winston' | |||
There was a problem hiding this comment.
I had this logger exposed via an index file as I was trying both winston and pino. Pino is meant to be faster but by default supports JSON logging. Even with their pretty formatter, it would make our logs a little strange with multiple timestamps.
We can move this to a single logger module that only includes winston if needed.
| import winston from 'winston' | ||
|
|
||
| // Define log level from environment variable so we can change it if needed | ||
| const logLevel = process.env.LOG_LEVEL ?? 'info' |
There was a problem hiding this comment.
This will allow us to only display logger.info and higher levels (.warn, .error) into the user-facing logs.
We can use the environment variable with customers or support so we can use logger.debug or similar in the code.
There was a problem hiding this comment.
Thanks Marc! Seems like a no-brainer as it gives us extra flexibility and observability, plus we can avoid leaving accidental console.log in the code. Unless the performance difference is huge, I'd advocate for using Winston instead of developing a custom transport for Pino.
| @@ -30,6 +30,7 @@ module.exports = { | |||
| 'unicorn/no-array-push-push': 0, | |||
| 'unicorn/numeric-separators-style': 0, | |||
| 'max-lines': 0, | |||
| 'no-console': 2, | |||
There was a problem hiding this comment.
ESLint now errors for all console.* statements.
| The following routes use "revalidate" values of under ${MINIMUM_REVALIDATE_SECONDS} seconds, which is not supported. | ||
| They will use a revalidate time of ${MINIMUM_REVALIDATE_SECONDS} seconds instead. | ||
| `) | ||
|
|
||
| // Disabling lint rule as the logger doesn't have a table formatter | ||
| // eslint-disable-next-line no-console | ||
| console.table(shortRevalidateRoutes) |
There was a problem hiding this comment.
I wasn't sure what we wanted to do here. We'd have to write some code to format as a table so I've left console.table as it was.
There was a problem hiding this comment.
This could always be a logger.info(JSON.stringify(shortRevalidateRoutes, null, 2)). Or we could create a logger.table that wraps my suggestion.
There was a problem hiding this comment.
Actuallym, nvm. That would behave more like console.dir, not console.table.
| @@ -1,3 +1,6 @@ | |||
| // This is a runtime function so assuming we don't want to add | |||
| // an additional dependency on a logger (Winston) for runtime code | |||
| /* eslint-disable no-console */ | |||
There was a problem hiding this comment.
My assumption for all of our runtime code is that we don't want to add the extra dependency of winston to avoid bundle bloat.
There was a problem hiding this comment.
Yeah, the new logger should be just for build time, no runtime code for the reason you mention. I do wonder if we can use the system log in handlers we generate?
There was a problem hiding this comment.
Let's look at that for the next PR. Sounds like a good idea.
test/index.spec.ts
Outdated
| @@ -1,3 +1,5 @@ | |||
| // Do we want logging in the tests? | |||
| /* eslint-disable no-console */ | |||
There was a problem hiding this comment.
Not sure if we care about console.* statements in the tests.
Personally, I'm not sure we should be including additional logging in the tests as the tests should provide the information we need.
Thoughts?
There was a problem hiding this comment.
I don't think they're necessary in the tests either. Maybe do that cleanup in another PR?
| @@ -810,9 +813,9 @@ describe('onPostBuild', () => { | |||
| }, | |||
| ]) | |||
|
|
|||
| const oldLog = console.log | |||
| const oldLoggerInfo = logger.info | |||
There was a problem hiding this comment.
I left this as was but we could probably just spy on the logger.info here to confirm it gave the message we expect.
|
I've updated the PR and added logging to all of the code. |
MarcL
force-pushed
the
marcl/better-logging
branch
from
158a3d1 to
a223e71
Compare
|
Some test snapshots fail so I'll need to work with @nickytonline or @orinokai to understand why. They don't look like they're related to any of the changes in this PR. 🤔
Adding a fix for the failing tests here: #2224 |
There was a problem hiding this comment.
This is looking great @MarcL! Left some questions/comments.
| @@ -210,7 +213,7 @@ export const warnForProblematicUserRewrites = ({ | |||
|
|
|||
| export const warnForRootRedirects = ({ appDir }: { appDir: string }) => { | |||
| if (existsSync(join(appDir, '_redirects'))) { | |||
| console.log( | |||
| logger.info( | |||
| yellowBright( | |||
There was a problem hiding this comment.
do we need the colours still, or does winston provide different colours for different log levels?
There was a problem hiding this comment.
Good idea. It does allow you to colour them but we'd have to add an additional config.
https://github.com/winstonjs/winston#colorizing-standard-logging-levels
Should we do this and remove our use of chalk or do we want to leave it as is so it matches the current behaviour?
There was a problem hiding this comment.
Maybe in a small follow up PR once the new logger is up and running. If it's not a big lift, go for it now.
There was a problem hiding this comment.
I took a look and we'd have to ensure we used the correct log levels. In some cases, we're changing colours but still using logger.info. Might be worth shipping this and then updating the log levels if we're considering some of them as different messages.
| @@ -1,3 +1,6 @@ | |||
| // This is a runtime function so assuming we don't want to add | |||
There was a problem hiding this comment.
double check, but I think you might be able to exclude the whole packages/runtime/src/templates/ folder from this eslint rule.
There was a problem hiding this comment.
Great. I'll check this.
There was a problem hiding this comment.
Can you do this for a single rule @nickytonline?
I can see how you exclude linting a set of files but not for a single rule.
There was a problem hiding this comment.
You can do it for a single rule. See https://eslint.org/docs/latest/use/configure/rules#using-configuration-files-1
MarcL
force-pushed
the
marcl/better-logging
branch
from
5c22126 to
6a68d3e
Compare
|
Going to close this as we're moving forward with other work. |
Description
This PR adds the winston logger to enable us to have clearer logging in the runtime. It will help us to add additional logging to help with debugging but avoid additional clutter in the logs. This is due to the default log level of
infobeing set.This is a suggestion to see if the team think it'll be useful. It will allow us to set a
LOG_LEVELenvironment variable to enable logging levels below the current default. With this, we can instrument the code and allow customers to enable a lower log level if we're struggling to debug issues.I've added the
no-consoleeslint rule to avoid accidentalconsole.*statements but have not enabled it for tests. See the inline comments for more details.I considered using pino too as it's faster. However, by default, it generates structured JSON logs which can't currently be ingested by Netlify's build process. You can use the pino-pretty package to display them nicely but it adds an additional timestamp.
winstongave a simpler 1-line transport which has parity with our console logging so in the short term we can keep this.Documentation
N/A
Tests
I've updated tests which spy or mock
console.*to use thelogger.*instead.There is 1 failing snapshot test that we need to look at before merging.
Relevant links (GitHub issues, etc.) or a picture of cute animal
#2220