Firebase-tools: Emulator errors with external HTTP calls when GOOGLE_APPLICATION_CREDENTIALS is not set.

[larssn]

_Not sure how best to post this using your neat template, since it might not be a bug. Maybe I'm just misunderstanding something._

I'm doing a few HTTP POST/PUT on a test site (hosted on AWS) we have set up, and. We're on Blaze so external network calls should be allowed. I'm getting the errors that can be seen in the log below when GOOGLE_APPLICATION_CREDENTIALS is not set.

Maybe related: https://github.com/firebase/firebase-functions/issues/561

[REQUIRED] Environment info

firebase-tools: 7.4.0

Platform: macOS

[REQUIRED] Test case

[REQUIRED] Steps to reproduce

[REQUIRED] Expected behavior

[REQUIRED] Actual behavior

Without the GOOGLE_APPLICATION_CREDENTIALS environment variable:

firebase emulators:start --only functions,firestore,database
i  Starting emulators: ["functions","firestore","database"]
✔  functions: Using node@8 from host.
✔  functions: Emulator started at http://localhost:5001
i  firestore: Serving WebChannel traffic on at http://localhost:8081
i  firestore: Emulator logging to firestore-debug.log
✔  firestore: Emulator started at http://localhost:8080
i  firestore: For testing set FIRESTORE_EMULATOR_HOST=localhost:8080
i  database: Emulator logging to database-debug.log
✔  database: Emulator started at http://localhost:9000
i  database: For testing set FIREBASE_DATABASE_EMULATOR_HOST=localhost:9000
i  functions: Watching "/cloud-functions-v2" for Cloud Functions...
✔  functions[onCategoryCreate]: firestore function initialized.
✔  functions[onCategoryUpdate]: firestore function initialized.
✔  functions[onProductCreate]: firestore function initialized.
✔  functions[onProductUpdate]: firestore function initialized.
✔  functions[onUserWritten]: firestore function initialized.
✔  functions[v1]: http function initialized (http://localhost:5001/app/europe-west1/v1).
i  functions[hourly]: function ignored because the pubsub.googleapis.com emulator does not exist or is not running.
i  functions[onFirebaseUserDeleted]: function ignored because the firebaseauth.googleapis.com emulator does not exist or is not running.
✔  All emulators started, it is now safe to connect.
i  functions: Beginning execution of "onCategoryCreate"
⚠  Unknown network resource requested!
   - URL: "http://169.254.169.254/computeMetadata/v1/instance"
i  functions: Beginning execution of "onProductCreate"
⚠  Unknown network resource requested!
   - URL: "http://169.254.169.254/computeMetadata/v1/instance"
⚠  functions: FetchError: Unexpected error determining execution environment: request to http://169.254.169.254/computeMetadata/v1/instance failed, reason: connect EHOSTDOWN 169.254.169.254:80 - Local (192.168.0.100:51124)
    at ClientRequest.<anonymous> (/cloud-functions-v2/node_modules/node-fetch/lib/index.js:1455:11)
    at emitOne (events.js:116:13)
    at ClientRequest.emit (events.js:211:7)
    at Socket.socketErrorListener (_http_client.js:401:9)
    at emitOne (events.js:116:13)
    at Socket.emit (events.js:211:7)
    at emitErrorNT (internal/streams/destroy.js:66:8)
    at _combinedTickCallback (internal/process/next_tick.js:139:11)
    at process._tickCallback (internal/process/next_tick.js:181:9)
    at Function.Module.runMain (module.js:696:11)
⚠  Your function was killed because it raised an unhandled error.
(node:72549) UnhandledPromiseRejectionWarning: Error: Can't set headers after they are sent.
    at validateHeader (_http_outgoing.js:491:11)
    at ServerResponse.setHeader (_http_outgoing.js:498:3)
    at ServerResponse.header (/usr/local/lib/node_modules/firebase-tools/node_modules/express/lib/response.js:771:10)
    at ServerResponse.send (/usr/local/lib/node_modules/firebase-tools/node_modules/express/lib/response.js:170:12)
    at ServerResponse.json (/usr/local/lib/node_modules/firebase-tools/node_modules/express/lib/response.js:267:15)
    at Function.<anonymous> (/usr/local/lib/node_modules/firebase-tools/lib/emulator/functionsEmulator.js:88:24)
    at Generator.next (<anonymous>)
    at fulfilled (/usr/local/lib/node_modules/firebase-tools/lib/emulator/functionsEmulator.js:4:58)
    at <anonymous>
    at process._tickDomainCallback (internal/process/next_tick.js:229:7)
(node:72549) 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:72549) [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.
i  functions: Beginning execution of "onProductUpdate"
⚠  Unknown network resource requested!
   - URL: "http://169.254.169.254/computeMetadata/v1/instance"
⚠  functions: Your function timed out after ~60s. To configure this timeout, see
      https://firebase.google.com/docs/functions/manage-functions#set_timeout_and_memory_allocation.
⚠  functions: Your function timed out after ~60s. To configure this timeout, see
      https://firebase.google.com/docs/functions/manage-functions#set_timeout_and_memory_allocation.

WITH GOOGLE_APPLICATION_CREDENTIALS set:

firebase emulators:start --only functions,firestore,database
i  Starting emulators: ["functions","firestore","database"]
✔  functions: Using node@8 from host.
✔  functions: Emulator started at http://localhost:5001
i  firestore: Serving WebChannel traffic on at http://localhost:8081
i  firestore: Emulator logging to firestore-debug.log
✔  firestore: Emulator started at http://localhost:8080
i  firestore: For testing set FIRESTORE_EMULATOR_HOST=localhost:8080
i  database: Emulator logging to database-debug.log
✔  database: Emulator started at http://localhost:9000
i  database: For testing set FIREBASE_DATABASE_EMULATOR_HOST=localhost:9000
i  functions: Watching "/cloud-functions-v2" for Cloud Functions...
⚠  functions: Your GOOGLE_APPLICATION_CREDENTIALS environment variable points to /Users/my_user/.firebase-adminsdk-1kbpo-1febf42538.json. Non-emulated services will access production using these credentials. Be careful!
✔  functions[onCategoryCreate]: firestore function initialized.
✔  functions[onCategoryUpdate]: firestore function initialized.
✔  functions[onProductCreate]: firestore function initialized.
✔  functions[onProductUpdate]: firestore function initialized.
✔  functions[onUserWritten]: firestore function initialized.
✔  functions[v1]: http function initialized (http://localhost:5001/app/europe-west1/v1).
i  functions[hourly]: function ignored because the pubsub.googleapis.com emulator does not exist or is not running.
i  functions[onFirebaseUserDeleted]: function ignored because the firebaseauth.googleapis.com emulator does not exist or is not running.
✔  All emulators started, it is now safe to connect.
⚠  functions: Your GOOGLE_APPLICATION_CREDENTIALS environment variable points to /Users/my_user/.firebase-adminsdk-1kbpo-1febf42538.json. Non-emulated services will access production using these credentials. Be careful!
i  functions: Beginning execution of "onCategoryCreate"
⚠  functions: Your GOOGLE_APPLICATION_CREDENTIALS environment variable points to /Users/my_user/.firebase-adminsdk-1kbpo-1febf42538.json. Non-emulated services will access production using these credentials. Be careful!
⚠  Google API requested!
   - URL: "https://www.googleapis.com/oauth2/v4/token"
   - Be careful, this may be a production service.
i  functions: Beginning execution of "onProductCreate"
⚠  functions: Your GOOGLE_APPLICATION_CREDENTIALS environment variable points to /Users/my_user/.firebase-adminsdk-1kbpo-1febf42538.json. Non-emulated services will access production using these credentials. Be careful!
⚠  Google API requested!
   - URL: "https://www.googleapis.com/oauth2/v4/token"
   - Be careful, this may be a production service.
i  functions: Beginning execution of "onProductUpdate"
⚠  functions: Your GOOGLE_APPLICATION_CREDENTIALS environment variable points to /Users/my_user/.firebase-adminsdk-1kbpo-1febf42538.json. Non-emulated services will access production using these credentials. Be careful!
⚠  Google API requested!
   - URL: "https://www.googleapis.com/oauth2/v4/token"
   - Be careful, this may be a production service.
⚠  functions: Your function timed out after ~60s. To configure this timeout, see
      https://firebase.google.com/docs/functions/manage-functions#set_timeout_and_memory_allocation.
⚠  functions: Your function timed out after ~60s. To configure this timeout, see
      https://firebase.google.com/docs/functions/manage-functions#set_timeout_and_memory_allocation.
⚠  functions: Your function timed out after ~60s. To configure this timeout, see
      https://firebase.google.com/docs/functions/manage-functions#set_timeout_and_memory_allocation.

[google-oss-bot]

This issue does not have all the information required by the template. Looks like you forgot to fill out some sections. Please update the issue with more information.

[samtstern]

@larssn can you show any code you're using related to the function (onProductCreate) or initialization (calls to Firebase SDK or similar)?

I want to figure out why it would be calling the computeMetadata API.

[larssn]

Alright, I boiled it down into something incredibly simple.
Each time I run npm test, it gives me this:

⚠  Unknown network resource requested!
   - URL: "http://169.254.169.254/computeMetadata/v1/instance"
⚠  functions: Your function timed out after ~60s. To configure this timeout, see
      https://firebase.google.com/docs/functions/manage-functions#set_timeout_and_memory_allocation.

It boils down to this line:

await admin.firestore().collection('collection_that_doesnt_exist').get();

If I comment it out, the unknown network errors goes away. The timeout stays though.
I can't see any floating promises, so it's weird.

_index.ts_

import * as admin from 'firebase-admin';
import * as functions from 'firebase-functions';
admin.initializeApp();

export const onProductCreate = functions.region('europe-west1').firestore
  .document('businesses/{businessId}/products/{productId}')
  .onCreate(async (snapshot, context) => {
    console.log('Test case');
    await admin.firestore().collection('collection_that_doesnt_exist').get();
  });

_test.ts_

/// <reference path='../node_modules/mocha-typescript/globals.d.ts' />

import * as firebase from "@firebase/testing";
import * as fs from "fs";

const projectId = "app"; // <-- I've removed my real project id, but I'm using the real one.
const coverageUrl = `http://localhost:8080/emulator/v1/projects/${projectId}:ruleCoverage.html`;
const admin = firebase.initializeAdminApp({ projectId });
const rules = fs.readFileSync("firestore.rules", "utf8");

before(async () => {
  await firebase.loadFirestoreRules({ projectId, rules });
});

after(async () => {
  // Clear the database after testing
  await firebase.clearFirestoreData({ projectId });
  await Promise.all(firebase.apps().map(app => app.delete()));
  console.log(`View rule coverage information at ${coverageUrl}\n`);
});

@suite
export class TestCase {
  @test(timeout(0))
  async "test case"() {
    await admin.firestore().doc(`businesses/_test_business_id_/products/_test_product_id_`).set({hello: 'world'});
  }
}

[samtstern]

@larssn sorry I sort of went dark here. I'm on a bit of a Firebase world tour right now (hello from Dubai!) and haven't had much quality debugging time. I'll be back in my normal office on Monday and will try and dig into this.

[larssn]

No worries 😄

Dont get lost in the desert

[samtstern]

@larssn hmm I am not able to reproduce this at all.

Can you try running your test again but with this additional logging and show me what you see?

exports.onProductCreate = functions.region('europe-west1').firestore
    .document('businesses/{businessId}/products/{productId}')
    .onCreate(async (snapshot, context) => {
        console.log(`Detected write to: ${snapshot.ref.path}`);
        console.log(`Firestore Settings: ${util.inspect(admin.firestore()._settings)}`)
        const snap = await admin.firestore().collection('collection_that_doesnt_exist').get();
        console.log(`Admin read finished, empty=${snap.empty}`);
    });

Here's what I see:

i  functions: Beginning execution of "onProductCreate"
>  Detected write to: businesses/_test_business_id_/products/_test_product_id_
>  Firestore Settings: { projectId: 'fir-dumpster',
  firebaseVersion: '8.6.0',
  libName: 'gccl',
  libVersion: '2.4.0 fire/8.6.0',
  port: 8080,
  servicePath: 'localhost',
  service: 'firestore.googleapis.com',
  sslCreds: InsecureChannelCredentialsImpl { callCredentials: EmptyCallCredentials {} },
  customHeaders: { Authorization: 'Bearer owner' } }

[larssn]

I pretty much get the same:

i  functions: Beginning execution of "onProductCreate"
>  Detected write to: businesses/_test_business_id_/products/_test_product_id_
>  Firestore Settings: { projectId: 'app',
  firebaseVersion: '8.6.0',
  libName: 'gccl',
  libVersion: '2.3.0 fire/8.6.0',
  port: 8080,
  servicePath: 'localhost',
  service: 'firestore.googleapis.com',
  sslCreds: { callCredentials: {} },
  customHeaders: { Authorization: 'Bearer owner' } }
>  Admin read finished, empty=true
i  functions: Finished "onProductCreate" in ~1s

No errors today. I also tried reverting back, but that also worked.

Is there any servers involved when running the emulator? I'm thinking it was some sort of transient problem.

Going back to my original code, it seems the grpc dependency was causing some of those problems.
I had this in the top of my index.ts:

import grpc = require('grpc');
admin.initializeApp();
admin.firestore().settings({ grpc });

I added it last week, after seeing some server problems with grpc-js ((node:2) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 close listeners added. Use emitter.setMaxListeners() to increase limit). Googling it revealed an issue (https://github.com/googleapis/nodejs-firestore/issues/661) with grpc-js.

I'll go back to it. Hopefully I won't be seeing the above error much.

[larssn]

I forgot why I opened this issue in the first place 👍 😓
I still get the Unknown network resource requested! errors.

Changing onProductCreate to:

export const onProductCreate = functions.region('europe-west1').firestore
  .document('businesses/{businessId}/products/{productId}')
  .onCreate(async (snapshot, context) => {
    console.log('Test case');
    await got.get('https://google.com');
  });

(Btw. you need got: npm i got)

I get the error:

i  functions: Beginning execution of "onProductCreate"
>  Test case
⚠  Unknown network resource requested!
   - URL: "https://google.com/"
⚠  Unknown network resource requested!
   - URL: "https://www.google.com/"
i  functions: Finished "onProductCreate" in ~1s

[larssn]

My normal code also gets these errors:

⚠  Unknown network resource requested!
   - URL: "http://169.254.169.254/computeMetadata/v1/instance"
⚠  Unknown network resource requested!
   - URL: "http://metadata.google.internal./computeMetadata/v1/instance"
>  Error: Could not load the default credentials. Browse to https://cloud.google.com/docs/authentication/getting-started for more information.
>      at GoogleAuth.getApplicationDefaultAsync (/Users/larsstoettrup/workspace/nuvoPoint/tillty-cloud-functions-v2/node_modules/google-auth-library/build/src/auth/googleauth.js:161:19)

[samtstern]

So there's definitely still a bug here, but I want to clarify that "Unknown
network resource requested!" is working as intended. We want to warn you
when your emulated code talks to anything in the outside world. For
instance if you're emulating Firestore but still sending real requests to
your payment service or email server that could be a problem!

But I think iwe need to change the log message to make that message
clearer.

On Wed, Oct 9, 2019, 9:00 AM Lars Støttrup Nielsen [e-mail]
wrote:

My normal code also gets these errors:

⚠ Unknown network resource requested!

• URL: "http://169.254.169.254/computeMetadata/v1/instance"

⚠ Unknown network resource requested!

• URL: "http://metadata.google.internal./computeMetadata/v1/instance"

Error: Could not load the default credentials. Browse to https://cloud.google.com/docs/authentication/getting-started for more information.

 at GoogleAuth.getApplicationDefaultAsync (/Users/larsstoettrup/workspace/nuvoPoint/tillty-cloud-functions-v2/node_modules/google-auth-library/build/src/auth/googleauth.js:161:19)

—
You are receiving this because you were assigned.
Reply to this email directly, view it on GitHub
https://github.com/firebase/firebase-tools/issues/1683?email_source=notifications&email_token=ACATB2RNSFS2JHRYE6RV43DQNX5YBA5CNFSM4I33ZHR2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEAYMP4Q#issuecomment-540067826,
or mute the thread
https://github.com/notifications/unsubscribe-auth/ACATB2WC2MK5QUJ3FUOUTGDQNX5YBANCNFSM4I33ZHRQ
.

[larssn]

Thanks for clarifying. I'll dig around a bit, and see if I can find the code that triggers the above.

[larssn]

So I did a few tests, and removing

await snapshot.ref.update({ hello: 'world' });, seems to cause the

>  Error: Could not load the default credentials. Browse to https://cloud.google.com/docs/authentication/getting-started for more information.
>      at GoogleAuth.getApplicationDefaultAsync (/Users/larsstoettrup/workspace/nuvoPoint/tillty-cloud-functions-v2/node_modules/google-auth-library/build/src/auth/googleauth.js:161:19)

error to go away.

(Where snapshot comes from a trigger (update trigger))

[samtstern]

@larssn ah ok thanks! The fact that snapshot.ref doesn't work well is a know issue and I have a fix coming. For now the workaround is admin.firestore().doc(snapshot.ref.path).update({ hello: 'world' })

[larssn]

The two warnings

⚠  Unknown network resource requested!
   - URL: "http://169.254.169.254/computeMetadata/v1/instance"
⚠  Unknown network resource requested!
   - URL: "http://metadata.google.internal./computeMetadata/v1/instance"

seems to come and go.

I'll close this, feel free to reopen if you think those warnings should be resolved first.

[samtstern]

@larssn I am going to keep this open until I figure out why your local functions are trying to access their compute metadata. That's scary to me because it's step 1 of trying to affect production resources, which is bad.

[technoplato]

@samtstern Would more reports of this help resolve the issue? https://i.imgur.com/bqStQ3n.png

[samtstern]

@technoplato we actually have started to figure this out! A few things:

1) Those are warnings, not errors. Sometimes they are serious warnings but they never actually crash your code.
2) Right now the best thing to do is gcloud auth application default login to get a good auth state on your machine.

[samtstern]

I actually am going to close this because all of the auth-fixing work and discussion should happen here:
https://github.com/firebase/firebase-tools/issues/1940

I did a lot of digging last week and I now have a really good sense of the problem. Now to solve it ...