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

Emulator errors with external HTTP calls when GOOGLE_APPLICATION_CREDENTIALS is not set. #1683

Closed
larssn opened this issue Sep 30, 2019 · 18 comments

Comments

@larssn
Copy link

larssn commented Sep 30, 2019

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: firebase/firebase-functions#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 comment has been minimized.

@samtstern
Copy link
Contributor

@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
Copy link
Author

larssn commented Sep 30, 2019

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
Copy link
Contributor

@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
Copy link
Author

larssn commented Oct 3, 2019

No worries 😄

Dont get lost in the desert

@samtstern
Copy link
Contributor

samtstern commented Oct 9, 2019

@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
Copy link
Author

larssn commented Oct 9, 2019

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 (googleapis/nodejs-firestore#661) with grpc-js.

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

@larssn larssn closed this as completed Oct 9, 2019
@larssn
Copy link
Author

larssn commented Oct 9, 2019

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 larssn reopened this Oct 9, 2019
@larssn
Copy link
Author

larssn commented Oct 9, 2019

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
Copy link
Contributor

samtstern commented Oct 9, 2019 via email

@larssn
Copy link
Author

larssn commented Oct 9, 2019

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

@larssn
Copy link
Author

larssn commented Oct 9, 2019

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
Copy link
Contributor

@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
Copy link
Author

larssn commented Oct 10, 2019

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.

@larssn larssn closed this as completed Oct 10, 2019
@samtstern samtstern reopened this Oct 10, 2019
@samtstern
Copy link
Contributor

@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
Copy link

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

@samtstern
Copy link
Contributor

@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
Copy link
Contributor

I actually am going to close this because all of the auth-fixing work and discussion should happen here:
#1940

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

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

No branches or pull requests

4 participants