search

firebase / firebase-ios-sdk

Firebase SDK for Apple App Development
https://firebase.google.com
Apache License 2.0
5.62k stars 1.47k forks source link

Firestore Crash (assertion) if connection is interrupted in between transaction retries at specific point #10719

Open isegal opened 1 year ago

isegal commented 1 year ago

Description

We have been observing this issue in production and it appears similar issues have been reported by others and I have a theory of how to try to reproduce it via unit tests.


Fatal Exception: NSInternalInconsistencyException
0  CoreFoundation                 0xa248 __exceptionPreprocess
1  libobjc.A.dylib                0x17a68 objc_exception_throw
2  Foundation                     0x546958 -[NSMutableDictionary(NSMutableDictionary) initWithContentsOfFile:]
3  Runner                         0xb17c0 firebase::firestore::util::ObjcThrowHandler(firebase::firestore::util::ExceptionType, char const*, char const*, int, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&)
4  Runner                         0xb126c firebase::firestore::util::Throw(firebase::firestore::util::ExceptionType, char const*, char const*, int, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&)
5  Runner                         0x109c88 firebase::firestore::util::internal::FailAssertion(char const*, char const*, int, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, char const*)
6  Runner                         0x109d18 firebase::firestore::util::internal::FailAssertion(char const*, char const*, int, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, char const*)
7  Runner                         0x1b43a8 firebase::firestore::core::Transaction::EnsureCommitNotCalled()
8  Runner                         0x1b4000 firebase::firestore::core::Transaction::Lookup(std::__1::vector<firebase::firestore::model::DocumentKey, std::__1::allocator<firebase::firestore::model::DocumentKey> > const&, std::__1::function<void (firebase::firestore::util::StatusOr<std::__1::vector<firebase::firestore::model::Document, std::__1::allocator<firebase::firestore::model::Document> > > const&)>&&)
9  Runner                         0xf4934 -[FIRTransaction getDocument:completion:]
10 Runner                         0xf4b10 -[FIRTransaction getDocument:error:]
11 Runner                         0x1fa648 __66-[FLTFirebaseFirestorePlugin transactionGet:withMethodCallResult:]_block_invoke + 368 (FLTFirebaseFirestorePlugin.m:368)
12 libdispatch.dylib              0x24b4 _dispatch_call_block_and_release
13 libdispatch.dylib              0x3fdc _dispatch_client_callout
14 libdispatch.dylib              0x70c8 _dispatch_queue_override_invoke
15 libdispatch.dylib              0x15a6c _dispatch_root_queue_drain
16 libdispatch.dylib              0x16284 _dispatch_worker_thread2
17 libsystem_pthread.dylib        0xdbc _pthread_wqthread
18 libsystem_pthread.dylib        0xb98 start_wqthread

Reproducing the issue

We see these reports in production and have not been able to reproduce locally in lab environment, we believe an integration test can be written as follows:

Pre-condition: ensure transaction auto-retries are enabled

  1. Start a transaction
  2. Get document
  3. Write a document
  4. Interrupt the connection BEFORE the transaction commit invokes the result callback

The resulting backtrace suggests the following theory of failure:

The assertion is thrown here:

void Transaction::EnsureCommitNotCalled() {
  HARD_ASSERT(!committed_,
              "A transaction object cannot be used after its "
              "update callback has been invoked.");
}

The assertion checks against comitted_ flag which is set only in only place (Transaction::Commit) but appears to be set prematurely:

void Transaction::Commit(util::StatusCallback&& callback) {
...

  committed_ = true; // <--- Too early!

  std::shared_ptr<Datastore> datastore = datastore_.lock();
  if (!datastore) {
    callback(Status(Error::kErrorFailedPrecondition,
                    "The client has already been terminated."));
    return;
  }

  datastore->CommitMutations(mutations_, std::move(callback));
}

The last line of Transaction::Commit performs the action commit. However, if connection is interrupted between the beginning of the function and the actual transaction write, we end up with _comitted flag set.

At this point the transaction runner will retry. At step 2 in the above test case it will assert because it erroneously considers that the transaction has been committed.

