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

Node 14 read ECONNRESET error #145

Closed
aaestrada opened this issue Nov 4, 2021 · 3 comments
Closed

Node 14 read ECONNRESET error #145

aaestrada opened this issue Nov 4, 2021 · 3 comments

Comments

@aaestrada
Copy link
Contributor

aaestrada commented Nov 4, 2021

I'm running performance and capacity tests with Clinic js

but when enable this hapi-pino library i receive the following error

[1636045080852] INFO (23140 on MacBook-Pro-de-Aaron.local): request completed req: { "id": "1636045080846:MacBook-Pro-de-Aaron.local:23140:kvl6zrp4:12905", "method": "get", "url": "/items", "headers": { "host": "localhost:3000", "connection": "keep-alive" }, "remoteAddress": "127.0.0.1", "remotePort": 56007 } res: { "statusCode": 200, "headers": { "content-type": "application/json; charset=utf-8", "cache-control": "no-cache", "content-length": 96, "accept-ranges": "bytes" } } responseTime: 6 [1636045080853] ERROR (23140 on MacBook-Pro-de-Aaron.local): err: { "type": "Error", "message": "read ECONNRESET", "stack": Error: read ECONNRESET at TCP.onStreamRead (internal/stream_base_commons.js:209:20) at TCP.callbackTrampoline (internal/async_hooks.js:130:17) "errno": -54, "code": "ECONNRESET", "syscall": "read" }

i make public repo to reproduce this error.

https://github.com/aaestrada/hapi-node-14-example

There is all the information to test and reproduce this error.

or follow this step by step guide:

https://github.com/aaestrada/hapi-node-14-example/tree/master/nodejs-profile

let me know i there is something more than i can do!

@ovhemert
Copy link

I've been running your example code and discovered the following:

The issue is not specific to Clinic, Node v14.x or your code example.
The error occurs on every implementation of hapi-pino (also the example in this repo) when called with autocannon default settings.

What is happening?

When running Clinic with the included commands, autocannon is started to hit the endpoint. No commandline params are specified here, so autocannon defaults to a duration of 10 seconds (-d 10). After that duration, any pending client connections are killed and that is what is causing the error on the server. The default is also to run 10 connections (-c 10), so that is why you would see the error occur 10x at the end.
If you run autocannon with the option -a 1000, the duration is ignored, and the test runs for 1000 complete requests. No killed connections in the end, and clean exit. The errors do not appear.

Quick fix for now, would be to run autocannon without a specified duration.

The reason that the errors are logged by the plugin

The HAPI server throws the following log event for this error:

  {
    "channel": "internal",
    "tags": ["connection", "client", "error"],
    "error": {
      "code": "ECONNRESET",
      ...
    }
  }

This event is being handled by the plugin here.
If this can be re-written to:

    if (!isCustomTagsLoggingIgnored(event, ignoredEventTags.log)) { // first check on ignoring tags
      if (event.error) {
        logger.error({ err: event.error })
      } else {
        logEvent(logger, event)
      }
    }

... it would be possible to ignore these client events with this plugin config:

  await server.register({
    plugin: require('hapi-pino'),
    options: {
      prettyPrint: true,
      ignoredEventTags: { log: ['client'], request: '*' }
    }
  })

cc @mcollina

@aaestrada
Copy link
Contributor Author

aaestrada commented Nov 24, 2021

Quick fix for now, would be to run autocannon without a specified duration.

Hi @ovhemert! Thanks for this information! This will be so helpful for us! Can i make a pr with these changes?

so we can replace the event.error condition here

with

    if (!isCustomTagsLoggingIgnored(event, ignoredEventTags.log)) { // first check on ignoring tags
      if (event.error) {
        logger.error({ err: event.error })
      } else {
        logEvent(logger, event)
      }
    }

so after this change should be able to ignore this events tags as you are showing here... right?

  await server.register({
    plugin: require('hapi-pino'),
    options: {
      prettyPrint: true,
      ignoredEventTags: { log: ['client'], request: '*' }
    }
  })

i know i repeating your comment... I wanna be sure if i'm following you!

i'll make a pr with this soom as posible!

aaestrada added a commit to aaestrada/hapi-pino that referenced this issue Nov 24, 2021
mcollina pushed a commit that referenced this issue Jan 26, 2022
* Fix read ECONRESET error #145

* Unit tests: Review ignoredEventTags before process events logs

* log event errors separated of log events
@aaestrada
Copy link
Contributor Author

(#149) fixed this issue!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants