Skip to content

FAILED_PRECONDITION error when committing transaction to clean Firestore Emulator #5871

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

Closed
ikappaki opened this issue Jan 7, 2022 · 16 comments · Fixed by #6550
Closed

FAILED_PRECONDITION error when committing transaction to clean Firestore Emulator #5871

ikappaki opened this issue Jan 7, 2022 · 16 comments · Fixed by #6550
Assignees

Comments

@ikappaki
Copy link

ikappaki commented Jan 7, 2022

[REQUIRED] Describe your environment

  • Operating System version: Windows 10
  • Browser version: Microsoft Edge 94, Firefox 95
  • Firebase SDK version: 9.6.1
  • Firebase Product: firestore

[REQUIRED] Describe the problem

I'm getting a FAILED_PRECONDITION error when submitting a simple transaction with runTransaction to the Firestone Emulator which has no data. Error message is similar to #3977.

the stored version (1641498227413898) does not match the required base version (0)

I'm calling firebase from ClojureScript via the firebase npm package.

Logs

produced with firebase.firestore.setLogLevel('debug').

[2022-01-07T21:24:52.832Z]  @firebase/firestore: Firestore (9.6.1): FirebaseAuthCredentialsProvider Auth detected
index.cjs.js:90 [2022-01-07T21:24:52.834Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Received user= null
index.cjs.js:90 [2022-01-07T21:24:52.834Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Using default OnlineComponentProvider
index.cjs.js:90 [2022-01-07T21:24:52.835Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Using default OfflineComponentProvider
index.cjs.js:90 [2022-01-07T21:24:52.835Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Initializing OfflineComponentProvider
index.cjs.js:90 [2022-01-07T21:24:52.836Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Initializing OnlineComponentProvider
index.cjs.js:90 [2022-01-07T21:24:52.838Z]  @firebase/firestore: Firestore (9.6.1): FirebaseAppCheckTokenProvider AppCheck not yet detected
index.cjs.js:90 [2022-01-07T21:24:52.841Z]  @firebase/firestore: Firestore (9.6.1): RestConnection Sending:  http://localhost:8080/v1/projects/xxx/databases/(default)/documents:batchGet {"documents":["projects/xxx/databases/(default)/documents/:repl-words/browser"]}
index.cjs.js:90 [2022-01-07T21:24:52.849Z]  @firebase/firestore: Firestore (9.6.1): Connection XHR received: [{"missing":"projects/xxx/databases/(default)/documents/:repl-words/browser","readTime":"2022-01-07T21:24:52.845714Z"}]
index.cjs.js:90 [2022-01-07T21:24:52.849Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC "BatchGetDocuments" completed.
index.cjs.js:90 [2022-01-07T21:24:52.849Z]  @firebase/firestore: Firestore (9.6.1): RestConnection Received:  [{"missing":"projects/xxx/databases/(default)/documents/:repl-words/browser","readTime":"2022-01-07T21:24:52.845714Z"}]
index.cjs.js:90 [2022-01-07T21:24:52.852Z]  @firebase/firestore: Firestore (9.6.1): RestConnection Sending:  http://localhost:8080/v1/projects/xxx/databases/(default)/documents:commit {"writes":[{"update":{"name":"projects/xxx/databases/(default)/documents/:repl-words/browser","fields":{"any":{"integerValue":"1"}}},"currentDocument":{"updateTime":"1970-01-01T00:00:00.000000000Z"}}]}
index.cjs.js:90 [2022-01-07T21:24:52.861Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC "Commit" failed with status: 400 response text: {"error":{"code":400,"message":"the stored version (1641498227413898) does not match the required base version (0)","status":"FAILED_PRECONDITION"}}
index.cjs.js:90 [2022-01-07T21:24:52.862Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC "Commit" completed.
index.cjs.js:90 [2022-01-07T21:24:52.862Z]  @firebase/firestore: Firestore (9.6.1): RestConnection Commit failed with error:  {"code":"failed-precondition","name":"FirebaseError"} url:  http://localhost:8080/v1/projects/xxx/databases/(default)/documents:commit request: {"writes":[{"update":{"name":"projects/xxx/databases/(default)/documents/:repl-words/browser","fields":{"any":{"integerValue":"1"}}},"currentDocument":{"updateTime":"1970-01-01T00:00:00.000000000Z"}}]}

Thanks

@dconeybe
Copy link
Contributor

dconeybe commented Jan 8, 2022

@ikappaki I wasn't able to reproduce the error message that you mentioned. I got this expected error instead:

FirestoreError [FirebaseError]: Can't update a document that doesn't exist.

Here is the code that I used to reproduce:

import { initializeApp } from "firebase/app";
import { connectFirestoreEmulator, collection, doc, getFirestore, runTransaction } from "firebase/firestore";

const firebaseConfig = {
  // insert config data here
};
const app = initializeApp(firebaseConfig);
const firestore = getFirestore();
connectFirestoreEmulator(firestore, 'localhost', 8080);

const docRef = doc(collection(firestore, 'foo'));

runTransaction(firestore, (transaction): Promise<any> => {
  return transaction.get(docRef)
    .then((snapshot) => {
      transaction.update(docRef, {'foo': 42});
    });
});

(this code is published at https://github.com/dconeybe/FirestoreEmulatorTransactionFailedPreconditionIssue5871)

Could you provide the full code snippet that you used to reproduce? Do you notice anything different in your code than mine? I'd like to reproduce for myself to facilitate debugging.

Here is the full log:

[2022-01-08T03:46:14.658Z]  @firebase/firestore: Firestore (9.6.1): FirebaseAuthCredentialsProvider Auth not yet detected
[2022-01-08T03:46:14.660Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Using default OnlineComponentProvider
[2022-01-08T03:46:14.660Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Using default OfflineComponentProvider
[2022-01-08T03:46:14.661Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Initializing OfflineComponentProvider
[2022-01-08T03:46:14.662Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Initializing OnlineComponentProvider
[2022-01-08T03:46:14.742Z]  @firebase/firestore: Firestore (9.6.1): FirebaseAppCheckTokenProvider AppCheck not yet detected
[2022-01-08T03:46:14.745Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC 'BatchGetDocuments' invoked (streaming) with request: {
  documents: [
    'projects/REDACTED/databases/(default)/documents/foo/5GGlNzbp5GBk7WmNtDq2'
  ]
}
[2022-01-08T03:46:14.745Z]  @firebase/firestore: Firestore (9.6.1): Connection Creating Firestore stub.
[2022-01-08T03:46:14.793Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC BatchGetDocuments received result: {
  transaction: <Buffer >,
  readTime: { seconds: '1641613574', nanos: 781838000 },
  missing: 'projects/REDACTED/databases/(default)/documents/foo/5GGlNzbp5GBk7WmNtDq2'
}
[2022-01-08T03:46:14.795Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC 'BatchGetDocuments' completed.
node_modules/@firebase/firestore/src/core/transaction.ts:176
        throw new FirestoreError(
              ^
FirestoreError [FirebaseError]: Can't update a document that doesn't exist.
    at Transaction$2.preconditionForUpdate (node_modules/@firebase/firestore/src/core/transaction.ts:176:15)
    at Transaction$2.update (node_modules/@firebase/firestore/src/core/transaction.ts:84:44)
    at Transaction.update (node_modules/@firebase/firestore/src/lite-api/transaction.ts:229:23)
    at index.ts:37:19
    at processTicksAndRejections (node:internal/process/task_queues:96:5) {
  code: 'invalid-argument',
  toString: [Function (anonymous)]
}

@ikappaki
Copy link
Author

ikappaki commented Jan 8, 2022

Hi @dconeybe,

Thanks for looking into this. I am using the Web API in from a browser in ClojureScript to invoke the transaction, thus the calls to the emulators seem to me that are performed via REST not RPC (I'm inferring this from the logs).

It will take me some time to figure out how to extract the minimal possible reproducible JS code from the ClojureScript compiler output.

Would you be able to perhaps provide me with a minimal setup similar to https://github.com/dconeybe/FirestoreEmulatorTransactionFailedPreconditionIssue5871 but using Web API REST calls that can be invoked from a browser instead of utilising RPC? Not sure where to start if I go down this path by myself, perhaps I should look into the firestore quickstart-js for inspiration.

If I modify your example to match my code it looks like the below and it does work fine when invoked from node.js:

import { initializeApp } from "firebase/app";
import { connectFirestoreEmulator, collection, doc, getFirestore, runTransaction, setLogLevel } from "firebase/firestore";

const firebaseConfig = {
// config
};

const app = initializeApp(firebaseConfig);
setLogLevel('debug');
const firestore = getFirestore();
connectFirestoreEmulator(firestore, 'localhost', 8080);

const docRef = doc(firestore, 'repl-words', 'foo');

runTransaction(firestore, (transaction): Promise<any> => {
  return transaction.get(docRef)
    .then((snapshot) => {

      transaction.set(docRef, {'foo': 42});
    });
});

log

$ npx ts-node index.ts
npx: installed 14 in 2.121s
[2022-01-08T10:05:20.363Z]  @firebase/firestore: Firestore (9.6.1): FirebaseAuthCredentialsProvider Auth not yet detected
[2022-01-08T10:05:20.363Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Using default OnlineComponentProvider
[2022-01-08T10:05:20.363Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Using default OfflineComponentProvider
[2022-01-08T10:05:20.363Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Initializing OfflineComponentProvider
[2022-01-08T10:05:20.364Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Initializing OnlineComponentProvider
[2022-01-08T10:05:20.442Z]  @firebase/firestore: Firestore (9.6.1): FirebaseAppCheckTokenProvider AppCheck not yet detected
[2022-01-08T10:05:20.445Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC 'BatchGetDocuments' invoked (streaming) with request: {
  documents: [
    'projects/xxx/databases/(default)/documents/repl-words/foo'
  ]
}
[2022-01-08T10:05:20.445Z]  @firebase/firestore: Firestore (9.6.1): Connection Creating Firestore stub.
[2022-01-08T10:05:20.479Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC BatchGetDocuments received result: {
  transaction: <Buffer >,
  readTime: { seconds: '1641636320', nanos: 473860000 },
  missing: 'projects/xxx/databases/(default)/documents/repl-words/foo'
}
[2022-01-08T10:05:20.480Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC 'BatchGetDocuments' completed.
[2022-01-08T10:05:20.482Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC 'Commit' invoked with request: {
  writes: [
    {
      update: {
        name: 'projects/xxx/databases/(default)/documents/repl-words/foo',
        fields: { foo: { integerValue: '42' } }
      },
      currentDocument: { updateTime: { seconds: '0', nanos: 0 } }
    }
  ]
}
[2022-01-08T10:05:20.491Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC 'Commit' completed with response: {
  writeResults: [
    {
      transformResults: [],
      updateTime: { seconds: '1641636320', nanos: 488859000 }
    }
  ],
  commitTime: { seconds: '1641636320', nanos: 488859000 }
}

Thanks!

@ikappaki
Copy link
Author

ikappaki commented Jan 8, 2022

Good news, I've managed to reproduce it with your example, it is the mere presence of firebase/auth that is causing the issue

import { initializeApp } from "firebase/app";
import "firebase/auth";
import { connectFirestoreEmulator, collection, doc, getFirestore, runTransaction, setLogLevel } from "firebase/firestore";

const firebaseConfig = {
// ...
};

const app = initializeApp(firebaseConfig);
setLogLevel('debug');
const firestore = getFirestore();
connectFirestoreEmulator(firestore, 'localhost', 8080);

const docRef = doc(firestore, 'repl-words', 'foo');

runTransaction(firestore, (transaction): Promise<any> => {
  return transaction.get(docRef)
    .then((snapshot) => {

      transaction.set(docRef, {'foo': 42});
    });
});

log

$ npx ts-node index.ts
npx: installed 14 in 1.463s
[2022-01-08T11:57:22.261Z]  @firebase/firestore: Firestore (9.6.1): FirebaseAuthCredentialsProvider Auth not yet detected
[2022-01-08T11:57:22.261Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Using default OnlineComponentProvider
[2022-01-08T11:57:22.261Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Using default OfflineComponentProvider
[2022-01-08T11:57:22.262Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Initializing OfflineComponentProvider
[2022-01-08T11:57:22.264Z]  @firebase/firestore: Firestore (9.6.1): FirestoreClient Initializing OnlineComponentProvider
[2022-01-08T11:57:22.332Z]  @firebase/firestore: Firestore (9.6.1): FirebaseAppCheckTokenProvider AppCheck not yet detected
[2022-01-08T11:57:22.348Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC 'BatchGetDocuments' invoked (streaming) with request: {
  documents: [
    'projects/xxx/databases/(default)/documents/repl-words/foo'
  ]
}
[2022-01-08T11:57:22.348Z]  @firebase/firestore: Firestore (9.6.1): Connection Creating Firestore stub.
[2022-01-08T11:57:22.371Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC BatchGetDocuments received result: {
  transaction: <Buffer >,
  readTime: { seconds: '1641643042', nanos: 365638000 },
  missing: 'projects/xxx/databases/(default)/documents/repl-words/foo'
}
[2022-01-08T11:57:22.372Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC 'BatchGetDocuments' completed.
[2022-01-08T11:57:22.374Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC 'Commit' invoked with request: {
  writes: [
    {
      update: {
        name: 'projects/xxx/databases/(default)/documents/repl-words/foo',
        fields: { foo: { integerValue: '42' } }
      },
      currentDocument: { updateTime: { seconds: '0', nanos: 0 } }
    }
  ]
}
[2022-01-08T11:57:22.397Z]  @firebase/firestore: Firestore (9.6.1): Connection RPC 'Commit' failed with error: Error: 9 FAILED_PRECONDITION: the stored version (1641636454958701) does not match the required base version (0)
    at Object.callErrorFromStatus (d:\clj\issues\FirestoreEmulatorTransactionFailedPreconditionIssue5871\node_modules\@grpc\grpc-js\src\call.ts:81:24)
    at Object.onReceiveStatus (d:\clj\issues\FirestoreEmulatorTransactionFailedPreconditionIssue5871\node_modules\@grpc\grpc-js\src\client.ts:343:36)
    at Object.onReceiveStatus (d:\clj\issues\FirestoreEmulatorTransactionFailedPreconditionIssue5871\node_modules\@grpc\grpc-js\src\client-interceptors.ts:462:34)
    at Object.onReceiveStatus (d:\clj\issues\FirestoreEmulatorTransactionFailedPreconditionIssue5871\node_modules\@grpc\grpc-js\src\client-interceptors.ts:424:48)
    at d:\clj\issues\FirestoreEmulatorTransactionFailedPreconditionIssue5871\node_modules\@grpc\grpc-js\src\call-stream.ts:323:24
    at processTicksAndRejections (internal/process/task_queues.js:79:11) {
  code: 9,
  details: 'the stored version (1641636454958701) does not match the required base version (0)',
  metadata: Metadata {
    internalRepr: Map { 'content-type' => [ 'application/grpc' ] },
    options: {}
  }
}

thanks

@dconeybe
Copy link
Contributor

@ikappaki I still cannot reproduce the "the stored version (1641636454958701) does not match the required base version (0)" error, even when I add the import for firebase/auth.

What sort of authentication do you have set up in the Firestore emulator? What security rules have you configured?

@ikappaki
Copy link
Author

Hi @dconeybe, indeed it does not occur the first time the db is brought up, the db has to be cleared first.

could you please try the following

  1. bring up the emulators.
  2. run the code snippet I posted last, some data will be created in the emulated firestore.
  3. hit the clear all data button in the firestore emulator to clear the store.
  4. rerun the snippet, it should error out.

I don't have any authentication or security rules setup. It is as plain as it can get.

Thanks

@dconeybe
Copy link
Contributor

Ahh okay NOW I can reproduce. Let me dig into this a bit.

@dconeybe dconeybe added the bug label Jan 10, 2022
@dconeybe
Copy link
Contributor

I'm assigning this to @yuchenshi who has expertise in the Firestore emulator.

Here are the results of my investigation:

Here is the problematic code (hereafter referred to as index.ts):

import { initializeApp } from "firebase/app";
import { connectFirestoreEmulator, collection, doc, getFirestore, runTransaction, setLogLevel } from "firebase/firestore";

const firebaseConfig = {
  // INSERT CONFIG HERE
};

const app = initializeApp(firebaseConfig);
setLogLevel('debug');
const firestore = getFirestore();
connectFirestoreEmulator(firestore, 'localhost', 8080);

const docRef = doc(firestore, 'repl-words', 'foo');

runTransaction(firestore, (transaction): Promise<any> => {
  return transaction.get(docRef)
    .then((snapshot) => {
      transaction.set(docRef, {'foo': 42});
    });
});

Prerequisites

  1. npm install -g typescript ts-node

Steps

  1. firebase emulators:start --only firestore --project YOUR_FIREBASE_PROJECT_ID
  2. ts-node index.ts
  3. CLick "Clear all data" in the Firestore Emulator Web UI (e.g. http://localhost:4000/firestore/data/).
  4. ts-node index.ts again

Expected Results

Both times that the index.ts script is run complete successfully.

Actual Results:

The first time that the index.ts script is run completes successfully (as expected);
however, the second time that it is run fails with this error:

@firebase/firestore: Firestore (9.6.1): Connection RPC 'Commit' failed with error: Error: 9 FAILED_PRECONDITION: the stored version (1641841011407934) does not match the required base version (0)

Minimal app to reproduce: https://github.com/dconeybe/FirestoreEmulatorTransactionFailedPreconditionIssue5871

@dconeybe dconeybe assigned yuchenshi and unassigned dconeybe Jan 10, 2022
@fredzqm
Copy link
Contributor

fredzqm commented Jan 31, 2022

Let me try to explain why this happens.

clearData is nothing more than a commit that deletes all database data.

From the repro steps:

  1. firebase emulators:start --only firestore --project YOUR_FIREBASE_PROJECT_ID
  2. ts-node index.ts
    Some entity is written.
  3. CLick "Clear all data" in the Firestore Emulator Web UI (e.g. http://localhost:4000/firestore/data/).
    All entities is cleared with a non-zero delete timestamp.
  4. ts-node index.ts again
    It tries to update the document with a precondition of currentDocument: { updateTime: { seconds: '0', nanos: 0 } }, but since the document was deleted at a non-zero timestamp the precondition failed.

It would say this is an SDK bug, we should change SDK to use currentDocument: { exists: false} instead of the updateTime. BatchGetDocument don't return the last mutated timestamp, so a precondition of updateTime can be wrong.

I would guess that prod database would behave similarly. (clearData is just deleting all entities)

Can we route this to the admin SDK them?

@yuchenshi
Copy link
Member

@schmidt-sebastian would you mind looking at this?

@schmidt-sebastian
Copy link
Contributor

Assigning to current on-call. We should be sending a precondition of {exists: false}.

@dconeybe dconeybe assigned ehsannas and unassigned dconeybe Feb 2, 2022
@bruxr
Copy link

bruxr commented Apr 29, 2022

Any update for this? The precondition failed is causing my automated tests to error out when using clearFirestore() method before every test. I assume that is the same as the clear all data button.

@dpsthree
Copy link

This same scenario is a problem when using firebase firestore:delete --project {project-name} --all-collections -f

@ikappaki
Copy link
Author

Hi @ehsannas, @dconeybe, @schmidt-sebastian and @yuchenshi.

apologies for the wide distribution, but not sure who is supposed to be looking at this.

It has been more than a year since this issue was reported and it appears there is an easy fix to apply. As mentioned by other users, the bug is still out there at large.

Could someone please apply the suggested fix so as to close this issue?

Thanks

@dconeybe dconeybe assigned dconeybe and unassigned ehsannas Aug 22, 2022
@dconeybe
Copy link
Contributor

I'll get a fix out by the end of the week.

@dconeybe
Copy link
Contributor

The fix has been merged: #6550. It should be included in the next release. I'll reply back here once the release is out.

I'm also going to make sure the fix is ported to Android and iOS, but I have no ETA for those fixes.

@firebase firebase locked and limited conversation to collaborators Sep 26, 2022
@dconeybe
Copy link
Contributor

dconeybe commented Oct 3, 2022

FYI The fix has been released in Firebase JS SDK version 9.9.4 (released Sept 01, 2022): https://firebase.google.com/support/release-notes/js#version_994_-_september_1_2022

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
9 participants