HTTP issues tryin' to get the metadata

[alexander-girsh]

Hi there!

Previously we used DigitalOcean's managed k8s clusters and after the fix googleapis/google-auth-library-nodejs#787 all was OK, but now we moved our project to our country's local managed k8s provider - Yandex.Cloud and so we're experiencing some errors with your lib which we love so much.

Supposition

When an instance of Logging class of your lib is running, it tries to use gcp-metadata (during the ./metadata.js wrapper) lib to understand the current execution context (GKE, GCE, ...). This lib handles EHOSTDOWN etc. but don't handles the FetchError and throws an exception which stops your initialization process.

Error log

FetchError: Response timeout while trying to fetch
http://169.254.169.254/computeMetadata/v1/instance (over 3000ms)
at Timeout._onTimeout (/app/node_modules/node-fetch/lib/index.js:387:12)
at listOnTimeout (internal/timers.js:549:17)
at processTimers (internal/timers.js:492:7)

Environment details

• OS: node:13.8.0 / node:13.8.0-alpine3.11 (docker images), Yandex.Cloud managed k8s (
  1.16)
• node.js version: 13.8.0
• npm version: 6.14.4
• @google-cloud/logging version: 7.3.0

[stephenplusplus]

@bcoe any ideas on this one? If I recall correctly, you previously worked with this topic in gcp-metadata.

edit Hi, @noguilty4you!

[alexander-girsh]

@stephenplusplus, Stephen hi, we're waiting for @bcoe's response? =)

[bcoe]

@stephenplusplus @noguilty4you how are credentials being provided to the logging client, are you using GOOGLE_APPLICATION_CREDENTIALS?

During the initial bootstrapping step, an attempt should not be made to connect to 169.254.169.254 if credentials have been explicitly provided. I wonder if we're hitting that endpoint elsewhere in the logging library.

[alexander-girsh]

@bcoe, thank you for response.

In my case with Yandex.Cloud I pass the credentials explicitly:
logName: config.GOOGLE_BUNYAN_LOGGER_JOURNAL_NAME,
keyFilename: './logger/google-stackdriver-credentials.json',
autoRetry: true,
maxRetries: 10

Which credentials should I pass to prevent the request to 169.254.169.254?
I tried to pass .resource: { type: "global" }, but it had no effect.

google-stackdriver-credentials.json content is:
"type": "service_account",
"project_id": "***hidden***",
"private_key_id": "***hidden***",
"private_key": "***hidden***",
"client_email": "***hidden***@***hidden***.iam.gserviceaccount.com",
"client_id": "***hidden***",
"auth_uri": "https://accounts.google.com/o/oauth2/auth",
"token_uri": "https://oauth2.googleapis.com/token",
"auth_provider_x509_cert_url": "https://www.googleapis.com/oauth2/v1/certs",
"client_x509_cert_url": "https://www.googleapis.com/robot/v1/metadata/x509/***hidden***.iam.gserviceaccount.com"

[bcoe]

@noguilty4you mind providing the snippet of code you use to actually instantiate the client as well? 👍

I'm definitely surprised that the metadata server is being hit.

[alexander-girsh]

@bcoe, OK, this is it.

/**
 * @module logger/bunyan
 * @desc It uses the bunyan library as logging solution
 * to format process logs to json and save any serializable
 * payload with the log records.
 *
 * Also it uses the simple stream to stdout/stderr
 * to save it if the cloud logging connection fails.
 *
 * Also it catches the unhandled errors / promise rejections
 * to log it on 'fatal' level
 * @see {@link https://www.npmjs.com/package/bunyan}
 */

import bunyan from 'bunyan'
import GoogleBunyanAdapter from '@google-cloud/logging-bunyan'
import {config} from './config.mjs'


/**
 * @desc this export allows any module to create own logging instance (like the express.js app creates the own one)
 * @type {Object}
 */
export const google_journals_options = {
    logName: config.GOOGLE_BUNYAN_LOGGER_JOURNAL_NAME,
    keyFilename: './logger/google-stackdriver-credentials.json',
    autoRetry: true,
    maxRetries: 10,
}

const google_journals_connection = new GoogleBunyanAdapter.LoggingBunyan(google_journals_options)

export const logger = bunyan.createLogger({
    name: config.SERVICE_NAME,
    service_name: config.SERVICE_NAME,
    service_version: config.SERVICE_VERSION,
    streams: [
        /**
         * @see {link: https://github.com/googleapis/nodejs-logging-bunyan#readme}
         * @type {GoogleBunyanAdapter.StreamResponse}
         */
        google_journals_connection.stream('info')
    ],
    src: true
})

[alexander-girsh]

@bcoe, let's spend some time to solve that. Otherwise I have to fork the thick pack of nodejs-logging-bunyan dependencies =)

[bcoe]

@noguilty4you thanks for following up.

@simonz130 wanted to put this bug on your radar, what's odd to me, is if we've provided the keyFileName we shouldn't be hitting the metadata server to fetch resource (obviously we are.). I'm not sure if this is a bug in the auth library, or in the logging library.

[0xSage]

@noguilty4you can you provide serviceContext to your google_journals_options, e.g.

const context = {
  service: 'something',
  version: '1.1', //optional
}

const google_journals_options = {
  logName: 'my-log',
  serviceContext: context,
  ...
}

It looks like the LoggingBunyan constructor attempts to detectServiceContext when your serviceContext config field is nil. DetectServiceContext does call the metadata service.

I'll patch the libraries to do better error handling shortly. But don't let me block you - the above should (hopefully) fix your issue asap.

[0xSage]

Update: I spent some time investigating if we should handle this in Nodejs-logging or Nodejs-logging-bunyan, but that breaks usage pattern for getenv. So I filed a bug within google-auth-library-nodejs repo instead.