no notifications with sailsJs + docker #825

subzero10 · 2022-07-05T18:33:31Z

Discussed in #824

^{Originally posted by atex21 July 5, 2022}
Hey!
I'm trying to test honeybadger but it's being impossible.. I'm with sailsJS and docker, configurations as described in documentation:

const honeybadgerConfig = {
  apiKey: process.env.HONEYBADGER_API_KEY,
  environment: environment
}

variables arrive well to the container in docker.

In a first hand I realized that that configuration about middleware doesn't work.. If I just throw an exception there is no try to send honeybadger notification, the errorHandler is not called =/

In the other hand, if I forgot the last point and use an explicit HoneyBadger.notify, then there is a try to send notification, however I'm stuck with errors coming for no reason =/, namely

Conditions of running	honeybadger-io/js version	Result of a Honeybadger.notify
Throw in class + notify in servererror	v3.2.9	(1)TypeError [ERR_INVALID_ARG_TYPE]: The "listener" argument must be of type function. Received an instance of Object
Throw in class	v3.2.9	Don’t notify / don’t arrive to errorHandler
Throw in class + notify in servererror	V4.0.3	(2)TypeError: Cannot read property 'breadcrumbs' of undefined
Throw in class	V4.0.3	Don’t notify / don’t arrive to errorHandler

a bit more detail:

(1)
[API] TypeError [ERR_INVALID_ARG_TYPE]: The "listener" argument must be of type function. Received an instance of Object
[API]     at checkListener (events.js:135:11)
[API]     at ClientRequest.once (events.js:539:3)
[API]     at new ClientRequest (_http_client.js:215:10)
[API]     at Object.request (https.js:374:10)
[API]     at Object.wrappedRequest (/usr/src/app/node_modules/newrelic/lib/instrumentation/core/http.js:412:22)
[API]     at Object.<anonymous> (/usr/src/app/node_modules/agent-base/patch-core.js:25:22)
[API]     at Object.<anonymous> (/usr/src/app/node_modules/socks-proxy-agent/node_modules/agent-base/patch-core.js:23:20)
[API]     at Object.<anonymous> (/usr/src/app/node_modules/agent-base/patch-core.js:25:22)
[API]     at Object.<anonymous> (/usr/src/app/node_modules/socks-proxy-agent/node_modules/agent-base/patch-core.js:23:20)
[API]     at Object.<anonymous> (/usr/src/app/node_modules/agent-base/patch-core.js:25:22)
[API]     at Object.request (/usr/src/app/node_modules/socks-proxy-agent/node_modules/agent-base/patch-core.js:23:20)
[API]     at /usr/src/app/node_modules/@honeybadger-io/js/dist/server/honeybadger.js:932:33
[API]     at parseStats (/usr/src/app/node_modules/@honeybadger-io/js/dist/server/honeybadger.js:757:16)
[API]     at FSReqCallback.readFileAfterClose [as oncomplete] (internal/fs/read_file_context.js:73:3)
[API]     at FSReqCallback.callbackTrampoline (internal/async_hooks.js:131:17)

(2)
[API] /usr/src/app/node_modules/@honeybadger-io/js/dist/server/honeybadger.js:871
[API]         var breadcrumbs = store.breadcrumbs;
[API]                                 ^
[API] 
[API] TypeError: Cannot read property 'breadcrumbs' of undefined
[API]     at Honeybadger.Client.addBreadcrumb (/usr/src/app/node_modules/@honeybadger-io/js/dist/server/honeybadger.js:871:33)
[API]     at Honeybadger.Client.notify (/usr/src/app/node_modules/@honeybadger-io/js/dist/server/honeybadger.js:727:14)
[API]     at process.honeybadgerUncaughtExceptionListener (/usr/src/app/node_modules/@honeybadger-io/js/dist/server/honeybadger.js:1151:28)
[API]     at process.emit (events.js:412:35)
[API]     at process.wrappedEmit (/usr/src/app/node_modules/newrelic/lib/instrumentation/core/globals.js:52:23)
[API]     at process.emit (/usr/src/app/node_modules/ts-node/node_modules/source-map-support/source-map-support.js:516:21)
[API]     at process.<anonymous> (internal/process/execution.js:167:25)
[API]     at process.wrappedFatalException [as _fatalException] (/usr/src/app/node_modules/newrelic/lib/instrumentation/core/globals.js:32:23)
[API] [nodemon] app crashed - waiting for file changes before starting...

