Rollbar hangs and swallows errors in async functions

[tdeck]

When encountering an error in an async function, rollbar seems to hang indefinitely and suppress all logging.

Here is a small proof of concept app:

const express = require('express');
const Rollbar = require('rollbar');

const app = express();

/* Uncomment this to make debugging much harder!
 
const rollbar = new Rollbar({
  accessToken: process.env.ROLLBAR_TOKEN,
  enabled: false, // NB
  captureUncaught: true,
  captureUnhandledRejections: true,
  varbose: true
});

// Note the issue happens even without this line:
// app.use(rollbar.errorHandler());
*/


app.get('/', function(req, res) {
  let x = y; // ERROR: y is undefined
  res.send('All good');
});

app.get('/async', async function(req, res) {
  let x = y; // ERROR: y is undefined
  res.send('All good');
});

app.listen(5678, function () {
  console.log('POC app listening on port 5678');
});

This simulates a scenario where I've made a typo or something like that: Rollbar swallows these errors even when verbose is true (aside: the need for this argument itself is very unintuitive) and when enabled is false. I am using rollbar 2.19.2

What I should get: ReferenceError: y is not defined in the logs, followed by a stack trace at both / and /async routes

What I get Correct behavior at / route, response hangs indefinitely at /async route with no logs.

[waltjones]

@tdeck When an async function throws (as in the let x = y example), the error is converted to a promise rejection. If the rejection is unhandled, Node's behavior at that point depends on whether a listener is registered for 'unhandledRejection'.

The default for most versions of Node ( I have confirmed here on Node 8 and Node 12), is to not log when any listener is added for the 'unhandledRejection' event. You can verify this by removing Rollbar completely and adding process.on('unhandledRejection', function(){}); to your app.js.

Starting in Node 10.17, a flag is provided to control the intended behavior for unhandled rejections. The setting node --unhandled-rejections=warn will cause Node to log the error to the console whether or not a listener is present. https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode

Alternately, if you want to use Rollbar without handling unhandled rejections, this can be disabled in Rollbar's config with captureUnhandledRejections: false and the listener won't be set.

About the "hanging" behavior, I'm not seeing this. When the function is async and the error then is converted to a rejection, the only difference I see in behavior is the presence of the logging. Again, you can use process.on('unhandledRejection', function(){}); without Rollbar to confirm.

What I see is the process does not exit, and if I then load a different endpoint, that endpoint responds fine. So the process isn't hung, but it also does not generate an HTTP response. In my testing, this is equally true without Rollbar and without any other 'unhandledRejection' listeners present.

I hope this helps, and do let me know if you're seeing something different.

[tdeck]

Sorry for my slow reply here - it's been a busy week. I realize my usage of the term "hang" here was ambigiuous - in both cases the promise never resolves and so there is no completed HTTP response, which is as expected. However the lack of an error about why there was no response caused me to perceive it differently.

I will experiment with --unhandled-rejections=warn, but might I suggest the Rollbar library also log these unhandled rejections, at least in the case that the developer has set verbose=true? The problem with the status quo is that it's not very intuitive, and a problem experienced in development or production will leave absolutely nothing in the logs. Obviously the developer can look at the rollbar dashboard if they've got collection enabled, but that often fails to put the issue in context like the actual server logs do.

I'm happy to make a PR for this if it's acceptable.

[waltjones]

My only concern about this suggestion is that it overrides a non-Rollbar Node.js behavior for which Node has its own setting.

I'll keep the issue open and consider enabling when verbose=true as you suggest.