✨ Even better logging #140
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
wwilsman
force-pushed
the
ww/better-logging
branch
9 times, most recently
from
a3d88c6
to
7a01de5
Compare
wwilsman
force-pushed
the
ww/no-puppeteer
branch
from
802d23b
to
c91588a
Compare
wwilsman
force-pushed
the
ww/better-logging
branch
4 times, most recently
from
86ecae4
to
9bfb11a
Compare
wwilsman
force-pushed
the
ww/better-logging
branch
from
9bfb11a
to
b1392ef
Compare
For logging purposes, these functions are better off not as helpers due to how specific they are to a page and its assocated capture or snapshot information
With additional logging, it became evident that the page was being closed during navigation. This is handled by a navigation timeout, however that timeout is too long to account for in this test. The test has been adjusted to help ensure navigation is finished when closing.
wwilsman
force-pushed
the
ww/better-logging
branch
from
b1392ef
to
2ddd967
Compare
🔥 This is exactly what we've been chasing for ages. Can't wait |
Robdel12
reviewed
Jan 22, 2021
Robdel12
suggested changes
Jan 22, 2021
| log.warn('Warning: `percy-agent.js` is deprecated, please update to the latest SDK version'); | ||
|
|
||
| let wrapper = '(window.PercyAgent = class PercyAgent { snapshot(n, o) { return PercyDOM.serialize(o); } });'; | ||
| log.deprecated('`percy-agent.js` is deprecated, please update to the latest SDK version'); |
| } | ||
|
|
||
| // Ensures that deprecation messages are not logged more than once | ||
| deprecated(debug, message, meta) { |
| } | ||
|
|
||
| // timestamp each log | ||
| let timestamp = Date.now(); |
There was a problem hiding this comment.
It's nice to see my cruft go away 😂
This was referenced Jan 23, 2021
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Purpose
With #128, we have much deeper control and insight into the asset discovery process. While the current logs are pretty good, this PR revamps the internal logger to make them even better so we can utilize them going forward in debugging customer issues.
While Winston is a great logger with many features, we only use a few; and with those few, not to their full potential. For example, formatters and transports – we use a custom formatter to add a percy label and color log levels, and we two transports for console logging and file logging. However, we still patch a few methods to better fit our use cases.
Approach
Replace Winston entirely with a custom logger. This custom logger follows a familiar loglevel style with
info,warn,error, anddebuglog levels, but additionally follows a traditional Node debug style format that allows precise control of which debug logs to show. This enables us to sprinkle more and more logs throughout the codebase while maintaining and easily digestible, granular, format.The new logger also drops the file logger completely and instead opts to retain in-memory logs so that they may be queried and uploaded later. If necessary, we can still save these full logs to a file using pipes which could then be inspected post-mortem.
The previous logger test helper captured all process IO writes which could cause the runner output itself to be swallowed if something went wrong during capture. The new logger test helper is linked directly to the logger's in-memory store which allows other processes to continue writing to stdio without interruption. This additionally required a slight modification of existing stdio writes to utilize the logger's stdio which is mocked under testing.
The
@percy/sdk-utilspackage had it's own logger and log test helper to avoid including Winston's entire ecosystem in individual SDKs. Now that Winston and its dependencies are removed, we can include our own logger and its helper within that package. This does mean that consuming SDKs will need to be updated to the new logging style as well to be compatible with this beta.As an experiment to test the value of these new logs, I tracked down and fixed a flakey test that consistently failed more often than not on my machine. It required a slight refactor of the capture method, but once additional logs were added, it became clear what the issue was and was substantially easier to fix.