[cloud_firestore] Transactions doesn't seem to work

[larssn]

Issue moved from flutter/flutter#28714

So we're running into some issues with transactions, where update statements run without errors, except they don't always update the document in question. Below are a few simple tests.

Test 1

Setup
Run on two Android devices, and do a countdown to trigger the code at the same time. The code simulates an artificially long transaction execution, by using Future.delayed. One device will use Future.delayed(Duration(seconds: 3)); and the other will use Future.delayed(Duration(seconds: 2));. The default transaction timeout is 5 seconds, so we're well within that.

The write operation is incrementing a counter in a single document.
The document looks like so: { counter: 0 }.

try {
  final docRef = Firestore.instance.document('test/test-document');
  await Firestore.instance.runTransaction((Transaction tx) async {
    print('-- TRANSACTION START --');
    final postSnapshot = await tx.get(docRef);
    final newVal = 1 + postSnapshot['counter'];
    await Future.delayed(Duration(seconds: 3));
    print('Updating counter value ' + newVal.toString());
    await tx.update(postSnapshot.reference, {'counter': newVal});
    print('-- TRANSACTION END --');
  });
} catch (e) {
  print(e);
}

Results
Device 1 with 2 second transaction console output:

I/flutter (30734): -- TRANSACTION START --
I/flutter (30734): Updating counter value 1
I/flutter (30734): -- TRANSACTION END --

Device 2 with 3 second transaction console output:

I/flutter (12311): -- TRANSACTION START --
I/flutter (12311): Updating counter value 1
I/flutter (12311): -- TRANSACTION END --
I/flutter (12311): -- TRANSACTION START --
I/flutter (12311): Updating counter value 2
I/flutter (12311): -- TRANSACTION END --

Expected document value:
{ counter: 2 }
Actual document value:
{ counter: 1 }

Notes for Test 1:
From observing the logs, device 2 seems to do what it should: It restarts its transaction after it receives the updated document from device 1, but the value of 2 never makes it to the database.

Test 2

Setup
Identical to Test 1, except it's only run on a single device, and a timeout is introduced for the transaction, which is shorter than the execution time for the transaction.

try {
  await Firestore.instance.runTransaction((Transaction tx) async {
    // ... Identical to before
  }, timeout: Duration(seconds: 1)); // <-- HERE
} catch (e) {
  print(e);
}

Results
Actual console output:

I/flutter ( 1247): -- TRANSACTION START --
I/flutter ( 1247): PlatformException(Error performing transaction, Timed out waiting for Task, null)
I/flutter ( 1247): -- TRANSACTION START --
I/flutter ( 1247): Updating counter value 1
I/flutter ( 1247): -- TRANSACTION END --
I/flutter ( 1247): Updating counter value 1
I/flutter ( 1247): -- TRANSACTION END --

Expected console output:

I/flutter ( 1247): -- TRANSACTION START --
I/flutter ( 1247): PlatformException(Error performing transaction, Timed out waiting for Task, null)

Notes for Test 2:
I'm not expecting it to retry the transaction at all, since the catch handler has already output the error, meaning the transaction is done.

That's all for now. If we dream up some more tests that also cause unexpected results, we'll update this post.

[collinjackson]

Thanks for filing this issue. Do you have any suggestions for how to fix it? Do you think this is a bug in the Firestore Android SDK, or in Flutterfire? Can we write an integration test that runs on a single device, or is it necessary to have two devices to trigger the issue?

[larssn]

I haven't heard mention of transactions not working in iOS or Android. So I assume it's a problem with the Flutter implementation.

Regarding tests: I would imagine an integration test on a single device would show the issue. We tested on two physical devices, back in March. In general, it would be a good idea to redo the above tests in their entirety.

I've been strapped for time, so I haven't dug into the code to try and figure out whats happening.

[larssn]

So I retested this. Now it hard crashes the app on the 3 second device:

E/AndroidRuntime(18365): FATAL EXCEPTION: AsyncTask #13
E/AndroidRuntime(18365): Process: com.nuvopoint.tillty, PID: 18365
E/AndroidRuntime(18365): java.lang.RuntimeException: An error occurred while executing doInBackground()
E/AndroidRuntime(18365): 	at android.os.AsyncTask$3.done(AsyncTask.java:353)
E/AndroidRuntime(18365): 	at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:383)
E/AndroidRuntime(18365): 	at java.util.concurrent.FutureTask.setException(FutureTask.java:252)
E/AndroidRuntime(18365): 	at java.util.concurrent.FutureTask.run(FutureTask.java:271)
E/AndroidRuntime(18365): 	at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:245)
E/AndroidRuntime(18365): 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
E/AndroidRuntime(18365): 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
E/AndroidRuntime(18365): 	at java.lang.Thread.run(Thread.java:764)
E/AndroidRuntime(18365): Caused by: java.lang.AssertionError: INTERNAL ASSERTION FAILED: A transaction object cannot be used after its update callback has been invoked.
E/AndroidRuntime(18365): 	at com.google.firebase.firestore.util.Assert.fail(com.google.firebase:firebase-firestore@@21.3.0:46)
E/AndroidRuntime(18365): 	at com.google.firebase.firestore.util.Assert.hardAssert(com.google.firebase:firebase-firestore@@21.3.0:31)
E/AndroidRuntime(18365): 	at com.google.firebase.firestore.core.Transaction.ensureCommitNotCalled(com.google.firebase:firebase-firestore@@21.3.0:246)
E/AndroidRuntime(18365): 	at com.google.firebase.firestore.core.Transaction.lookup(com.google.firebase:firebase-firestore@@21.3.0:81)
E/AndroidRuntime(18365): 	at com.google.firebase.firestore.Transaction.getAsync(com.google.firebase:firebase-firestore@@21.3.0:191)
E/AndroidRuntime(18365): 	at com.google.firebase.firestore.Transaction.get(com.google.firebase:firebase-firestore@@21.3.0:228)
E/AndroidRuntime(18365): 	at io.flutter.plugins.firebase.cloudfirestore.CloudFirestorePlugin$5.doInBackground(CloudFirestorePlugin.java:613)
E/AndroidRuntime(18365): 	at io.flutter.plugins.firebase.cloudfirestore.CloudFirestorePlugin$5.doInBackground(CloudFirestorePlugin.java:608)
E/AndroidRuntime(18365): 	at android.os.AsyncTask$2.call(AsyncTask.java:333)
E/AndroidRuntime(18365): 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
E/AndroidRuntime(18365): 	... 4 more

[✓] Flutter (Channel dev, 1.19.0-1.0.pre, on Mac OS X 10.13.6 17G12034, locale en-DK)
    • Flutter version 1.19.0-1.0.pre at /Users/larsstoettrup/workspace/flutter
    • Framework revision 456d80b9dd (5 days ago), 2020-05-11 11:45:03 -0400
    • Engine revision d96f962ca2
    • Dart version 2.9.0 (build 2.9.0-7.0.dev 092ed38a87)

 
[✓] Android toolchain - develop for Android devices (Android SDK version 29.0.2)
    • Android SDK at /Users/larsstoettrup/Library/Android/sdk
    • Platform android-29, build-tools 29.0.2
    • ANDROID_HOME = /Users/larsstoettrup/Library/Android/sdk
    • Java binary at: /Applications/Android Studio.app/Contents/jre/jdk/Contents/Home/bin/java
    • Java version OpenJDK Runtime Environment (build 1.8.0_212-release-1586-b4-5784211)
    • All Android licenses accepted.

[!] Xcode - develop for iOS and macOS
    ✗ Xcode installation is incomplete; a full installation is necessary for iOS development.
      Download at: https://developer.apple.com/xcode/download/
      Or install Xcode via the App Store.
      Once installed, run:
        sudo xcode-select --switch /Applications/Xcode.app/Contents/Developer
        sudo xcodebuild -runFirstLaunch
    • CocoaPods version 1.9.1

[✓] Android Studio (version 3.6)
    • Android Studio at /Applications/Android Studio.app/Contents
    • Flutter plugin version 45.1.1
    • Dart plugin version 192.7761
    • Java version OpenJDK Runtime Environment (build 1.8.0_212-release-1586-b4-5784211)

[✓] VS Code (version 1.45.1)
    • VS Code at /Applications/Visual Studio Code.app/Contents
    • Flutter extension version 3.10.1

[✓] Connected device (1 available)
    • SM T580 • 52037c6b4d72c351 • android-arm • Android 8.1.0 (API 27)

! Doctor found issues in 1 category.

[larssn]

cc @TahaTesser
Is this information enough to reproduce it in your end?

[yizenlim]

having the same hard crash issue , really need this to be working :( any solutions yet ? it only happens when running transaction simultaneously on 2 devices

[Salakar]

Hey all, as part of our on-going work for #2582, this has been resolved in our Firebase Firestore rework (#2913) - which has now been merged into master. We'll look at publishing some prereleases in the next few days. Thank you

[larssn]

I look forward to testing it out