Firestore emulator hangs after clearFirestoreData or DELETE

[stari4ek]

[REQUIRED] Environment info

firebase-tools:

7.13.0

Platform:

$ uname -a
Linux 7u 5.4.5-050405-generic #201912181630 SMP Wed Dec 18 16:33:40 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

[REQUIRED] Test case

[REQUIRED] Steps to reproduce

Firestore emulator become unresponsive after clearing it's DB using:

• clearFirestoreData from @firebase/testing
• HTTP DELETE to http://localhost:8080/emulator/v1/projects/<PROJECT-ID>/databases/(default)/documents (as described: https://firebase.google.com/docs/emulator-suite/connect_and_prototype#clear_your_database_between_tests)

For example as part of mocha's afterEach. If It's enabled - I'm always getting timeout for 2nd test in a suit. If I skip DB clear - no timeouts.

Tests perform querying and setting/updating documents wrapped in transaction.

[REQUIRED] Expected behavior

Firestore emulator should process DB requests after clearing it up properly.

[REQUIRED] Actual behavior

Emulator started with --debug logs next errors:

✔  firestore: Emulator started at http://localhost:8080
i  firestore: For testing set FIRESTORE_EMULATOR_HOST=localhost:8080
✔  All emulators started, it is now safe to connect.
[2020-02-14T11:03:57.200Z] Feb 14, 2020 2:03:57 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead
INFO: Detected HTTP/2 connection.

[2020-02-14T11:03:57.754Z] Feb 14, 2020 2:03:57 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead
INFO: Detected HTTP/2 connection.

[2020-02-14T11:03:57.775Z] Feb 14, 2020 2:03:57 PM com.google.cloud.datastore.emulator.impl.util.WrappedStreamObserver onError
INFO: operation failed: the stored version (1581678237759003) does not match the required base version (0)

[2020-02-14T11:03:58.556Z] Feb 14, 2020 2:03:58 PM com.google.cloud.datastore.emulator.impl.util.WrappedStreamObserver onError
INFO: operation failed: the stored version (1581678237759003) does not match the required base version (0)

[2020-02-14T11:04:00.074Z] Feb 14, 2020 2:04:00 PM com.google.cloud.datastore.emulator.impl.util.WrappedStreamObserver onError
INFO: operation failed: the stored version (1581678237759003) does not match the required base version (0)

[2020-02-14T11:04:03.312Z] Feb 14, 2020 2:04:03 PM com.google.cloud.datastore.emulator.impl.util.WrappedStreamObserver onError
INFO: operation failed: the stored version (1581678237759003) does not match the required base version (0)

[2020-02-14T11:04:05.759Z] Feb 14, 2020 2:04:05 PM com.google.cloud.datastore.emulator.impl.util.WrappedStreamObserver onError
INFO: operation failed: the stored version (1581678237759003) does not match the required base version (0)

[2020-02-14T11:04:11.732Z] Feb 14, 2020 2:04:11 PM com.google.cloud.datastore.emulator.impl.util.WrappedStreamObserver onError
INFO: operation failed: the stored version (1581678237759003) does not match the required base version (0)

[2020-02-14T11:04:11.867Z] Feb 14, 2020 2:04:11 PM io.gapi.emulators.netty.HttpVersionRoutingHandler channelRead
INFO: Detected HTTP/2 connection.

All attempts to perform requests to firestore after it produce same errors in emulator's log and timeout on the client side:

Error: Timeout of 10000ms exceeded. For async tests and hooks, ensure "done()" is called; if returning a Promise, ensure it resolves. (/home/astar/dev/tvirl/develop/fb/functions/test/spec/app/iid/manager.spec.ts)
    at listOnTimeout (internal/timers.js:531:17)
    at processTimers (internal/timers.js:475:7)

Sometime there is error in the client log:

FirebaseError: 9 FAILED_PRECONDITION: the stored version (1581678549229005) does not match the required base version (0)
    at new FirestoreError (node_modules/@firebase/firestore/src/util/error.ts:166:5)
    at /home/astar/dev/tvirl/develop/fb/functions/node_modules/@firebase/firestore/src/platform_node/grpc_connection.ts:127:15
    at Object.onReceiveStatus (node_modules/grpc/src/client_interceptors.js:1210:9)
    at InterceptingListener._callNext (node_modules/grpc/src/client_interceptors.js:568:42)
    at InterceptingListener.onReceiveStatus (node_modules/grpc/src/client_interceptors.js:618:8)
    at callback (node_modules/grpc/src/client_interceptors.js:847:24)

[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]

@stari4ek thanks for the detailed report! Hoping @yuchenshi can dig into this one.

[stari4ek]

ditching @firebase/testing and using firebase-admin with process.env.FIRESTORE_EMULATOR_HOST solves the problem.

