receiving "connect EHOSTUNREACH 169.254.169.254:80" when following simple README

[mreinigjr]

Environment details

• OS: Ubuntu 18 LTS
• Node.js version: 10.16.0
• npm version: 6.11.3
• @google-cloud/logging-winston version: 2.0.1
• winston version: 3.2.1

Steps to reproduce

1. Use a non-GCP server/environment.
2. Follow this: https://github.com/googleapis/nodejs-logging-winston/blob/master/samples/quickstart.js

This issue is very similar if not identical to:
googleapis/nodejs-logging-bunyan#353

The only resolution I have found so far is to revert back to logging-winston version 0.11.1. Under the environment above, everything then works.

I am seeing this issues whether I set the GOOGLE_APPLICATION_CREDENTIALS env variable or specify the projectId and keyFilename or specify projectId and credentials when creating the LoggingWinston object. So all 3 ways fail on v1.0.0+, but all 3 work on v0.11.1.

I have seen the error appear two different ways, with the first type of error message appearing from following the above steps.

(node:12374) UnhandledPromiseRejectionWarning: FetchError: request to http://169.254.169.254/computeMetadata/v1/instance failed, reason: connect EHOSTUNREACH 169.254.169.254:80
    at ClientRequest.<anonymous> (/home/user/projects/test/node_modules/node-fetch/lib/index.js:1455:11)
    at ClientRequest.emit (events.js:198:13)
    at Socket.socketErrorListener (_http_client.js:392:9)
    at Socket.emit (events.js:198:13)
    at emitErrorNT (internal/streams/destroy.js:91:8)
    at emitErrorAndCloseNT (internal/streams/destroy.js:59:3)
    at process._tickCallback (internal/process/next_tick.js:63:19)
(node:12374) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1)
(node:12374) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

Here is an alternative error message that we are seeing using the same environment outlined above, but on a remote server. I do not have reproducible steps for this error message, but this was the first error message we saw before digging deeper. The below error message lead us to the reproducible error message above.

(node:21602) UnhandledPromiseRejectionWarning: Error: Unsuccessful response status code. Request failed with status code 404
    at Gaxios.request (/home/user/test/node_modules/gaxios/build/src/gaxios.js:70:23)
    at process._tickCallback (internal/process/next_tick.js:68:7)
(node:21602) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1)
(node:21602) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

Thanks!

[bcoe]

@michaelreinig @marklawlor if you set the resource type to global when writing the log, you can work around this issue, until we land a fix tomorrow:

log.write(entry, {
  resource: {
    type: 'global'
  }
})

[mreinigjr]

Thank you @bcoe. I will do as you have suggested until you release the fix. Thank you to you and your team for looking into this so quickly.

[bcoe]

@michaelreinig if you update your dependencies, such that @google-cloud/logging is now at 5.3.1, this issue should now be addressed 👍

Please feel free to reopen if you're continuing to have issues, thank you for your patience.

[robymes]

Hello,
I still experience the same behavior, @google-cloud/logging-winston:2.0.1 still doesn't work, @google-cloud/logging-winston:0.11.1 works
I tried to completely wipe out node_modules folder, reinstall modules and rebuild npm, but I still receive the following error:
(node:25552) UnhandledPromiseRejectionWarning: FetchError: request to http://169.254.169.254/computeMetadata/v1/instance failed, reason: connect ENETUNREACH 169.254.169.254:80
Is it possible that updating @google-cloud/logging is not enough?
Do we also need to wait for a new version for @google-cloud/logging-winston?

[bcoe]

@robymes make sure you delete package-lock.json, and rm -rf node_modules, my hunch is that perhaps you have the old dependency in your tree.

If you continue to bump into issues, please go ahead and open a new issue 👍

[mreinigjr]

@michaelreinig if you update your dependencies, such that @google-cloud/logging is now at 5.3.1, this issue should now be addressed

Please feel free to reopen if you're continuing to have issues, thank you for your patience.

@bcoe, I can confirm that the issue has been resolved. Thanks again for your help.

[bcoe]

@michaelreinig awesome, thanks for reporting the issue; helped is identify the problem quickly.

[distractedCoding]

@michaelreinig Hey, the bug still appears in 5.3.1 but it has a not consistent behaviour.

(node:16476) UnhandledPromiseRejectionWarning: FetchError: request to http://169.254.169.254/computeMetadata/v1/instance failed, reason: connect ENETUNREACH 169.254.169.254:80 at ClientRequest.<anonymous> (D:\BOTfriends\Code\botfriendsLogger\node_modules\node-fetch\lib\index.js:1455:11) at ClientRequest.emit (events.js:182:13) at Socket.socketErrorListener (_http_client.js:399:9) at Socket.emit (events.js:182:13) at emitErrorNT (internal/streams/destroy.js:82:8) at emitErrorAndCloseNT (internal/streams/destroy.js:50:3) at process.internalTickCallback (internal/process/next_tick.js:72:19) (node:16476) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1) (node:16476) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

[robymes]

yes resolved, thank you for your support @bcoe !

[dan-turner]

This is still intermittently happening for me with the following config:

import { LoggingWinston } from "@google-cloud/logging-winston";
import config from "../config";

const gcpTransport = new LoggingWinston({
      projectId: config.serviceAccount.projectId,
      credentials: {
        client_email: config.serviceAccount.clientEmail,
        private_key: config.serviceAccount.privateKey
      },
      logName: `my-api-${config.environment}`,
      resource: {        
        type: "global"
      }
    });

<snipped>

The other annoying thing is, simply importing the transport as above (and never even new'ing one up), is enough for it to cause open handle warnings for @grpc when running under jest

Jest has detected the following 1 open handle potentially keeping Jest from exiting:

  ●  Timeout

      at new SubchannelPool (node_modules/@grpc/grpc-js/build/src/subchannel-pool.js:38:13)
      at Object.<anonymous> (node_modules/@grpc/grpc-js/build/src/subchannel-pool.js:99:30)

[dan-turner]

I notice that this one is still closed, it's definitely causing problems for me still.

It's intermittently failing with connect EHOSTUNREACH 169.254.169.254:80 when configuring LoggingWinston as follows:

import { LoggingWinston } from "@google-cloud/logging-winston";
import config from "../config";

const gcpTransport = new LoggingWinston({
      projectId: config.serviceAccount.projectId,
      credentials: {
        client_email: config.serviceAccount.clientEmail,
        private_key: config.serviceAccount.privateKey
      },
      logName: `my-api-${config.environment}`,
      resource: {        
        type: "global"
      }
    });

<snipped>

[bcoe]

@dan-turner is this mainly happening when in the context of Jest, I think this might potentially be related to:

#414

[dan-turner]

@bcoe no it was happening in our now.sh environments. It was causing the first few requests to each lambda to fail with 502. Hitting each route enough times after they become warm, the problem would go away and logs would start to appear in StackDriver. Ultimately we couldn’t accept this though and had to remove this package for now.

[chrisathook]

i was able to replicate this as well. if you hit the end point a few times it will start to work. is there anyway to make this work on first request? this is definitely not fixed.

[bcoe]

@chrisathook in what environment are you using @google-cloud/logging?

[chrisathook]

I am testing in a local docker container based on the node:13.8 image from docker. Below are the versions of logging winston and logging i have installed on the project.

"@google-cloud/logging": "^7.2.3",
"@google-cloud/logging-winston": "^3.0.5",

when i run the app in my local Docker container i get the error. if i run it a few times the error disappears, then if i wait a bit it will return. Oddly if i run the app just in node on windows 10 it does not happen.

[bcoe]

@chrisathook could you share the exact exception that you're seeing? gcp-metadata should not be throwing exceptions when EHOSTUNREACH is hit, I just want to confirm that this is in fact the error you're seeing, in which case there must be a code path we didn't think of.

[chrisathook]

here is what i am seeing when testing
error: request to http://169.254.169.254/computeMetadata/v1/instance failed, reason: connect ECONNREFUSED 169.254.169.254:80
error: FetchError: request to http://169.254.169.254/computeMetadata/v1/instance failed, reason: connect ECONNREFUSED 169.254.169.254:80
at ClientRequest. (/usr/src/app/node_modules/node-fetch/lib/index.js:1455:11)
at ClientRequest.emit (events.js:321:20)
at Socket.socketErrorListener (_http_client.js:432:9)
at Socket.emit (events.js:321:20)
at emitErrorNT (internal/streams/destroy.js:84:8)
at processTicksAndRejections (internal/process/task_queues.js:84:21)

[bcoe]

It looks like ECONNREFUSED is not currently one of the exceptions handled by gcp-metadata we can try adding this to the list of suppressed errors.

[JustinBeckwith]

Pretty sure we have this one fixed now :) Please do let us know if you're still running into problems?