Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log Uncaught Errors & Unhandled Promise Rejections In Main Process #2110

Merged
merged 21 commits into from Mar 8, 2018

Conversation

gasi
Copy link
Contributor

@gasi gasi commented Mar 5, 2018

  • Add electron-unhandled dependency:
    • Ensures errors are normalized (disabled to prevent serializing non-errors that are thrown and leaking information)
    • Distinguishes between main and renderer processes
    • Allows suppression of error dialog
  • Log uncaught errors and unhandled promise rejections in main process
  • Tested using unguarded throw new TyperError(…) and Promise.reject(…) in setTimeout after app ready event.
  • Extract Privacy module that centralizes how we redact sensitive information such as phone numbers, group IDs, and user file paths.
  • Add eslint-plugin-mocha to disallow exclusive tests using *.only.

Fixes #2019.

Copy link
Contributor

@scottnonnenberg scottnonnenberg left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Short and sweet. Think we could do just a little bit better, though. :0)

main.js Outdated
@@ -1,3 +1,4 @@
const addUnhandledErrorHandler = require('electron-unhandled');
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would like us to separate built-ins (fs, path) from third-party node modules, from our own stuff. Can we move this to the node modules location?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sure, no problem.

main.js Outdated
logger: (error) => {
console.log(
'main.js: Uncaught error or unhandled promise rejection:',
error && error.stack ? error.stack : error
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This might be a good opportunity to spend the time to remove the current directory from any paths on the call stack, so sensitive information doesn't get into the logs.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good idea. Let me look into that.

@@ -415,6 +426,7 @@ app.on('ready', () => {
logging.initialize().catch((error) => {
loggingSetupError = error;
}).then(() => {
/* eslint-enable more/no-then */
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What's happening here? Despite the title of the commit ('reducing the scope'), it seems like we're increasing its scope since we're enabling it higher in the file.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, we reduce the places where we can use then, encouraging new code to use async / await.

@gasi
Copy link
Contributor Author

gasi commented Mar 6, 2018

@scottnonnenberg @scottnonnenberg-signal: Thanks for the code review. Addressed your feedback, incl. redacting sensitive file paths. Didn’t rebase but here’s a link to latest changes just in case: https://github.com/signalapp/Signal-Desktop/pull/2110/files/e3c9a81ba006f7fbebe9fe2e14299423effac665..75208f89d075de69dbfa3f08cf2ccd81e33b926d

Copy link
Contributor

@scottnonnenberg scottnonnenberg left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So great to get centralized Error handling and callstack redaction in place! A few things to consider:

@@ -416,7 +416,7 @@
});
var error = c.validateNumber();
if (error) {
console.log('Invalid contact received', error && error.stack ? error.stack : error);
console.log('Invalid contact received:', Errors.toLogFormat(error));
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I just had a look at the ensure-error code, and it doesn't have the same behavior as our previous approach. Before, we looked for .stack and if we didn't find it, we would rely on the toString() of whatever we got. ensure-error does a util.inspect() on the incoming thing and creates a new callstack.

Seems like in most situations we'd be alright, perhaps even better than we were before. At least in terms of debuggability. But in some cases we'd show a whole lot more data than we did before since util.inspect() will enumerate keys while toString() didn't. That might have privacy implications.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for digging in. I saw the behavior slightly changed but didn’t notice any exposure so far. Let’s keep an eye on it during the beta.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let me know what specific examples are that we have to be aware of. I am also happy to revert to error && error.stack ? error.stack : error.

// toLogFormat :: Error -> String
exports.toLogFormat = (error) => {
const normalizedError = ensureError(error);
return Privacy.redactAll(normalizedError.stack);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do we need to redact here, if we're already redacting in logging.js?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sure; I must have added this before the general redaction in the logging module.

const GROUP_ID_PATTERN = /(group\()([^)]+)(\))/g;

const APP_ROOT_PATH = Path.join(__dirname, '..', '..', '..');
const APP_ROOT_PATH_PATTERN = new RegExp(APP_ROOT_PATH, 'g');
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We're creating a regular expression from an arbitrary incoming path. Seems like we may want to put some protections in here to prevent crashes. Or perhaps rely on a recursive string replace instead of using regular expressions.

Also, doesn't the path.join() code above create a path ending with ../../..? path.resolve() should help with that.

Copy link
Contributor Author

@gasi gasi Mar 7, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Re: RegExp. Good call on being more defensive around creating the RegExp from a user supplied file path. Followed JDD’s advice and added _.escapeRegExp: lodash/lodash#1084 (comment). Wish there was simply a String::replaceAll function.

Re: path.join. Confirmed it does the right thing and normalizes the path to not have ../../... Otherwise, the tests wouldn’t have passed anyways. I prefer path.join to path.resolve if it meets our needs as it is a pure function. path.resolve falls back to process.cwd().

Copy link
Contributor Author

@gasi gasi Mar 7, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

FWIW, PureScript offers a straightforward String::replaceAll function (which even minimizes chances of accidentally flipping arguments using Pattern and Replacement types): https://pursuit.purescript.org/packages/purescript-strings/3.5.0/docs/Data.String#v:replaceAll

The implementation shows that it’s non-trivial: https://github.com/purescript/purescript-strings/blob/06e048c1a6026e3fd6dd9aff0a2d26da23cec783/src/Data/String.js#L114-L120

😜

@gasi
Copy link
Contributor Author

gasi commented Mar 7, 2018

Thanks for pointing some edge cases I didn’t handle. Submitted changes to address these. I’d appreciate another look — thanks! https://github.com/signalapp/Signal-Desktop/pull/2110/files/75208f89d075de69dbfa3f08cf2ccd81e33b926d..2d02d620f0b086fce99d117e1eab24516b1a407a

@gasi
Copy link
Contributor Author

gasi commented Mar 8, 2018

@gasi gasi force-pushed the log-uncaught-errors-promise-rejections branch from 6b138fc to 81b927c Compare March 8, 2018 20:59
@gasi
Copy link
Contributor Author

gasi commented Mar 8, 2018

Rebased and pushed. Changes: Rebasing to fix .only leftover (thanks!) and adding mocha ESLint plugin 😄

gasi added 19 commits March 8, 2018 16:22
Allows errors to be formatted and sanitized for logging. Removes sensitive paths
such as the app root directory.

Ideally, this module would be called singular `Error` but that is already a
global name. Using `Errors` plural is  similar to Java convention for utilities
such as `Arrays`, `Collections`, `Files`, etc. See:
https://stackoverflow.com/a/11673838
Centralizes how we redact sensitive information.
Example:

```
> node
> const nonError = {foo: 'i-am-private'};
undefined

// before
> util.inspect(nonError);
'{ foo: \'i-am-private\' }'

// after
> nonError.toString()
'[object Object]'
>
```
Omits use of `ensure-error` for privacy.

Before:
`Uncaught error or unhandled promise rejection: NonError: { private: true }`

After:
`Uncaught error or unhandled promise rejection: [object Object]`

Tested using:

```
setTimeout(() => {
  throw new Error('sync: booooom!');
}, 5000);

setTimeout(() => {
  Promise.reject(new Error('async: promise'))
}, 10000);

setTimeout(() => {
  Promise.reject({private: true});
}, 15000);
```
Allows us to set various lint rules for our tests.
@gasi gasi force-pushed the log-uncaught-errors-promise-rejections branch from 81b927c to c7305db Compare March 8, 2018 22:33
@gasi
Copy link
Contributor Author

gasi commented Mar 8, 2018

Rebased against after merging #2111 and #2112: no changes.

It potentially could leak information from serialized non-errors that are thrown
due to `util.inspect`.
@gasi
Copy link
Contributor Author

gasi commented Mar 8, 2018

Added one more commit to update our electron-unhandled fork and not even use ensure-error and clean-error. Will merge now.

@gasi gasi merged commit 8a1bff0 into development Mar 8, 2018
gasi added a commit that referenced this pull request Mar 8, 2018
…ions In Main Process

- [x] Add `electron-unhandled` dependency:
  - ~~Ensures errors are normalized~~ (disabled to prevent serializing non-errors that are thrown and leaking information)
  - Distinguishes between main and renderer processes
  - Allows suppression of error dialog
- [x] Log uncaught errors and unhandled promise rejections in main process
- [x] Tested using unguarded `throw new TyperError(…)` and `Promise.reject(…)` in `setTimeout` after `app` `ready` event.
- [x] Extract `Privacy` module that centralizes how we redact sensitive information such as phone numbers, group IDs, and user file paths.
- [x] Add `eslint-plugin-mocha` to disallow exclusive tests using `*.only`.

Fixes #2019.
@gasi gasi deleted the log-uncaught-errors-promise-rejections branch March 8, 2018 23:05
scottnonnenberg-signal added a commit that referenced this pull request Mar 16, 2018
New option in settings: delete all application data
(383e02e)

Remove all configuration in database when we discover we are unlinked
(9acb189)

Delete everything in database when we link with a different phone number
from previous link (9acb189)

Windows: Delete all data on uninstall
(c855597)

Dev:
  - Switch to a new service for debug logs, since GitHub is retiring
    anonymous gists (#2111)
  - Redact file paths in anything that goes to the log on disk (#2110)
  - When top-level process errors happen, don't show dialog with stack
    trace (#2110)
  - Add `nsp` to CI runs
    (fd056e1)
  - Add eslint-plugin-mocha to disallow exclusive tests using *.only
    (#2110)
gasi pushed a commit to gasi/Signal-Desktop that referenced this pull request Mar 22, 2018
New option in settings: delete all application data
(signalapp@383e02e)

Remove all configuration in database when we discover we are unlinked
(signalapp@9acb189)

Delete everything in database when we link with a different phone number
from previous link (signalapp@9acb189)

Windows: Delete all data on uninstall
(signalapp@c855597)

Dev:
  - Switch to a new service for debug logs, since GitHub is retiring
    anonymous gists (signalapp#2111)
  - Redact file paths in anything that goes to the log on disk (signalapp#2110)
  - When top-level process errors happen, don't show dialog with stack
    trace (signalapp#2110)
  - Add `nsp` to CI runs
    (signalapp@fd056e1)
  - Add eslint-plugin-mocha to disallow exclusive tests using *.only
    (signalapp#2110)
Vinnl pushed a commit to Vinnl/Signal-Desktop that referenced this pull request Mar 23, 2018
New option in settings: delete all application data
(signalapp@383e02e)

Remove all configuration in database when we discover we are unlinked
(signalapp@9acb189)

Delete everything in database when we link with a different phone number
from previous link (signalapp@9acb189)

Windows: Delete all data on uninstall
(signalapp@c855597)

Dev:
  - Switch to a new service for debug logs, since GitHub is retiring
    anonymous gists (signalapp#2111)
  - Redact file paths in anything that goes to the log on disk (signalapp#2110)
  - When top-level process errors happen, don't show dialog with stack
    trace (signalapp#2110)
  - Add `nsp` to CI runs
    (signalapp@fd056e1)
  - Add eslint-plugin-mocha to disallow exclusive tests using *.only
    (signalapp#2110)
scottnonnenberg-signal added a commit that referenced this pull request Apr 11, 2018
Note: this release is equivalent to v1.7.0-beta.3. The changes listed below are compared to the previous production release, v1.6.1.

Update to electron 1.8.4 (#2186)

Migrate all attachments from IndexedDB to file system in the background (#2208, #2193, #2165, #2162, #2129)
Save attachments to disk when importing Chrome app export (#2212)

New option in settings: delete all application data (383e02e, #2144 and #2153)

Remove all configuration in database when we discover we are unlinked (9acb189 and 1c6d91b)

Delete everything in database when we link with a different phone number from previous link (9acb189)

Windows: Delete all data on uninstall (c855597)

Fixed: Read receipts setting would not be synchronized along with re-link (#2218)

Fixed: Clicking conversation in left pane when already selected would remove focus on message composition field - thanks @colefranz! (#2032)

Fixed: Searching for the phone number of an existing contact, then selecting 'start conversation' would erase contact details (#2191)

Fixed: Selecting Settings menu option multiple times would open multiple instances of settings view - thanks @navdeepsinghkhalsa (#2167)

Dev:
  - Redact file paths in anything that goes to the log on disk (#2110)
  - When top-level process errors happen, don't show dialog with stack trace (#2110)
  - Add `nsp` to CI runs (fd056e1)
  - Add eslint-plugin-mocha to disallow exclusive tests using *.only (#2110)
  - Preparation for encrypted backups (cea42bd)
  - Updates to structure of exported data - messages.zip, flat list of attachments (6d8f4b7)
  - Relax Node.js version requirements (#2203)
  - Fix a few typos in documentation - thanks @Vinnl (#2171)
  - Update issue template to mention that translation should be via Transifex (#2157)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants