feat(logging): persist and export application logs #814
Conversation
nsakaimbo
changed the title
desktop/env.js
Outdated
| throw err; | ||
| } | ||
| } ); | ||
| } |
There was a problem hiding this comment.
there shouldn't be a need for existsSync() right? We always want to make sure the directory is there and so adding the existsSync() only creates a race-condition where the directory could be there when it's called and gone by the time it's done, leaving us in the same state as if we just assumed it was there.
mkdirSync() shouldn't fail if the directory already exists.
const logPath = process.env.WP_DEBUG_LOG || path.join( appData, 'logs', 'wp-desktop.log' );
mkdirSync( path.dirname( logPath ), { recursive: true }, error => { … } );There was a problem hiding this comment.
Thanks - good catch. Addressed in d7d3aea.
There was a problem hiding this comment.
Interestingly enough, a plainmkdirSync( ... { recursive: true} ) will throw an error (code EEXIST) if the directory already exists (at least, it does in CI). Updated with try/catch in 029cb26 and it's working again as expected.
|
|
||
| State.prototype.getLogPath = function( ) { | ||
| return this.logPath; | ||
| }; |
There was a problem hiding this comment.
Would these be necessary if we moved the logging directory logic into the logging module? It doesn't look obvious that it needs to occur in desktop/env.js especially since this logic is specific to the logger and there's a logger module. Anything that relies on the logger module will pull it in and that module-init code that we write will run before anything can call it, so we still have the ability to initialize things before any logging call could be made.
There was a problem hiding this comment.
Yeah I'm not thrilled about this either, but this seemed like a reasonable choice given the alternatives. The logs path needs to be set relative to the user's userData directory, but the userData directory itself is overriden early in the application's lifecyle in env.js.
/**
* Initialize core components
*/
const state = require( './lib/state' );
const config = require( './lib/config' );
const appData = path.join( app.getPath( 'appData' ), config.appPathName );
// Initialize log directory prior to requiring any modules that log
const logPath = process.env.WP_DEBUG_LOG ? process.env.WP_DEBUG_LOG : path.join( appData, 'logs', 'wp-desktop.log' );
mkdirSync( path.dirname( logPath ), { recursive: true }, ( err ) => {
if ( err ) {
err.message = 'Failed to initialize log directory: ' + err.message;
throw err;
}
} );
state.setLogPath( logPath );
// Initialize settings
const Settings = require( './lib/settings' );
// Catch-all error handler
// We hook in very early to catch issues during the startup process
require( './app-handlers/exceptions' )();
// if app path set to asar, switch to the dir, not file
var apppath = app.getAppPath();
if ( path.extname( apppath ) === '.asar' ) {
apppath = path.dirname( apppath );
}
process.chdir( apppath );
process.env.CALYPSO_ENV = config.calypso_config;
// Set app config path
app.setPath( 'userData', appData );
if ( Settings.isDebug() ) {
process.env.DEBUG = config.debug.namespace;
}
It's definitely awkward having lib/logger know in advance about "where the overidden userData directory is", and it would be an easy footgun if the path to userData ever changes and we forget to change the path buried in lib/logger as well. Having this path set in env.js, next to the userData override, is far from perfect but makes it a little more obvious what's going on.
The prior implementation (that wasn't really implemented) seemed to have the log path set in the application's config (ref). This seems like a reasonable choice as well, save for the fact that the config values are set at buildtime, not runtime, so a path relative to userData in the config object would also smell a little funny.
There was a problem hiding this comment.
Did we consider replacing debug's logging mechanism? Do we need the additional functionality that Winston brings? If we're mostly trying to expose the logs then we could probably shrink the scope of this work by augmenting debug instead, plus I think that would allow us to grab logs for any subsystem in Calypso, not just the ones we specifically convert.
My guess is that getting the logs as they are is probably 1000x better than not getting any and getting additional structures is about 1200x better. Obviously there's no evidence yet but in terms of adding a new dependency without a clear need I'd rather question if it's needed before adding it.
If you have seen it already and know it's super helpful then please go ahead and introduce it. That being said, please make sure that there's good integration with our existing debug calls as well.
It doesn't look like this PR actually does any logging. While this may help separate the concerns on the PR it'd be nice to more clearly see what it's supposed to be doing. Can we compare this to the existing logging that it looks like is supposed to be happening as evidenced in the deleted code from desktop/env.js?
What were the tradeoffs in this work vs. adding a menu option to download the existing log data?
This feature replaces
Yep. One of the goals of the implementation is to maintain parity with the behavior of
We preserve the functionality of
To reduce noise and make these changes easier to review, this PR is solely focused on the logger implementation. The actual replacement of For context, here is the diff in its entirety, which you're more than welcome to inspect. IMO conceptualizing and discussing changes is a little easier when changes can be broken up this way.
The key limitation of the
The availability and formatting of debug logs in this manner is fairly standard and provides significant value when debugging. Anything that reduces the feedback cycle between our users' reporting an issue and our ability to identify/reproduce a problem is a step in the right direction. Log formatting with Log format looks like so: Nothing new here and this is a fairly common format (see VSCode, for example). Side note: I don't think the millisecond difference item is particularly useful, but this is also trivial to add with To inspect log output for yourself, you can download an artifact from #815 (or build that branch locally) (instructions).
A couple of points worth noting:
|
I may not have communicated what I wanted. I understand that you're replacing
For example,
Not something I'm worried about until we actually have a need for it. You can probably persuade me that Put another way, what about Also on local time I consider that more of a liability than a help due to the way that local clocks can change so dramatically. As I write this comment I've opened the console and run
Can you elaborate here? Based on the deleted code it looks like
In this case for me, at least since this involves changes whose implications lie beyond this PR I'm not finding it easier to understand. It's fine to leave them separate, but maybe at the same time the work itself is bigger in scope than it needs to be if it's hard to contain in a single PR. I know logging extends throughout the whole app so maybe this isn't proper to consider it the case here. Just responding to the comment from a personal take (the PRs are now separate but I have to open three tabs to review any one of them 😉) |
Sure, down the road we may decide to use another logging solution. In the case of
YMMV, but I strongly disagree with this point, based on my own experience 🤷♂. A log level may incorporate some human judgement, but at the end of the day it's one more data point that, in addition to others, can make inspecting and filtering logs a lot less tedious and provide some hint to context/intent. If an error is thrown (or is uncaught), that's a fairly obvious categorization. Also, there is a strong case to be made for warnings w.r.t unexpected conditions. There's some judgement involved to categorization, sure, but those judgements can and should be made collectively as part of PR review w.r.t the developer's/team's priorities.
In summary, I don't expect any element to be perfect on its own, but the more information/context I have to debug a problem, the better. From my own experience, it would be more tedious not to have any additional context such as severity or timestamps(!). (Also, emphasis on user logs, as this is different from viewing streaming output in your console for development purposes, in which case you may/may not care as much about a timestamp). I'm also going to emphasize that we're not re-inventing the wheel here. Logs for various applications we use every day (include other Automattic applications) incorporate exactly these items, and for good reason.
I'm fine with making this one giant PR. However I often find that large features/diffs tend to result in less thorough reviews, as the sheer volume of the changes can be overwhelming (which is understandable). Either approach has its limitations, and chances are I would be prompted to break things up if I went with One Giant PR™. That being said, let me know and it would be no problem to close these initial PRs and simply point the final one at
Yep, it seems that was the intent at some point earlier in the application's history, but that idea wasn't fleshed out and no file was being written to whatsoever. It looks like part of the goal was to upload logs with crash reports, however crash reporting wasn't fully implemented. If and when we do get around to it, we now have logs we can upload with our crash reports (if we so choose). |
😅
Perfectly clear. In fact, this is the primary reason I'm hesitant about these changes. In this I believe that the the size of this PR is probably a result of rebuilding the existing system
Sounds like that was a bug and probably part of why this has been more work than it should have been. Would have been nice if we could have done this all in one small PR adding a menu option to download that file. Based on your responses I don't think any of your original points were unclear or miscommunicated. In short, my feedback is that it seems like this work could be accomplished with much less by relying on If you didn't explore using |
|
I briefly explored using My assessment of There's probably clever hacks to all of the above issues. However there are clear benefits to a solution that addresses most (if not all) all of these items out-of the-box, while preserving behaviors we've been using to-date. Regardless of underlying library ( |
nsakaimbo
changed the title
Description
This series of PRs adds activity logs to the Desktop application, exportable via the
FileHelpmenu. User logs are archived and exported to the user's desktop, at which point they can be shared for troubleshooting/debugging purposes.The log format follows industry-standard best practices of categorization by functional area and priority (
info,debug,errorandwarn), and includes details of both key events and uncaught exceptions (with associated stack traces 🎉).To-date, logging in the application has been limited solely to the developer environment via the npm
debugmodule. The goals of realizing this feature are to (1) minimize disruption of the developer environment by maintaining behavior of the existingdebugmodule, (2) extend logging to incorporate more useful format, and (3) make persisted user logs available for troubleshooting purposes.Motivation and Context
Troubleshooting issues reported by users has primarily been driven by educated (as much as possible) guesswork and back-and-forth to probe for more details about any given problem. In an effort to minimize this feedback loop and make debugging more efficient, users now have the option of exporting an archive of their logs to their desktop which they can attach to support requests.
Organization
This feature is staggered into three PRs to make code review more manageable.
PR 1. Add custom logging module (
lib/logger)PR 2. Replace usage of prior
debugmodule with the custom loggerPR 3. Add log archival and export functionality via the application's "Help" menu
[1] WP-Desktop Custom Logger Implementation
This PR adds a custom logging solution to wp-desktop. The
lib/loggerimplementation is a wrapper for the popularwinstonlogging library, which provides a lot of great functionality and flexibility out-of-the-box. Key benefits of utilizingwinstonare (1) the ability to customize log formatting, (2) the ability to log to multiple transports and (3) capturing uncaught exceptions.Key Features
DEBUGenvironment variable to filter logs by functional area (e.g.DEBUG=desktop:*)debugmodule, i.e.log = require( 'lib/logger')( 'desktop:<function>')The location of the application's log file during end-to-end testing is redirected to the
test/logsfolder.