Can you help please?

Thank you in advance.

The text was updated successfully, but these errors were encountered:

shalvah · 2022-07-05T21:10:21Z

Will take a look.

@atex21 what version of Sails and Node.js are you using?

shalvah · 2022-07-05T22:40:30Z

(Also, is this exclusively within Docker? Were you able to test with Docker?) @subzero10 you said you were able to reproduce this; was it in Docker or outside? I don't really think this is a Docker thing, but I guess we should be sure.

My initial exploration:

Yes, the middleware approach doesn't seem to work. The middleware stack is terminated after the error is thrown (later middleware aren't called). Makes me wonder if Sails changed something in their error handling
Manual notifyAsync in the controller action works for me.

Not yet verified, but I suspect this has something to do with async. I'll do further investigations later.

atex21 · 2022-07-06T07:39:29Z

Hi @shalvah!
The versions used are v14.17.6 for nodeJS and 1.5.2 for sailsJS.
I also tried notifyAsync as you mentioned but the error is the same about store & breadcrumbs..

shalvah · 2022-07-06T18:28:57Z

@atex21 what does your controller where the error is thrown look like?

atex21 · 2022-07-06T18:39:51Z

@atex21 what does your controller where the error is thrown look like?

hey @shalvah !
in a first try I'm just trying to throw an exception simply.. I have created an endpoint which controller only throws

fail: function (req, res) {
    throw (new Error('This is a runtime error generated by to test honeybadger in app.'));
 }

and what happened is that sails response serverError is "activated" and if I have a Honeybadger.notify / notifyAsync there I have the errors mentioned

shalvah · 2022-07-06T18:43:11Z

What do you mean by sails response serverError? Is this a custom server error file you added? What does that look like?

shalvah · 2022-07-06T18:44:46Z

Also, did you call Honeybadger.configure before trying to call notify?

It looks like this should be fairly straightforward to fix, but the Sails docs are terrible on error handling, so that's probably how this scenario was missed in the first place.

atex21 · 2022-07-06T18:50:56Z

What do you mean by sails response serverError? Is this a custom server error file you added? What does that look like?

Yes, it's a file that can be configured in sails to answer to res.serverError() , the file is api/responses/serverError.js

And yes, I do the config of honeybadger at the "beggining", in config/http.js as described in honeybadger docs

shalvah · 2022-07-06T19:24:54Z

Still can't reproduce. This is working for me:

serverError.js:

const Honeybadger = require('@honeybadger-io/js');

module.exports = function serverError(optionalData) {
  Honeybadger.notify(optionalData);

  var req = this.req;
  var res = this.res;

  if (_.isError(optionalData)) {
    sails.log.info('Custom response `res.serverError()` called with an Error:', optionalData);
    return res.status(400).send(optionalData.stack);
  }
};

The handler:

module.exports = {
  fn: function (req, res) {
    e = new Error("BAD THINGS");

    throw e;
    return {};
  }
};

What am I missing?

Also, I just noticed you have two exceptions raised. Are they for the different versions of Honeybadger? Because that first one doesn't seem related.

afilipa · 2022-07-06T20:58:13Z

@shalvah are you using docker too? 🤔

And in your example did you put honeybadger configuration in http.js?

The different exceptions I mentioned first are related to two versions of honeybadger, yes.
And I only see the errors trying to debug, with logs in honeybadger.js.

subzero10 · 2022-07-07T19:01:48Z

@shalvah

you said you were able to reproduce this; was it in Docker or outside?

I didn't use Docker. What I was able to reproduce is the fact that i couldn't make the integration work as described in the documentation. But you already confirmed that too.

shalvah · 2022-07-10T11:45:57Z

