Transaction crash

[michalrentka]

How frequently does the bug occur?

Sometimes

Description

Users complain that even though no specific action can reproduce this issue, inevitably the app will crash after some time of usage. The app has a sync functionality, so it processes data in the background queue, while the user is using the app, so that's why users might feel that way.

All Realm writes are made in background queues. In background queue all realms are created and all realm actions are performed in an autoreleasepool block. The realm is invalidated after write. The realm file is accessed only from the main app.

The realm wrapper can be found here: https://github.com/zotero/zotero-ios/blob/master/Zotero/Controllers/Database/RealmDbStorage.swift

Stacktrace & log output

Incident Identifier: 66541EC6-0FC2-4BC7-9F07-81C3126A011B
Hardware Model:      iPad8,11
Process:         Zotero [7841]
Path:            /private/var/containers/Bundle/Application/CC7D0E85-86F0-4D6E-8252-7641FDA67557/Zotero.app/Zotero
Identifier:      org.zotero.ios.Zotero
Version:         1.0.3 (5)
Code Type:       ARM-64
Parent Process:   [1]

Date/Time:       2022-05-03 22:14:49 +0000
OS Version:      iPhone OS 15.4.1 (19E258)
Report Version:  104

Exception Type:  SIGABRT
Exception Codes: #0 at 0x1b7e33b78
Crashed Thread:  5

Thread 0:
0   libsystem_kernel.dylib              0x00000001b7e2d4e0 mach_msg_trap + 8
1   CoreFoundation                      0x0000000180f88820 __CFRunLoopServiceMachPort + 372
2   CoreFoundation                      0x0000000180f8ccac __CFRunLoopRun + 1180
3   CoreFoundation                      0x0000000180fa06b8 CFRunLoopRunSpecific + 600
4   GraphicsServices                    0x000000019d03a374 GSEventRunModal + 164
5   UIKitCore                           0x0000000183905e88 -[UIApplication _run] + 1100
6   UIKitCore                           0x00000001836875ec UIApplicationMain + 364
7   Zotero                              0x000000010082ad04 main + 27908 (<compiler-generated>:0)
8   ???                                 0x0000000101b9dce4 0x0 + 0

Thread 1:
0   libsystem_kernel.dylib              0x00000001b7e2d4e0 mach_msg_trap + 8
1   CoreFoundation                      0x0000000180f88820 __CFRunLoopServiceMachPort + 372
2   CoreFoundation                      0x0000000180f8ccac __CFRunLoopRun + 1180
3   CoreFoundation                      0x0000000180fa06b8 CFRunLoopRunSpecific + 600
4   Foundation                          0x0000000182787414 -[NSRunLoop+ 99348 (NSRunLoop) runMode:beforeDate:] + 236
5   Foundation                          0x00000001827c8cac -[NSRunLoop+ 367788 (NSRunLoop) runUntilDate:] + 92
6   UIKitCore                           0x000000018387ffb0 -[UIEventFetcher threadMain] + 524
7   Foundation                          0x00000001827d755c __NSThread__start__ + 808
8   libsystem_pthread.dylib             0x00000001f14ee9ac _pthread_start + 148
9   libsystem_pthread.dylib             0x00000001f14ede68 thread_start + 8

Thread 2:
0   libsystem_kernel.dylib              0x00000001b7e2d4e0 mach_msg_trap + 8
1   Zotero                              0x0000000101274a28 exception_server_thread + 10816040 (PLCrashMachExceptionServer.m:683)
2   libsystem_pthread.dylib             0x00000001f14ee9ac _pthread_start + 148
3   libsystem_pthread.dylib             0x00000001f14ede68 thread_start + 8

Thread 3:
0   libsystem_kernel.dylib              0x00000001b7e2ee58 kevent + 8
1   Zotero                              0x000000010108d5cc void* std::__1::__thread_proxy<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, realm::_impl::ExternalCommitHelper::ExternalCommitHelper(realm::_impl::RealmCoordinator&)::$_0> >(void*) + 8820172 (thread:300)
2   libsystem_pthread.dylib             0x00000001f14ee9ac _pthread_start + 148
3   libsystem_pthread.dylib             0x00000001f14ede68 thread_start + 8

Thread 4:
0   libsystem_kernel.dylib              0x00000001b7e2d4e0 mach_msg_trap + 8
1   CoreFoundation                      0x0000000180f88820 __CFRunLoopServiceMachPort + 372
2   CoreFoundation                      0x0000000180f8ccac __CFRunLoopRun + 1180
3   CoreFoundation                      0x0000000180fa06b8 CFRunLoopRunSpecific + 600
4   CFNetwork                           0x0000000181a164d8 0x18179f000 + 2585816
5   Foundation                          0x00000001827d755c __NSThread__start__ + 808
6   libsystem_pthread.dylib             0x00000001f14ee9ac _pthread_start + 148
7   libsystem_pthread.dylib             0x00000001f14ede68 thread_start + 8

Thread 5 Crashed:
0   libsystem_kernel.dylib              0x00000001b7e33b78 __pthread_kill + 8
1   libsystem_c.dylib                   0x000000018c0fd51c abort + 168
2   Zotero                              0x0000000101242b90 std::__1::basic_stringstream<char, std::__1::char_traits<char>, std::__1::allocator<char> >::basic_stringstream() + 10611600 (sstream:803)
3   Zotero                              0x0000000101242d94 realm::util::terminate_internal(std::__1::basic_stringstream<char, std::__1::char_traits<char>, std::__1::allocator<char> >&) + 10612116 (terminate.cpp:123)
4   Zotero                              0x0000000101242ecc realm::util::terminate(char const*, char const*, long, std::initializer_list<realm::util::Printable>&&) + 10612428 (terminate.cpp:0)
5   Zotero                              0x0000000101022bf8 realm::DB::do_end_write() + 8383480 (db.cpp:2294)
6   Zotero                              0x0000000101024cc8 realm::Transaction::rollback() + 8391880 (db.cpp:2787)
7   Zotero                              0x0000000101021a10 realm::Transaction::close() + 8378896 (db.cpp:2690)
8   Zotero                              0x000000010102ab18 std::__1::__shared_ptr_pointer<realm::Transaction*, (anonymous namespace)::$_8, std::__1::allocator<realm::Transaction> >::__on_zero_shared() + 8416024 (shared_ptr.h:267)
9   Zotero                              0x0000000100e1d3c0 std::__1::shared_ptr<realm::app::App>::~shared_ptr() + 6263744 (shared_ptr.h:959)
10  Zotero                              0x00000001010ff458 realm::Realm::~Realm() + 9286744 (shared_realm.cpp:104)
11  Zotero                              0x0000000100e1d3c0 std::__1::shared_ptr<realm::app::App>::~shared_ptr() + 6263744 (shared_ptr.h:959)
12  libobjc.A.dylib                     0x0000000199c712f0 object_cxxDestructFromClass+ 33520 (objc_object*, objc_class*) + 116
13  libobjc.A.dylib                     0x0000000199c6e144 objc_destructInstance + 80
14  libobjc.A.dylib                     0x0000000199c779b4 _objc_rootDealloc + 80
15  Zotero                              0x0000000100f1e548 -[RLMRealm dealloc] + 7316808 (RLMRealm.mm:0)
16  libobjc.A.dylib                     0x0000000199c70a74 AutoreleasePoolPage::releaseUntil+ 31348 (objc_object**) + 196
17  libobjc.A.dylib                     0x0000000199c6cdf4 objc_autoreleasePoolPop + 212
18  libswiftObjectiveC.dylib            0x00000001aef6ea1c autoreleasepool<A>+ 6684 (invoking:) + 76
19  Zotero                              0x000000010087a5ac specialized RealmDbStorage.perform<A>(request:invalidateRealm:) + 353708 (RealmDbStorage.swift:69)
20  Zotero                              0x0000000100a4c234 specialized SyncBatchProcessor.sync(data:libraryId:object:userId:expectedKeys:) + 2261556 (SyncBatchProcessor.swift:165)
21  Zotero                              0x0000000100a49d7c SyncBatchProcessor.process(data:headers:batch:) + 2252156 (SyncBatchProcessor.swift:102)
22  Zotero                              0x0000000100a49ccc closure #2 in closure #1 in SyncBatchProcessor.start() + 2251980 (<compiler-generated>:0)
23  Zotero                              0x0000000100a4b5a8 partial apply for closure #2 in closure #1 in SyncBatchProcessor.start() + 2258344 (<compiler-generated>:0)
24  Zotero                              0x00000001009fb408 closure #2 in ApiOperation.main() + 1930248 (<compiler-generated>:0)
25  Zotero                              0x0000000100dc91bc partial apply for specialized closure #2 in closure #2 in closure #3 in closure #1 in DownloadRequest._response<A>+ 5919164 (queue:responseSerializer:completionHandler:) + 48
26  Zotero                              0x0000000100d5cd6c thunk for @escaping @callee_guaranteed () -> () + 5475692 (<compiler-generated>:0)
27  libdispatch.dylib                   0x0000000180c7fe68 _dispatch_call_block_and_release + 32
28  libdispatch.dylib                   0x0000000180c81a2c _dispatch_client_callout + 20
29  libdispatch.dylib                   0x0000000180c89124 _dispatch_lane_serial_drain + 668
30  libdispatch.dylib                   0x0000000180c89c80 _dispatch_lane_invoke + 392
31  libdispatch.dylib                   0x0000000180c94500 _dispatch_workloop_worker_thread + 648
32  libsystem_pthread.dylib             0x00000001f14ee0bc _pthread_wqthread + 288
33  libsystem_pthread.dylib             0x00000001f14ede5c start_wqthread + 8

Thread 6:
0   libsystem_kernel.dylib              0x00000001b7e2dab4 __workq_kernreturn + 8
1   libsystem_pthread.dylib             0x00000001f14ede5c start_wqthread + 8

Thread 7:
0   libsystem_kernel.dylib              0x00000001b7e2dab4 __workq_kernreturn + 8
1   libsystem_pthread.dylib             0x00000001f14ede5c start_wqthread + 8

Thread 8:
0   libsystem_kernel.dylib              0x00000001b7e2dab4 __workq_kernreturn + 8
1   libsystem_pthread.dylib             0x00000001f14ede5c start_wqthread + 8

Thread 9:
0   libsystem_kernel.dylib              0x00000001b7e2dab4 __workq_kernreturn + 8
1   libsystem_pthread.dylib             0x00000001f14ede5c start_wqthread + 8

Thread 10:
0   libsystem_kernel.dylib              0x00000001b7e2dab4 __workq_kernreturn + 8
1   libsystem_pthread.dylib             0x00000001f14ede5c start_wqthread + 8

Thread 11:
0   libsystem_kernel.dylib              0x00000001b7e2dab4 __workq_kernreturn + 8
1   libsystem_pthread.dylib             0x00000001f14ede5c start_wqthread + 8

Thread 12:
0   ???                                 0x0000000000000000 0x0 + 0

Can you reproduce the bug?

Yes, sometimes

Reproduction Steps

Perform enough writes to realms in background queues until the app crashes.

Version

10.25.1

What SDK flavour are you using?

Local Database only

Are you using encryption?

No, not using encryption

Platform OS and version(s)

iOS 15.4.1

Build environment

Xcode version: 13.3
Dependency manager: SwiftPM

[leemaguire]

Hi @michalrentka I took a look at your repo and see that the Realm is not confined to the queue that is set for SyncBatchProcessor.storageQueue. Because the Realm is being accessed concurrently inside of SyncBatchProcessor.start() without any locking I suspect that is what is causing the crash. Can you open the Realm with the storageQueue and see if that solves the issue?

https://www.mongodb.com/docs/realm/sdk/swift/advanced-guides/threading/#create-a-serial-queue-to-use-realm-on-a-background-thread

[michalrentka]

Thanks @leemaguire! I completely missed that part, shame on me. Is it ok to write to Realm from multiple background queues or would you recommend creating a separate queue and synchronize all writes to that queue?

I'll test your suggestion and see whether I can reproduce or we have more reports.

Edit: Actually I re-checked. The write is happening on storageQueue. The api operation runs completion block in provided queue as queue.async { completion(...) } in https://github.com/zotero/zotero-ios/blob/827cede5c7643e0944e812532f3d0a572077b445/Zotero/Controllers/Sync/SyncBatchProcessor.swift#L71. I added dispatchPrecondition(condition: .onQueue(self.storageQueue)) and it's running on storageQueue, which is serial. I can add storageQueue.async(flags: .barrier), but that shouldn't change anything on serial queue.

[sipersso]

I am seeing a few crashes with a very similar stacktrace. One common thing I could see for these crash reports was that there was a trace that the realm was supposed to be compacted. Maybe realm compaction has something to do with this?

 0x6bbc __pthread_kill + 8
1  libsystem_pthread.dylib        0xd854 pthread_kill + 208
2  libsystem_c.dylib              0x1f6a4 abort + 124
3  MyApp                       0x68e948 realm::util::terminate(char const*, char const*, long, std::initializer_list<realm::util::Printable>&&) + 128 (terminate.cpp:128)
4  MyApp                       0x68ec88 realm::util::terminate_internal(std::__1::basic_stringstream<char, std::__1::char_traits<char>, std::__1::allocator<char> >&) + 123 (terminate.cpp:123)
5  MyApp                       0x68ea04 realm::util::terminate(char const*, char const*, long, std::initializer_list<realm::util::Printable>&&) + 133 (terminate.cpp:133)
6  MyApp                       0x46f1d0 realm::DB::do_end_write() + 2294 (db.cpp:2294)
7  MyApp                       0x4712a0 realm::Transaction::rollback() + 2787 (db.cpp:2787)
8  MyApp                       0x46dfe8 realm::Transaction::close() + 2690 (db.cpp:2690)
9  MyApp                       0x4770f0 std::__1::__shared_ptr_pointer<realm::Transaction*, (anonymous namespace)::$_8, std::__1::allocator<realm::Transaction> >::__on_zero_shared() + 395 (db.cpp:395)
10 MyApp                       0x307784 std::__1::shared_ptr<realm::app::App>::~shared_ptr() + 220 (shared_ptr.h:220)
11 MyApp                       0x54b124 realm::Realm::~Realm() + 104 (shared_realm.cpp:104)
12 MyApp                       0x307784 std::__1::shared_ptr<realm::app::App>::~shared_ptr() + 220 (shared_ptr.h:220)
13 libobjc.A.dylib                0x7800 object_cxxDestructFromClass(objc_object*, objc_class*) + 112
14 libobjc.A.dylib                0x4874 objc_destructInstance + 92
15 libobjc.A.dylib                0xd824 _objc_rootDealloc + 52
16 MyApp                       0x40890c -[RLMRealm dealloc] + 822 (RLMRealm.mm:822)
17 libobjc.A.dylib                0x6e78 AutoreleasePoolPage::releaseUntil(objc_object**) + 192
18 libobjc.A.dylib                0x3734 objc_autoreleasePoolPop + 208
19 libswiftObjectiveC.dylib       0xbdc autoreleasepool<A>(invoking:) + 68
20 MyApp                       0x12442c partial apply for specialized closure #1 in Realm.writeAsync<A>(obj:errorHandler:onComplete:block:) + 4342334508
21 MyApp                       0x63fa4 thunk for @escaping @callee_guaranteed () -> () + 4341546916 (<compiler-generated>:4341546916)```

[pavel-ship-it]

@michalrentka ,
Is this the only place you're creating a Realm instance?
Please note the Realm constructor here - we're not only opening Realm on the queue but passing the queue to the Realm too.

[michalrentka]

@pavel-ship-it thanks for pointing that out. I thought it's not mandatory to use that parameter. I'll update my code to confine all Realm instances to their respective queues and update this issue if I still get similar crash reports.

[sync-by-unito]

➤ Finn Andersen commented:

@michalrentka - did it fix your problem?

[michalrentka]

@finnschiermer we didn't release this into the wild yet, but I didn't see any similar crashes in beta testing, so this is most likely solved by those changes. I think we can close this issue.