Problemmatic:

import * as firebase from '@firebase/testing';
const firebaseApp = firebase.initializeAdminApp({ projectId: TEST_PROJECT_ID });

Works well:

import admin = require('firebase-admin');
const firebaseApp = admin.initializeApp({
    projectId: TEST_PROJECT_ID
});

export function cleanupFirestore(projectId: string): Promise<void> {
    const u: URL = new URL(
        `/emulator/v1/projects/${projectId}/databases/(default)/documents`,
        EMULATOR_HOST);

    return axios
        .delete(u.toString());
}

To workaround emulator + @firebase/testing issue unique projectId for each test can be used to isolate data between tests

[samtstern]

@stari4ek thanks for the update! Good to know although it means there's definitely still a bug somewhere.

[yuchenshi]

@stari4ek Could you please do us a favor and create a minimal reproduction (e.g. GitHub repo / complete test script)? It sounds like @firebase/testing is correlated to the issue and having the exact test case that fails after clearing data helps a lot here to get me started on troubleshooting.

[stari4ek]

According to comments on firebase/firebase-js-sdk#2633 @firebase/testing is client-side sdk. And it's incorrect to use it for backend (firebase-admin) unit tests.

Using firebase-admin (admin.initializeApp) + process.env.FIRESTORE_EMULATOR_HOST is the right approach to work with firestore emulator for unit tests.

Sorry, I'm a bit limited with time to work on repro project. But repro would have:

• controller under test which uses firebase-admin to set/update/get/query on firestore.
• mocha test which initializeAdminApp (@firebase/testing) for whole suit or before each test
• clearFirestoreData (@firebase/testing) called after each test

[yuchenshi]

If I read this correctly, it seems that your test also involve preconditions (e.g. asserting that the document doesn't exist yet). It totally looks like the client SDK keeps retrying on precondition failures and thus the timeout. I definitely agree that using a server SDK is the ultimate solution here, but we may be able to do better for surfacing the error.

[stari4ek]

it seems that your test also involve preconditions (e.g. asserting that the document doesn't exist yet)

nope. test itself does not asserts if document exists. functionality under test take care about both cases. But those get/update/create are wrapped to transaction, so transaction retries mechanic may take a place. Those FirebaseError: 9 FAILED_PRECONDITION: the stored version (1581678549229005) does not match the required base version (0) is firebase internal validation.

[seanburlington]

Is there any update on this issue ?

I have the same problem

firebase --version 8.17.0 "firebase": "^8.1.1"

Steps to reproduce

1. Start emulator - no data
2. Add data via react code using document.set
3. Delete document via emulator UI
4. Add data again using the same document.set call

Expected result : document is recreated

Actual result

[2020-12-04T14:40:10.815Z] @firebase/firestore: Firestore (8.1.1): RestConnection Commit failed with error: {"code":"failed-precondition","name":"FirebaseError"} url: http://localhost:8080/v1/projects/rockburn-booking/databases/(default)/documents:commit request: {"writes":[{"update":{"name":"projects/rockburn-booking/databases/(default)/documents/bookings/2020-12-04","fields":{"week":{"stringValue":"49"},"year":{"integerValue":"2020"},"month":{"integerValue":"12"},"date":{"timestampValue":"2020-12-04T00:00:00.000000000Z"},"hours":{"arrayValue":{"values":[{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"},{"integerValue":"0"}]}}}},"currentDocument":{"updateTime":"1970-01-01T00:00:00.000000000Z"}}]}

FirebaseError: the stored version (1607092795883434) does not match the required base version (0)

I can workaround by creating a different document every time

[yuchenshi]

@seanburlington We'd need some repro (including the code that perform the transaction) in order to further look into this. Would you mind sharing what you're doing in the React app in the form of a snippet (or better yet, GitHub repo)?

[gbhall]

I just spent an inordinate amount of time thinking I wasn't understanding transactions properly.

Had this same issue using the Swift SDK and emulator. No longer using the emulator and it runs as expected.

Same issue when clearing data within Firestore in the emulator and getting the error does not match the required base version

[gbhall]

@yuchenshi do you still need an example?

[yuchenshi]

@gbhall Yes, we'd appreciate a repro to pinpoint the issue

[tmazeika]

I'm encountering a similar issue here (outside of @firebase/testing). Here's a minimum complete verifiable example, @yuchenshi: https://github.com/tmazeika/1971mcve. Cheers.

[Edudjr]

Same here using the latest Swift SDK (9.2.0).

[yuchenshi]

Hi all, we've been working on a fix on the JS SDK, which should cover the testing SDKs as well. However, @Edudjr if you're experiencing an issue on the Swift SDK, please file a separate issue on the Swift SDK repo.

[yuchenshi]

Duplicate of https://github.com/firebase/firebase-js-sdk/issues/5871