@afilipa okay, you've definitely got something weird going on here. Your error is occurring during the uncaughtExceptionListener , which shouldn't be called, as Sails catches that error and routes it to the serverError handler. And it looks like this may have something to do with the New Relic library, which seems to wrap and override some Node.js behaviour. Can you try disabling the New Relic module (ensure it's not require()d anywhere.

I also see you're using ts-node, which may be another cause of troubles itself. But I can't be sure. Also, are you using import, and is it ESM import or TypeScript import?

Also, can you upload a basic repo for reproduction? Or at least share full versions of the relevant files (routes, http, controller, serverError).

shalvah · 2022-07-10T11:50:43Z

Also: it seems the middleware approach does work, but only for async errors. (You can see this by throwing asynchronously in your controller: setTimeout(() => { throw new Error('Badgers!') }, 100).) But it's kind of pointless if you have a custom serverError, so I'll update the docs to recommend the serverError approach instead.

shalvah · 2022-07-11T20:08:55Z

Oops. I meant @atex21. Or whoever is having the issue.

atex21 · 2022-07-12T08:46:45Z

@afilipa okay, you've definitely got something weird going on here. Your error is occurring during the uncaughtExceptionListener , which shouldn't be called, as Sails catches that error and routes it to the serverError handler. And it looks like this may have something to do with the New Relic library, which seems to wrap and override some Node.js behaviour. Can you try disabling the New Relic module (ensure it's not require()d anywhere.

I also see you're using ts-node, which may be another cause of troubles itself. But I can't be sure. Also, are you using import, and is it ESM import or TypeScript import?

Also, can you upload a basic repo for reproduction? Or at least share full versions of the relevant files (routes, http, controller, serverError).

Hi @shalvah!
I'm still trying to find the issue, I disabled new relic as you mentioned but it still doesn't work 😕
I'm also trying to do a little side project to reproduce it and show you, as soon as I have news here I'll let you know.

Regarding the import of honeybadger, I'm using the require('@honeybadger-io/js') as said in documentation.

Oops. I meant @atex21. Or whoever is having the issue.

No prob 😛, afilipa was me too, just used personal account because it was weekend and I didn't have company account 😉

shalvah · 2022-07-16T20:16:22Z

Also, please include your New Relic setup in your reproduction (minus sensitive data, of course). I strongly suspect that's the culprit here.

atex21 · 2022-07-18T09:21:31Z

Hi @shalvah !
I still have no news 😩

The new relic info is basically:
package.json
"newrelic": "8.14.1"

app.js
const newrelic = require('newrelic');

newrelic.js

'use strict'
 require('dotenv').config();
 
exports.config = {
   app_name: [process.env.NEW_RELIC_APP_NAME],
   license_key: process.env.NEW_RELIC_LICENSE_KEY,

  distributed_tracing: {
    enabled: true
  },
  logging: {
    level: 'info'
  },

  allow_all_headers: true,
  attributes: {
    exclude: [
      'request.headers.cookie',
      'request.headers.authorization',
      'request.headers.proxyAuthorization',
      'request.headers.setCookie*',
      'request.headers.x*',
      'response.headers.cookie',
      'response.headers.authorization',
      'response.headers.proxyAuthorization',
      'response.headers.setCookie*',
      'response.headers.x*'
    ]
  }
}

But as you suggested before I had removed the require to newrelic and it didn't work too

shalvah · 2022-07-18T19:36:24Z

Sorry to make another request, but please share the stack trace with New Relic disabled. Still trying to understand why it's trying to call the uncaught exception handler. Maybe another error is being thrown? 🤔

atex21 · 2022-07-19T07:43:22Z

Hi @shalvah!

My debug without new relic seems to enter in a loop that breaks docker.. but in order to capture some logs I broke the loop and what I have is:

logHoneybadgerLoop.txt

my console.logs are in @honeybadger-io/js/dist/server/honeybadger.js that is:

honeybadger.js.txt

in ServerTransport.prototype.send I commented the first if clause to try taking into account the comment and the error I was having, but the result was the same 😩

hope to find something with your help, thank you!

shalvah · 2022-07-19T09:10:46Z

@atex21 looks like these are logs for v3. Let's focus on v4, please. 🙏

shalvah · 2022-07-19T09:14:22Z

Oh never mind. Looks like these are v4, but the error seems to be the first one you posted (which was v3)

atex21 · 2022-07-19T09:15:01Z

@atex21 looks like these are logs for v3. Let's focus on v4, please. 🙏

🤔
@shalvah which v3 and v4 are you talking about?! I'm using honeybadger 4.0.3

shalvah · 2022-07-19T09:34:48Z

Thanks, this is very helpful. Could you add a console.log(options.endpoint, httpOptions), just before var req = transport.request(?

atex21 · 2022-07-19T10:00:15Z

Thanks, this is very helpful. Could you add a console.log(options.endpoint, httpOptions), just before var req = transport.request(?

it prints:

[API] right before request https://api.honeybadger.io/v1/notices/js {
[API]   method: 'POST',
[API]   headers: {
[API]     'X-API-Key': 'our_api_key',
[API]     'Content-Type': 'application/json',
[API]     Accept: 'text/json, application/json',
[API]     'Content-Length': 10874
[API]   }
[API] }

atex21 · 2022-07-19T12:13:42Z

@shalvah I forget to mention that the logs I sent you are related to direct call to Honeybadger.notify with no use of middleware.

Updating the code as you mentioned in updated doc, middleware + use of errorHandler call, I have:

withHoneybadgerErrorHandler.txt

atex21 · 2022-07-20T18:37:16Z

Hey @shalvah & @subzero10 !
After one more bunch of hours debugging this.. I found a similar issue about [ERR_INVALID_ARG_TYPE]: The "listener" argument must be of type function. Received an instance of Object and tried to apply the solution mentioned..
what seems strange because both https.request(url, options, function(response) {...} and https.request(options, function(response) {...} should work..

after this try I had a new error, but the loop was gone!
new error:

connect ECONNREFUSED 127.0.0.1:443
[API]     at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1148:16) {
[API]   errno: -111,
[API]   code: 'ECONNREFUSED',
[API]   syscall: 'connect',
[API]   address: '127.0.0.1',
[API]   port: 443
[API] }
[API] [Honeybadger] Error report failed: an unknown error occurred. message=connect ECONNREFUSED 127.0.0.1:443

what also didn't make sense to me.. why was it trying to do something to 127.0.0.1 (?)

well, I had changed the code to have:

var httpOptions = {                      
                    method: options.method,                
                    headers: options.headers,                                               
                    url: options.endpoint
};   
...
var req = transport.request(httpOptions, function(res) { ...

but it seems url doesn't work as described before.. then I tried with:

var {protocol, hostname, pathname} = new url.URL(options.endpoint);
//  var protocol = new url.URL(options.endpoint).protocol;
var httpOptions = {                      
                    method: options.method,                
                    headers: options.headers,                                               
                    protocol: protocol,     
                    hostname: hostname,
                    path: pathname  
};   
...
var req = transport.request(httpOptions, function(res) { ...

and

🥹

So, given that changes were in file @honeybadger-io/js/dist/server/honeybadger.js, what can we do to make it work?!
I believe the solution works for all, I also tried with a little sample sails project and it worked, but it's in your side 😅

Please let me know how can we do it?
Thank you!!

shalvah · 2022-07-23T11:55:40Z

Found the problem.

socks-proxy-agent is patching Node.js' http(s).request (via node-agent-base). You can see that this guy also had the same 127.0.0.1 problem

This behaviour was fixed in 2019, so upgrading agent-base to v5 should fix this. However, you might not be able to upgrade, maybe because one of your dependencies is indirectly using it, so we'll probably also have to go with your suggested fix to work around that.

atex21 · 2022-07-25T08:02:04Z

Found the problem.

socks-proxy-agent is patching Node.js' http(s).request (via node-agent-base). You can see that this guy also had the same 127.0.0.1 problem

This behaviour was fixed in 2019, so upgrading agent-base to v5 should fix this. However, you might not be able to upgrade, maybe because one of your dependencies is indirectly using it, so we'll probably also have to go with your suggested fix to work around that.

Hi @shalvah !
Thank you for your help here 🙏
I also had noticed the point you mentioned about agent-base, but as you also said it's something I'm not able to upgrade (at least now), it's a dependency of a dependency ..

So, since you opened a PR with the workaround change in your side, which is the timeline to have it available to use (approximately 😅)?

Again, thanks a lot for your assistance!

shalvah · 2022-07-25T15:10:11Z

Just need a review from @subzero10 or @joshuap, and then I can merge and see about publishing a release.

subzero10 · 2022-07-25T15:36:19Z

Hey @shalvah, I just approved!
@shalvah and @atex21 thank you both for not giving up!

I am still confused though about this error. How is that related to the PR you submitted? Or is there a way for us to reproduce that error? I think I've seen that error again.

atex21 · 2022-07-25T15:44:55Z

Hey @shalvah, I just approved! @shalvah and @atex21 thank you both for not giving up!

I am still confused though about this error. How is that related to the PR you submitted? Or is there a way for us to reproduce that error? I think I've seen that error again.

Hey @subzero10 !
The error you mentioned is another one, that occurred to me when I used the new steps in the documentation about middleware.
After that error I removed the middleware again and simply use Honeybadger.notify in api/responses/serverError.js and I arrived to the solution submitted in the PR.

So, probably it would be needed a little more investigation regarding middleware use with sails 🤔

shalvah · 2022-07-25T15:48:15Z

Good point. That error only occurs because the original report sending crashed, leading to the uncaughtException handler being called. At that point, we've switched the store to the AsyncStore, which only works if it's inside a run() block, otherwise it returns undefined.. The solution would be to ignore an undefined value of store. Sending in a fix

subzero10 · 2022-07-26T05:54:28Z

Good point. That error only occurs because the original report sending crashed, leading to the uncaughtException handler being called. At that point, we've switched the store to the AsyncStore, which only works if it's inside a run() block, otherwise it returns undefined.. The solution would be to ignore an undefined value of store. Sending in a fix

Oh, that's an edgy scenario! Now it makes sense!

subzero10 · 2022-07-26T20:47:56Z

Hey @atex21, this is fixed with v4.0.5!

atex21 · 2022-07-27T08:19:45Z

Thank you @subzero10 & @shalvah for your efforts here!
Let's do it 🤾‍♀️

subzero10 self-assigned this Jul 5, 2022

shalvah mentioned this issue Jul 23, 2022

Workaround for Node.js-patching libraries #843

Merged

shalvah closed this as completed in 3d3ab08 Jul 25, 2022

shalvah mentioned this issue Jul 25, 2022

feat: combine contents from GlobalStore when reporting. #845

Closed

shalvah mentioned this issue Jul 26, 2022

Support Error.cause #847

Closed

no notifications with sailsJs + docker #825

no notifications with sailsJs + docker #825

Comments

subzero10 commented Jul 5, 2022

Discussed in #824

shalvah commented Jul 5, 2022

shalvah commented Jul 5, 2022

atex21 commented Jul 6, 2022

shalvah commented Jul 6, 2022

atex21 commented Jul 6, 2022

shalvah commented Jul 6, 2022

shalvah commented Jul 6, 2022 • edited Loading

atex21 commented Jul 6, 2022

shalvah commented Jul 6, 2022

afilipa commented Jul 6, 2022 • edited Loading

subzero10 commented Jul 7, 2022

shalvah commented Jul 10, 2022

shalvah commented Jul 10, 2022 • edited Loading

shalvah commented Jul 11, 2022

atex21 commented Jul 12, 2022

shalvah commented Jul 16, 2022

atex21 commented Jul 18, 2022 • edited Loading

shalvah commented Jul 18, 2022

atex21 commented Jul 19, 2022

shalvah commented Jul 19, 2022

shalvah commented Jul 19, 2022

atex21 commented Jul 19, 2022 • edited Loading

shalvah commented Jul 19, 2022

atex21 commented Jul 19, 2022

atex21 commented Jul 19, 2022

atex21 commented Jul 20, 2022 • edited Loading

shalvah commented Jul 23, 2022 • edited Loading

atex21 commented Jul 25, 2022

shalvah commented Jul 25, 2022

subzero10 commented Jul 25, 2022 • edited Loading

atex21 commented Jul 25, 2022

shalvah commented Jul 25, 2022

subzero10 commented Jul 26, 2022

subzero10 commented Jul 26, 2022

atex21 commented Jul 27, 2022

shalvah commented Jul 6, 2022 •

edited

Loading

afilipa commented Jul 6, 2022 •

edited

Loading

shalvah commented Jul 10, 2022 •

edited

Loading

atex21 commented Jul 18, 2022 •

edited

Loading

atex21 commented Jul 19, 2022 •

edited

Loading

atex21 commented Jul 20, 2022 •

edited

Loading

shalvah commented Jul 23, 2022 •

edited

Loading

subzero10 commented Jul 25, 2022 •

edited

Loading