firebase-js-sdk icon indicating copy to clipboard operation
firebase-js-sdk copied to clipboard

`withFunctionTriggersDisabled` from `@firebase/rules-unit-testing` fails with timeout if there is no internet connection

Open sceee opened this issue 1 year ago • 9 comments

Operating System

Windows

Browser Version

Firebase SDK Version

10.8.0

Firebase SDK Product:

Firestore

Describe your project's tooling

Node JS Cloud Functions accessing firestore

Describe the problem

When using the emulator suite and using @firebase/rules-unit-testing to test Firestore rules, as soon as I add the following code in an after hook in the tests and execute the tests while being offline, they fail with a timeout:

...
  let adminDb: Firestore
  let firebaseTestEnvironment: RulesTestEnvironment
  let userDB: firebaseJSCompat.firestore.Firestore

before(async () => {
    adminDb = getFirestore()

    const rulesContent = fs.readFileSync(path.resolve(__dirname, '../../../firestore.rules'), 'utf8')

    firebaseTestEnvironment = await initializeTestEnvironment({
          projectId: TEST_FIREBASE_PROJECT_ID,
          firestore: {
            rules: rulesContent,
          },
        })

    userDB = firebaseTestEnvironment
            .authenticatedContext("123", {
              email: `[email protected]`,
            })
            .firestore()
  })

it('tests something', async () => {
          await assertSucceeds(inexistentUserDB.collection("whatever").doc("abc").get())
})
...

after(async () => {
  await resetData()
})

async function resetData(): Promise<void> {
  await withFunctionTriggersDisabled(async () => {
    // For testing purposes we do nothing here as it doesn't matter
    await Promise.resolve()
  })
}

The error logged is:

"after all" hook for "tests something":
Error: Timeout of 15000ms exceeded. For async tests and hooks, ensure "done()" is called; if returning a Promise, ensure it resolves.

When getting back online without changing any code, everything passes and there is no timeout. The same happens if the withFunctionTriggersDisabled is removed.

The tests are executed using

firebase emulators:exec --import=./test/emulatordata \"npm test\"

npm test is mocha --reporter spec --timeout 15000.

Steps and code to reproduce issue

See above.

sceee avatar Feb 14 '24 15:02 sceee

Hi @sceee,

Can you confirm your Firebase CLI version firebase -v and can you let us know the value you've configured for the environment variable FIREBASE_EMULATOR_HUB?

MarkDuckworth avatar Feb 14 '24 16:02 MarkDuckworth

Hi @MarkDuckworth

I'm on Firebase CLI 13.2.1.

The environment variable values are configured the following way just to be sure - even though I think they should anyway automatically be set by firebase emulators:exec:

process.env.FIREBASE_EMULATOR_HUB = 'localhost:4400'
process.env.FIRESTORE_EMULATOR_HOST = 'localhost:5002'

These match the configured ports in firebase.json (emulators node).

sceee avatar Feb 14 '24 18:02 sceee

A few things to try. First, try using 127.0.0.1:4400 instead of localhost:4400.

Second, check the output from the firebase emulators ... command. I see these logs during the call to withFunctionTriggersDisabled(...). Are you seeing similar logs?

emulators: Disabling Cloud Functions triggers, non-HTTP functions will not execute. emulators: Enabling Cloud Functions triggers, non-HTTP functions will execute.

MarkDuckworth avatar Feb 15 '24 00:02 MarkDuckworth

Hi @MarkDuckworth yeah, I already tried using 127.0.0.1:4400 instead of localhost:4400 but that did not make any difference.

I can also confirm I see these logs:

i  emulators: Disabling Cloud Functions triggers, non-HTTP functions will not execute.
i  emulators: Enabling Cloud Functions triggers, non-HTTP functions will execute.

So I debugged further into the code of rules-unit-testing. Here the background triggers are disabled by a PUT to http://localhost:4400/functions/disableBackgroundTriggers and here they are enabled again using a PUT to http://localhost:4400/functions/enableBackgroundTriggers.

So I tried the following:

  1. Turn your device into flight mode / make it offline
  2. Start emulators using firebase emulators:start
  3. Make a PUT to http://localhost:4400/functions/disableBackgroundTriggers to disable the triggers -> is immediately successful
  4. Make a PUT to http://localhost:4400/functions/enableBackgroundTriggers -> the request hangs forever (until after a long time, a timeout occurs)

So I think there is some code in the emulator that hangs when http://localhost:4400/functions/enableBackgroundTriggers is called while being offline - and this causes the withFunctionTriggersDisabled to hang.

Of course, when using this in my tests, they abort the operation after 15s because that's their timeout.

But as written, I tried it completely without tests (and without using rules-unit-testing at all) just with the emulators and a PUT request to the mentioned Urls and could reproduce it. => So it seems the issue lies in the emulator.

Hope this helps you to reproduce it.

sceee avatar Feb 16 '24 09:02 sceee

I'm re-labling this for the functions team to investigate. However, I did attempt to reproduce and I could not reproduce it.

Is it possible that your function implementation is attempting to make a network request when the function definition is re-loading, causing the timeout?

MarkDuckworth avatar Feb 16 '24 15:02 MarkDuckworth

@MarkDuckworth well, after more tests, it seems it probably works as intended, but the call to http://localhost:4400/functions/enableBackgroundTriggers is just taking long (longer than my test timeout) causing timeouts when being offline.

It seems it causes all functions to be reloaded and - probably depending on the number of functions - it takes longer when being offline compared to being online (~ 1/3 or 1/4 of the time when being online compared to being offline).

Interestingly, the call to http://localhost:4400/functions/disableBackgroundTriggers only takes a few ms.

So probably, it's basically working as intended and maybe it has to do something with parameters or secrets being used in the functions - and these function definitions try to reach the secrets endpoint before using the secrets from .secrets.local which then causes the longer execution time when being offline as it waits until a timeout occurs. It's just an assumption.

sceee avatar Feb 16 '24 15:02 sceee

Interesting. I'm also observing the function loading faster when online. Glad you have a fix for the tests. I'll leave this open for the functions team to review and confirm if it is working as expected.

MarkDuckworth avatar Feb 16 '24 15:02 MarkDuckworth

I am experiencing the same phenomenon using mocha and a beforeEach hook in which I populate my test firestore running on the emulator. Using firebase CLI 13.6.0. Tried calling PUT http://localhost:4400/functions/disableBackgroundTriggers with Postman: returns after more than 10 ms. Tried calling PUT http://localhost:4400/functions/enableBackgroundTriggers with Postman: returns after more than 5 seconds. Worked around with invoking mocha --timeout 10000 but this slows down by tests to un unbearable duration.

fred-klein avatar Apr 01 '24 21:04 fred-klein

Just noticed that PUT http://localhost:4400/functions/enableBackgroundTriggers behaves just like updating the source of my functions. It seems to reload the whole set of functions. Here is the console output:

i  emulators: Enabling Cloud Functions triggers, non-HTTP functions will execute.

and the common part after updating my functions while the emulator is running

✔  functions: Using node@20 from host.
Serving at port 8769
✔  functions: Loaded functions definitions from source: abcMyFunction, xyzAnotherFunction.

fred-klein avatar Apr 01 '24 21:04 fred-klein