It appears that datastore->CommitMutations() is itself an asynchronous function, so in order to properly set comitted flag, we may have to wrap it within a lambda function instead of moving instead of committed = true; so probably something like this:

    datastore->CommitMutations(mutations_,
                             [callback, this] (util::Status status){
        if(status.ok()) {
            this->committed_ = true;
        }
        callback(status);

For reference, here is the transaction runner:

void TransactionRunner::Run() {
  queue_->VerifyIsCurrentQueue();
  attempts_remaining_ -= 1;

  auto shared_this = this->shared_from_this();
  backoff_.BackoffAndRun([shared_this] {
    std::shared_ptr<Transaction> transaction =
        shared_this->remote_store_->CreateTransaction();
    shared_this->update_callback_(
        transaction, [transaction, shared_this](const util::Status& status) {
          shared_this->queue_->Enqueue([transaction, shared_this, status] {
            shared_this->ContinueCommit(transaction, status);
          });
        });
  });
}

I originally discovered and commented on here: https://github.com/firebase/firebase-ios-sdk/commit/58c75667065bb42750bc19be356ec8a71f554306

Firebase SDK Version

10.4.0 and earlier

Xcode Version

14.1

Installation Method

CocoaPods

Firebase Product(s)

Firestore

Targeted Platforms

iOS

Relevant Log Output

No response

If using Swift Package Manager, the project's Package.resolved

Expand Package.resolved snippet
```json Replace this line with the contents of your Package.resolved. ```

If using CocoaPods, the project's Podfile.lock

Expand Podfile.lock snippet
```yml PODS: - abseil/algorithm (1.20211102.0): - abseil/algorithm/algorithm (= 1.20211102.0) - abseil/algorithm/container (= 1.20211102.0) - abseil/algorithm/algorithm (1.20211102.0): - abseil/base/config - abseil/algorithm/container (1.20211102.0): - abseil/algorithm/algorithm - abseil/base/core_headers - abseil/meta/type_traits - abseil/base (1.20211102.0): - abseil/base/atomic_hook (= 1.20211102.0) - abseil/base/base (= 1.20211102.0) - abseil/base/base_internal (= 1.20211102.0) - abseil/base/config (= 1.20211102.0) - abseil/base/core_headers (= 1.20211102.0) - abseil/base/dynamic_annotations (= 1.20211102.0) - abseil/base/endian (= 1.20211102.0) - abseil/base/errno_saver (= 1.20211102.0) - abseil/base/fast_type_id (= 1.20211102.0) - abseil/base/log_severity (= 1.20211102.0) - abseil/base/malloc_internal (= 1.20211102.0) - abseil/base/pretty_function (= 1.20211102.0) - abseil/base/raw_logging_internal (= 1.20211102.0) - abseil/base/spinlock_wait (= 1.20211102.0) - abseil/base/strerror (= 1.20211102.0) - abseil/base/throw_delegate (= 1.20211102.0) - abseil/base/atomic_hook (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/base/base (1.20211102.0): - abseil/base/atomic_hook - abseil/base/base_internal - abseil/base/config - abseil/base/core_headers - abseil/base/dynamic_annotations - abseil/base/log_severity - abseil/base/raw_logging_internal - abseil/base/spinlock_wait - abseil/meta/type_traits - abseil/base/base_internal (1.20211102.0): - abseil/base/config - abseil/meta/type_traits - abseil/base/config (1.20211102.0) - abseil/base/core_headers (1.20211102.0): - abseil/base/config - abseil/base/dynamic_annotations (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/base/endian (1.20211102.0): - abseil/base/base - abseil/base/config - abseil/base/core_headers - abseil/base/errno_saver (1.20211102.0): - abseil/base/config - abseil/base/fast_type_id (1.20211102.0): - abseil/base/config - abseil/base/log_severity (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/base/malloc_internal (1.20211102.0): - abseil/base/base - abseil/base/base_internal - abseil/base/config - abseil/base/core_headers - abseil/base/dynamic_annotations - abseil/base/raw_logging_internal - abseil/base/pretty_function (1.20211102.0) - abseil/base/raw_logging_internal (1.20211102.0): - abseil/base/atomic_hook - abseil/base/config - abseil/base/core_headers - abseil/base/log_severity - abseil/base/spinlock_wait (1.20211102.0): - abseil/base/base_internal - abseil/base/core_headers - abseil/base/errno_saver - abseil/base/strerror (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/base/errno_saver - abseil/base/throw_delegate (1.20211102.0): - abseil/base/config - abseil/base/raw_logging_internal - abseil/container/common (1.20211102.0): - abseil/meta/type_traits - abseil/types/optional - abseil/container/compressed_tuple (1.20211102.0): - abseil/utility/utility - abseil/container/container_memory (1.20211102.0): - abseil/base/config - abseil/memory/memory - abseil/meta/type_traits - abseil/utility/utility - abseil/container/fixed_array (1.20211102.0): - abseil/algorithm/algorithm - abseil/base/config - abseil/base/core_headers - abseil/base/dynamic_annotations - abseil/base/throw_delegate - abseil/container/compressed_tuple - abseil/memory/memory - abseil/container/flat_hash_map (1.20211102.0): - abseil/algorithm/container - abseil/container/container_memory - abseil/container/hash_function_defaults - abseil/container/raw_hash_map - abseil/memory/memory - abseil/container/hash_function_defaults (1.20211102.0): - abseil/base/config - abseil/hash/hash - abseil/strings/cord - abseil/strings/strings - abseil/container/hash_policy_traits (1.20211102.0): - abseil/meta/type_traits - abseil/container/hashtable_debug_hooks (1.20211102.0): - abseil/base/config - abseil/container/hashtablez_sampler (1.20211102.0): - abseil/base/base - abseil/base/core_headers - abseil/container/have_sse - abseil/debugging/stacktrace - abseil/memory/memory - abseil/profiling/exponential_biased - abseil/profiling/sample_recorder - abseil/synchronization/synchronization - abseil/utility/utility - abseil/container/have_sse (1.20211102.0) - abseil/container/inlined_vector (1.20211102.0): - abseil/algorithm/algorithm - abseil/base/core_headers - abseil/base/throw_delegate - abseil/container/inlined_vector_internal - abseil/memory/memory - abseil/container/inlined_vector_internal (1.20211102.0): - abseil/base/core_headers - abseil/container/compressed_tuple - abseil/memory/memory - abseil/meta/type_traits - abseil/types/span - abseil/container/layout (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/meta/type_traits - abseil/strings/strings - abseil/types/span - abseil/utility/utility - abseil/container/raw_hash_map (1.20211102.0): - abseil/base/throw_delegate - abseil/container/container_memory - abseil/container/raw_hash_set - abseil/container/raw_hash_set (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/base/endian - abseil/container/common - abseil/container/compressed_tuple - abseil/container/container_memory - abseil/container/hash_policy_traits - abseil/container/hashtable_debug_hooks - abseil/container/hashtablez_sampler - abseil/container/have_sse - abseil/memory/memory - abseil/meta/type_traits - abseil/numeric/bits - abseil/utility/utility - abseil/debugging/debugging_internal (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/base/dynamic_annotations - abseil/base/errno_saver - abseil/base/raw_logging_internal - abseil/debugging/demangle_internal (1.20211102.0): - abseil/base/base - abseil/base/config - abseil/base/core_headers - abseil/debugging/stacktrace (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/debugging/debugging_internal - abseil/debugging/symbolize (1.20211102.0): - abseil/base/base - abseil/base/config - abseil/base/core_headers - abseil/base/dynamic_annotations - abseil/base/malloc_internal - abseil/base/raw_logging_internal - abseil/debugging/debugging_internal - abseil/debugging/demangle_internal - abseil/strings/strings - abseil/functional/bind_front (1.20211102.0): - abseil/base/base_internal - abseil/container/compressed_tuple - abseil/meta/type_traits - abseil/utility/utility - abseil/functional/function_ref (1.20211102.0): - abseil/base/base_internal - abseil/base/core_headers - abseil/meta/type_traits - abseil/hash/city (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/base/endian - abseil/hash/hash (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/base/endian - abseil/container/fixed_array - abseil/hash/city - abseil/hash/low_level_hash - abseil/meta/type_traits - abseil/numeric/int128 - abseil/strings/strings - abseil/types/optional - abseil/types/variant - abseil/utility/utility - abseil/hash/low_level_hash (1.20211102.0): - abseil/base/config - abseil/base/endian - abseil/numeric/bits - abseil/numeric/int128 - abseil/memory (1.20211102.0): - abseil/memory/memory (= 1.20211102.0) - abseil/memory/memory (1.20211102.0): - abseil/base/core_headers - abseil/meta/type_traits - abseil/meta (1.20211102.0): - abseil/meta/type_traits (= 1.20211102.0) - abseil/meta/type_traits (1.20211102.0): - abseil/base/config - abseil/numeric/bits (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/numeric/int128 (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/numeric/bits - abseil/numeric/representation (1.20211102.0): - abseil/base/config - abseil/profiling/exponential_biased (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/profiling/sample_recorder (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/synchronization/synchronization - abseil/time/time - abseil/random/distributions (1.20211102.0): - abseil/base/base_internal - abseil/base/config - abseil/base/core_headers - abseil/meta/type_traits - abseil/numeric/bits - abseil/random/internal/distribution_caller - abseil/random/internal/fast_uniform_bits - abseil/random/internal/fastmath - abseil/random/internal/generate_real - abseil/random/internal/iostream_state_saver - abseil/random/internal/traits - abseil/random/internal/uniform_helper - abseil/random/internal/wide_multiply - abseil/strings/strings - abseil/random/internal/distribution_caller (1.20211102.0): - abseil/base/config - abseil/base/fast_type_id - abseil/utility/utility - abseil/random/internal/fast_uniform_bits (1.20211102.0): - abseil/base/config - abseil/meta/type_traits - abseil/random/internal/fastmath (1.20211102.0): - abseil/numeric/bits - abseil/random/internal/generate_real (1.20211102.0): - abseil/meta/type_traits - abseil/numeric/bits - abseil/random/internal/fastmath - abseil/random/internal/traits - abseil/random/internal/iostream_state_saver (1.20211102.0): - abseil/meta/type_traits - abseil/numeric/int128 - abseil/random/internal/nonsecure_base (1.20211102.0): - abseil/base/core_headers - abseil/meta/type_traits - abseil/random/internal/pool_urbg - abseil/random/internal/salted_seed_seq - abseil/random/internal/seed_material - abseil/types/optional - abseil/types/span - abseil/random/internal/pcg_engine (1.20211102.0): - abseil/base/config - abseil/meta/type_traits - abseil/numeric/bits - abseil/numeric/int128 - abseil/random/internal/fastmath - abseil/random/internal/iostream_state_saver - abseil/random/internal/platform (1.20211102.0): - abseil/base/config - abseil/random/internal/pool_urbg (1.20211102.0): - abseil/base/base - abseil/base/config - abseil/base/core_headers - abseil/base/endian - abseil/base/raw_logging_internal - abseil/random/internal/randen - abseil/random/internal/seed_material - abseil/random/internal/traits - abseil/random/seed_gen_exception - abseil/types/span - abseil/random/internal/randen (1.20211102.0): - abseil/base/raw_logging_internal - abseil/random/internal/platform - abseil/random/internal/randen_hwaes - abseil/random/internal/randen_slow - abseil/random/internal/randen_engine (1.20211102.0): - abseil/base/endian - abseil/meta/type_traits - abseil/random/internal/iostream_state_saver - abseil/random/internal/randen - abseil/random/internal/randen_hwaes (1.20211102.0): - abseil/base/config - abseil/random/internal/platform - abseil/random/internal/randen_hwaes_impl - abseil/random/internal/randen_hwaes_impl (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/numeric/int128 - abseil/random/internal/platform - abseil/random/internal/randen_slow (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/base/endian - abseil/numeric/int128 - abseil/random/internal/platform - abseil/random/internal/salted_seed_seq (1.20211102.0): - abseil/container/inlined_vector - abseil/meta/type_traits - abseil/random/internal/seed_material - abseil/types/optional - abseil/types/span - abseil/random/internal/seed_material (1.20211102.0): - abseil/base/core_headers - abseil/base/dynamic_annotations - abseil/base/raw_logging_internal - abseil/random/internal/fast_uniform_bits - abseil/strings/strings - abseil/types/optional - abseil/types/span - abseil/random/internal/traits (1.20211102.0): - abseil/base/config - abseil/random/internal/uniform_helper (1.20211102.0): - abseil/base/config - abseil/meta/type_traits - abseil/random/internal/traits - abseil/random/internal/wide_multiply (1.20211102.0): - abseil/base/config - abseil/numeric/bits - abseil/numeric/int128 - abseil/random/internal/traits - abseil/random/random (1.20211102.0): - abseil/random/distributions - abseil/random/internal/nonsecure_base - abseil/random/internal/pcg_engine - abseil/random/internal/pool_urbg - abseil/random/internal/randen_engine - abseil/random/seed_sequences - abseil/random/seed_gen_exception (1.20211102.0): - abseil/base/config - abseil/random/seed_sequences (1.20211102.0): - abseil/container/inlined_vector - abseil/random/internal/nonsecure_base - abseil/random/internal/pool_urbg - abseil/random/internal/salted_seed_seq - abseil/random/internal/seed_material - abseil/random/seed_gen_exception - abseil/types/span - abseil/status/status (1.20211102.0): - abseil/base/atomic_hook - abseil/base/config - abseil/base/core_headers - abseil/base/raw_logging_internal - abseil/container/inlined_vector - abseil/debugging/stacktrace - abseil/debugging/symbolize - abseil/functional/function_ref - abseil/strings/cord - abseil/strings/str_format - abseil/strings/strings - abseil/types/optional - abseil/status/statusor (1.20211102.0): - abseil/base/base - abseil/base/core_headers - abseil/base/raw_logging_internal - abseil/meta/type_traits - abseil/status/status - abseil/strings/strings - abseil/types/variant - abseil/utility/utility - abseil/strings/cord (1.20211102.0): - abseil/base/base - abseil/base/config - abseil/base/core_headers - abseil/base/endian - abseil/base/raw_logging_internal - abseil/container/fixed_array - abseil/container/inlined_vector - abseil/functional/function_ref - abseil/meta/type_traits - abseil/strings/cord_internal - abseil/strings/cordz_functions - abseil/strings/cordz_info - abseil/strings/cordz_statistics - abseil/strings/cordz_update_scope - abseil/strings/cordz_update_tracker - abseil/strings/internal - abseil/strings/str_format - abseil/strings/strings - abseil/types/optional - abseil/strings/cord_internal (1.20211102.0): - abseil/base/base_internal - abseil/base/config - abseil/base/core_headers - abseil/base/endian - abseil/base/raw_logging_internal - abseil/base/throw_delegate - abseil/container/compressed_tuple - abseil/container/inlined_vector - abseil/container/layout - abseil/functional/function_ref - abseil/meta/type_traits - abseil/strings/strings - abseil/types/span - abseil/strings/cordz_functions (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/base/raw_logging_internal - abseil/profiling/exponential_biased - abseil/strings/cordz_handle (1.20211102.0): - abseil/base/base - abseil/base/config - abseil/base/raw_logging_internal - abseil/synchronization/synchronization - abseil/strings/cordz_info (1.20211102.0): - abseil/base/base - abseil/base/config - abseil/base/core_headers - abseil/base/raw_logging_internal - abseil/container/inlined_vector - abseil/debugging/stacktrace - abseil/strings/cord_internal - abseil/strings/cordz_functions - abseil/strings/cordz_handle - abseil/strings/cordz_statistics - abseil/strings/cordz_update_tracker - abseil/synchronization/synchronization - abseil/types/span - abseil/strings/cordz_statistics (1.20211102.0): - abseil/base/config - abseil/strings/cordz_update_tracker - abseil/strings/cordz_update_scope (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/strings/cord_internal - abseil/strings/cordz_info - abseil/strings/cordz_update_tracker - abseil/strings/cordz_update_tracker (1.20211102.0): - abseil/base/config - abseil/strings/internal (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/base/endian - abseil/base/raw_logging_internal - abseil/meta/type_traits - abseil/strings/str_format (1.20211102.0): - abseil/strings/str_format_internal - abseil/strings/str_format_internal (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/functional/function_ref - abseil/meta/type_traits - abseil/numeric/bits - abseil/numeric/int128 - abseil/numeric/representation - abseil/strings/strings - abseil/types/optional - abseil/types/span - abseil/strings/strings (1.20211102.0): - abseil/base/base - abseil/base/config - abseil/base/core_headers - abseil/base/endian - abseil/base/raw_logging_internal - abseil/base/throw_delegate - abseil/memory/memory - abseil/meta/type_traits - abseil/numeric/bits - abseil/numeric/int128 - abseil/strings/internal - abseil/synchronization/graphcycles_internal (1.20211102.0): - abseil/base/base - abseil/base/base_internal - abseil/base/config - abseil/base/core_headers - abseil/base/malloc_internal - abseil/base/raw_logging_internal - abseil/synchronization/kernel_timeout_internal (1.20211102.0): - abseil/base/core_headers - abseil/base/raw_logging_internal - abseil/time/time - abseil/synchronization/synchronization (1.20211102.0): - abseil/base/atomic_hook - abseil/base/base - abseil/base/base_internal - abseil/base/config - abseil/base/core_headers - abseil/base/dynamic_annotations - abseil/base/malloc_internal - abseil/base/raw_logging_internal - abseil/debugging/stacktrace - abseil/debugging/symbolize - abseil/synchronization/graphcycles_internal - abseil/synchronization/kernel_timeout_internal - abseil/time/time - abseil/time (1.20211102.0): - abseil/time/internal (= 1.20211102.0) - abseil/time/time (= 1.20211102.0) - abseil/time/internal (1.20211102.0): - abseil/time/internal/cctz (= 1.20211102.0) - abseil/time/internal/cctz (1.20211102.0): - abseil/time/internal/cctz/civil_time (= 1.20211102.0) - abseil/time/internal/cctz/time_zone (= 1.20211102.0) - abseil/time/internal/cctz/civil_time (1.20211102.0): - abseil/base/config - abseil/time/internal/cctz/time_zone (1.20211102.0): - abseil/base/config - abseil/time/internal/cctz/civil_time - abseil/time/time (1.20211102.0): - abseil/base/base - abseil/base/core_headers - abseil/base/raw_logging_internal - abseil/numeric/int128 - abseil/strings/strings - abseil/time/internal/cctz/civil_time - abseil/time/internal/cctz/time_zone - abseil/types (1.20211102.0): - abseil/types/any (= 1.20211102.0) - abseil/types/bad_any_cast (= 1.20211102.0) - abseil/types/bad_any_cast_impl (= 1.20211102.0) - abseil/types/bad_optional_access (= 1.20211102.0) - abseil/types/bad_variant_access (= 1.20211102.0) - abseil/types/compare (= 1.20211102.0) - abseil/types/optional (= 1.20211102.0) - abseil/types/span (= 1.20211102.0) - abseil/types/variant (= 1.20211102.0) - abseil/types/any (1.20211102.0): - abseil/base/config - abseil/base/core_headers - abseil/base/fast_type_id - abseil/meta/type_traits - abseil/types/bad_any_cast - abseil/utility/utility - abseil/types/bad_any_cast (1.20211102.0): - abseil/base/config - abseil/types/bad_any_cast_impl - abseil/types/bad_any_cast_impl (1.20211102.0): - abseil/base/config - abseil/base/raw_logging_internal - abseil/types/bad_optional_access (1.20211102.0): - abseil/base/config - abseil/base/raw_logging_internal - abseil/types/bad_variant_access (1.20211102.0): - abseil/base/config - abseil/base/raw_logging_internal - abseil/types/compare (1.20211102.0): - abseil/base/core_headers - abseil/meta/type_traits - abseil/types/optional (1.20211102.0): - abseil/base/base_internal - abseil/base/config - abseil/base/core_headers - abseil/memory/memory - abseil/meta/type_traits - abseil/types/bad_optional_access - abseil/utility/utility - abseil/types/span (1.20211102.0): - abseil/algorithm/algorithm - abseil/base/core_headers - abseil/base/throw_delegate - abseil/meta/type_traits - abseil/types/variant (1.20211102.0): - abseil/base/base_internal - abseil/base/config - abseil/base/core_headers - abseil/meta/type_traits - abseil/types/bad_variant_access - abseil/utility/utility - abseil/utility/utility (1.20211102.0): - abseil/base/base_internal - abseil/base/config - abseil/meta/type_traits - BoringSSL-GRPC (0.0.24): - BoringSSL-GRPC/Implementation (= 0.0.24) - BoringSSL-GRPC/Interface (= 0.0.24) - BoringSSL-GRPC/Implementation (0.0.24): - BoringSSL-GRPC/Interface (= 0.0.24) - BoringSSL-GRPC/Interface (0.0.24) - FirebaseCore (10.5.0): - FirebaseCoreInternal (~> 10.0) - GoogleUtilities/Environment (~> 7.8) - GoogleUtilities/Logger (~> 7.8) - FirebaseCoreExtension (10.5.0): - FirebaseCore (~> 10.0) - FirebaseCoreInternal (10.5.0): - "GoogleUtilities/NSData+zlib (~> 7.8)" - FirebaseFirestore (10.5.0): - abseil/algorithm (~> 1.20211102.0) - abseil/base (~> 1.20211102.0) - abseil/container/flat_hash_map (~> 1.20211102.0) - abseil/memory (~> 1.20211102.0) - abseil/meta (~> 1.20211102.0) - abseil/strings/strings (~> 1.20211102.0) - abseil/time (~> 1.20211102.0) - abseil/types (~> 1.20211102.0) - FirebaseCore (~> 10.0) - "gRPC-C++ (~> 1.44.0)" - leveldb-library (~> 1.22) - nanopb (< 2.30910.0, >= 2.30908.0) - FirebaseFirestoreSwift (10.5.0): - FirebaseCore (~> 10.0) - FirebaseCoreExtension (~> 10.0) - FirebaseFirestore (~> 10.0) - FirebaseSharedSwift (~> 10.0) - FirebaseSharedSwift (10.5.0) - GoogleBenchmark (1.5.0) - GoogleTest (99.99.99) - GoogleUtilities/Environment (7.11.0): - PromisesObjC (< 3.0, >= 1.2) - GoogleUtilities/Logger (7.11.0): - GoogleUtilities/Environment - "GoogleUtilities/NSData+zlib (7.11.0)" - "gRPC-C++ (1.44.0)": - "gRPC-C++/Implementation (= 1.44.0)" - "gRPC-C++/Interface (= 1.44.0)" - "gRPC-C++/Implementation (1.44.0)": - abseil/base/base (= 1.20211102.0) - abseil/base/core_headers (= 1.20211102.0) - abseil/container/flat_hash_map (= 1.20211102.0) - abseil/container/inlined_vector (= 1.20211102.0) - abseil/functional/bind_front (= 1.20211102.0) - abseil/hash/hash (= 1.20211102.0) - abseil/memory/memory (= 1.20211102.0) - abseil/random/random (= 1.20211102.0) - abseil/status/status (= 1.20211102.0) - abseil/status/statusor (= 1.20211102.0) - abseil/strings/cord (= 1.20211102.0) - abseil/strings/str_format (= 1.20211102.0) - abseil/strings/strings (= 1.20211102.0) - abseil/synchronization/synchronization (= 1.20211102.0) - abseil/time/time (= 1.20211102.0) - abseil/types/optional (= 1.20211102.0) - abseil/types/variant (= 1.20211102.0) - abseil/utility/utility (= 1.20211102.0) - "gRPC-C++/Interface (= 1.44.0)" - gRPC-Core (= 1.44.0) - "gRPC-C++/Interface (1.44.0)" - gRPC-Core (1.44.0): - gRPC-Core/Implementation (= 1.44.0) - gRPC-Core/Interface (= 1.44.0) - gRPC-Core/Implementation (1.44.0): - abseil/base/base (= 1.20211102.0) - abseil/base/core_headers (= 1.20211102.0) - abseil/container/flat_hash_map (= 1.20211102.0) - abseil/container/inlined_vector (= 1.20211102.0) - abseil/functional/bind_front (= 1.20211102.0) - abseil/hash/hash (= 1.20211102.0) - abseil/memory/memory (= 1.20211102.0) - abseil/random/random (= 1.20211102.0) - abseil/status/status (= 1.20211102.0) - abseil/status/statusor (= 1.20211102.0) - abseil/strings/cord (= 1.20211102.0) - abseil/strings/str_format (= 1.20211102.0) - abseil/strings/strings (= 1.20211102.0) - abseil/synchronization/synchronization (= 1.20211102.0) - abseil/time/time (= 1.20211102.0) - abseil/types/optional (= 1.20211102.0) - abseil/types/variant (= 1.20211102.0) - abseil/utility/utility (= 1.20211102.0) - BoringSSL-GRPC (= 0.0.24) - gRPC-Core/Interface (= 1.44.0) - Libuv-gRPC (= 0.0.10) - gRPC-Core/Interface (1.44.0) - leveldb-library (1.22.1) - LibFuzzer (1.0) - Libuv-gRPC (0.0.10): - Libuv-gRPC/Implementation (= 0.0.10) - Libuv-gRPC/Interface (= 0.0.10) - Libuv-gRPC/Implementation (0.0.10): - Libuv-gRPC/Interface (= 0.0.10) - Libuv-gRPC/Interface (0.0.10) - nanopb (2.30909.0): - nanopb/decode (= 2.30909.0) - nanopb/encode (= 2.30909.0) - nanopb/decode (2.30909.0) - nanopb/encode (2.30909.0) - PromisesObjC (2.1.1) - ProtobufCpp (3.11.4) DEPENDENCIES: - FirebaseCore (from `../..`) - FirebaseCoreExtension (from `../..`) - FirebaseCoreInternal (from `../..`) - FirebaseFirestore (from `../..`) - FirebaseFirestoreSwift (from `../../`) - FirebaseSharedSwift (from `../../`) - GoogleBenchmark (from `GoogleBenchmark.podspec`) - GoogleTest (from `GoogleTest.podspec`) - leveldb-library - LibFuzzer (from `LibFuzzer.podspec`) - ProtobufCpp (from `ProtobufCpp.podspec`) SPEC REPOS: trunk: - abseil - BoringSSL-GRPC - GoogleUtilities - "gRPC-C++" - gRPC-Core - leveldb-library - Libuv-gRPC - nanopb - PromisesObjC EXTERNAL SOURCES: FirebaseCore: :path: "../.." FirebaseCoreExtension: :path: "../.." FirebaseCoreInternal: :path: "../.." FirebaseFirestore: :path: "../.." FirebaseFirestoreSwift: :path: "../../" FirebaseSharedSwift: :path: "../../" GoogleBenchmark: :podspec: GoogleBenchmark.podspec GoogleTest: :podspec: GoogleTest.podspec LibFuzzer: :podspec: LibFuzzer.podspec ProtobufCpp: :podspec: ProtobufCpp.podspec CHECKOUT OPTIONS: LibFuzzer: :commit: 4626bd0b91102af234125f7f8ff0daaffb7a1fa4 :git: https://github.com/llvm/llvm-project.git SPEC CHECKSUMS: abseil: ebe5b5529fb05d93a8bdb7951607be08b7fa71bc BoringSSL-GRPC: 3175b25143e648463a56daeaaa499c6cb86dad33 FirebaseCore: 324b8d182d9ff7e3f6d1fa2f04b082d1c7a3e366 FirebaseCoreExtension: d9fa427f1ae1edccf2368ce5e8d567e4c1f0ebc8 FirebaseCoreInternal: e463f41bb935cd049505bf7e9a5bdd7dcea90df6 FirebaseFirestore: 7785ee9fe192f736fdb9f5d14a451ba0b33c3005 FirebaseFirestoreSwift: 3f63a09244cf0dc5e19072c13618446c686b05b6 FirebaseSharedSwift: 30289ed76ccb441067a2cd3472cc5b2f491b9d8f GoogleBenchmark: cf1f83beb67a519251fcc4026876a665966e8b6b GoogleTest: 3768a5de0867ab88af66e86117030466d313f485 GoogleUtilities: c2bdc4cf2ce786c4d2e6b3bcfd599a25ca78f06f "gRPC-C++": 9675f953ace2b3de7c506039d77be1f2e77a8db2 gRPC-Core: 943e491cb0d45598b0b0eb9e910c88080369290b leveldb-library: 50c7b45cbd7bf543c81a468fe557a16ae3db8729 LibFuzzer: 5d026ad5b27314c02b1d8e8440de43ec35382710 Libuv-gRPC: 55e51798e14ef436ad9bc45d12d43b77b49df378 nanopb: b552cce312b6c8484180ef47159bc0f65a1f0431 PromisesObjC: ab77feca74fa2823e7af4249b8326368e61014cb ProtobufCpp: 3e2fbf7f779e13869e8065a46b77a0e4c1db4f04 PODFILE CHECKSUM: e0ea8e0c3ec38137252f85cf75983e473cbf9219 COCOAPODS: 1.11.3 ```
google-oss-bot commented 1 year ago

I couldn't figure out how to label this issue, so I've labeled it for a human to triage. Hang tight.

MarkDuckworth commented 1 year ago

Thanks for reporting. We will take a deeper look and follow up.

watabee commented 1 year ago

I have the same issue. Is there any solution available?

MarkDuckworth commented 1 year ago

@isegal, sorry for the delay. I have been reviewing your theory today. It looks like a new Transaction instance is created by the TransactionRunner each time the transaction commit is attempted, therefore the _committed flag is reset to false on each attempt to retry the transaction. In my testing, this occurred both when the transaction was retried because the backend could not be reached or when a document had been modified by another process.

Specifically this line is creating a new Transaction object on each commit attempt:

    std::shared_ptr<Transaction> transaction =
        shared_this->remote_store_->CreateTransaction();

Have you able to reproduce the issue in test since you originally reported?

@watabee, are you able to reproduce this with a test? Or do you have any more context on what your application is doing when this occurs?

MarkDuckworth commented 1 year ago

We reviewed this issue again yesterday but couldn't determine how to reproduce it or how it could occur. The next step would be to enable logging in the SDK and provide us with logs from the time that the issue occurs in your applicaiton.

isegal commented 1 year ago

@isegal, sorry for the delay. I have been reviewing your theory today. It looks like a new Transaction instance is created by the TransactionRunner each time the transaction commit is attempted, therefore the _committed flag is reset to false on each attempt to retry the transaction. In my testing, this occurred both when the transaction was retried because the backend could not be reached or when a document had been modified by another process.

Have you able to reproduce the issue in test since you originally reported?

I have not been able to reproduce locally or in the lab environment, but we are still getting occasional crash reports from production when running at scale.

Specifically this line is creating a new Transaction object on each commit attempt:

    std::shared_ptr<Transaction> transaction =
        shared_this->remote_store_->CreateTransaction();

Sorry, I overlooked this. But I wonder if the issue is elsewhere:

It looks like FlutterFire is also maintaining its own dictionary of transaction objects and keying by transactionId which it also maintains (based on generating a UUID).

https://github.com/firebase/flutterfire/blob/d14b545adb6052f1e5acd7a0e679d790a4741122/packages/cloud_firestore/cloud_firestore/ios/Classes/FLTFirebaseFirestorePlugin.m#L372

(FIRTransaction has a shared ownership of Transaction)

@implementation FIRTransaction {
  std::shared_ptr<Transaction> _internalTransaction;
}

Looking back at the original stack trace, we see that FLT is invoking a method on its own potentially stale transaction object:

10 Runner 0xf4b10 -[FIRTransaction getDocument:error:] 11 Runner 0x1fa648 __66-[FLTFirebaseFirestorePlugin transactionGet:withMethodCallResult:]_block_invoke + 368 (FLTFirebaseFirestorePlugin.m:368)

I wonder if somehow FlutterFire is using a stale transaction object as a result of a rare race condition?

fivecar commented 1 year ago

@MarkDuckworth / @isegal : I get this issue in a production app on RNFirebase (i.e. without Flutter in the mix). The crash comes up every few days, on a user base of 20 users (!), and so it's relatively frequent. Especially considering my app only uses one transaction an hour.

FIRESTORE INTERNAL ASSERTION FAILED: A transaction object cannot be used after its update callback has been invoked. (expected !committed_)

If I were to enableLogging in the production app, how would I get those logs back to you? I'm using Instabug at the moment, but could potentially use RNFirebase's Crashlytics. It seems to me, though, that neither platform would ship the full set of necessary logs from a production app...

fivecar commented 1 month ago

@MarkDuckworth @isegal : just wanted to check back on my question ^^^, since this crash still regularly happens in my super-low MAU app on a regular basis.