couchbase-lite-C icon indicating copy to clipboard operation
couchbase-lite-C copied to clipboard

Crash when closing database shortly after query change

Open blaugold opened this issue 3 years ago • 4 comments

OS: iOS Simulator CBL C: Couchbase Lite for C / EE build number 183, ID 3.0.0, from commit d1821646+b018a12d

Below is an excerpt of the iOS crash report with the stack traces of the two threads that seem relevant to me. This zip archive contains the full crash report as well as Couchbase Lite logs.

Exception Type:        EXC_BAD_ACCESS (SIGSEGV)
Exception Codes:       KERN_INVALID_ADDRESS at 0x0000000000000000
Exception Note:        EXC_CORPSE_NOTIFY

Termination Signal:    Segmentation fault: 11
Termination Reason:    Namespace SIGNAL, Code 0xb
Terminating Process:   exc handler [3594]

Thread 1:
0   libsystem_kernel.dylib        	0x000000010c6862ba mach_msg_trap + 10
1   libsystem_kernel.dylib        	0x000000010c68662c mach_msg + 60
2   libsystem_notify.dylib        	0x000000010c56b330 notify_check + 773
3   libsystem_c.dylib             	0x000000010b894ed6 notify_check_tz + 32
4   libsystem_c.dylib             	0x000000010b894ace tzsetwall_basic + 55
5   libsystem_c.dylib             	0x000000010b896df3 mktime + 46
6   com.couchbase.CouchbaseLite-C 	0x0000000109970b96 fleece::GetLocalTZOffset(tm*, bool) + 81 (ParseDate.cc:503) [inlined]
7   com.couchbase.CouchbaseLite-C 	0x0000000109970b96 litecore::LogIterator::writeTimestamp(litecore::LogIterator::Timestamp, std::__1::basic_ostream<char, std::__1::char_traits<char> >&) + 518 (LogDecoder.cc:59)
8   com.couchbase.CouchbaseLite-C 	0x00000001098f96eb litecore::LogDomain::dylog(litecore::LogLevel, char const*, unsigned int, char const*, __va_list_tag*) + 203 (Logging.cc:508) [inlined]
9   com.couchbase.CouchbaseLite-C 	0x00000001098f96eb litecore::LogDomain::vlog(litecore::LogLevel, unsigned int, bool, char const*, __va_list_tag*) + 709 (Logging.cc:463)
10  com.couchbase.CouchbaseLite-C 	0x00000001098f9ee4 litecore::Logging::_log(litecore::LogLevel, char const*, ...) const + 120 (Logging.cc:652)
11  com.couchbase.CouchbaseLite-C 	0x000000010990730e litecore::LiveQuerier::stop() + 20 (LiveQuerier.cc:82) [inlined]
12  com.couchbase.CouchbaseLite-C 	0x000000010990730e C4Query::enableObserver(litecore::C4QueryObserverImpl*, bool) + 1114 (c4Query.cc:275)
13  com.couchbase.CouchbaseLite-C 	0x0000000109907c27 litecore::C4QueryObserverImpl::~C4QueryObserverImpl() + 43 (c4QueryImpl.hh:129)
14  com.couchbase.CouchbaseLite-C 	0x0000000109906dfa litecore::C4QueryObserverImpl::~C4QueryObserverImpl() + 5 (c4QueryImpl.hh:127) [inlined]
15  com.couchbase.CouchbaseLite-C 	0x0000000109906dfa litecore::C4QueryObserverImpl::~C4QueryObserverImpl() + 14 (c4QueryImpl.hh:127)
16  com.couchbase.CouchbaseLite-C 	0x00000001098c9f90 cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::~ListenerToken() + 58 (CBLQuery_Internal.hh:198)
17  com.couchbase.CouchbaseLite-C 	0x00000001098c9ef6 cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::~ListenerToken() + 5 (CBLQuery_Internal.hh:187) [inlined]
18  com.couchbase.CouchbaseLite-C 	0x00000001098c9ef6 cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::~ListenerToken() + 14 (CBLQuery_Internal.hh:187)
19  com.couchbase.CouchbaseLite-C 	0x00000001098c9e71 fleece::Retained<cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)> >::~Retained() + 8 (RefCounted.hh:109) [inlined]
20  com.couchbase.CouchbaseLite-C 	0x00000001098c9e71 fleece::Retained<cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)> >::~Retained() + 8 (RefCounted.hh:109) [inlined]
21  com.couchbase.CouchbaseLite-C 	0x00000001098c9e71 void CBLDatabase::notify<void (*)(void*, CBLQuery*, CBLListenerToken*)>(cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>*) const + 64 (CBLDatabase_Internal.hh:278) [inlined]
22  com.couchbase.CouchbaseLite-C 	0x00000001098c9e71 cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::queryChanged() + 72 (CBLDatabase.cc:88) [inlined]
23  com.couchbase.CouchbaseLite-C 	0x00000001098c9e71 cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::ListenerToken(CBLQuery*, void (*)(void*, CBLQuery*, CBLListenerToken*), void*)::'lambda'(C4Query*)::operator()(C4Query*) const::'lambda'(C4QueryObserver*)::operator()(C4QueryObserver*) const + 72 (CBLQuery_Internal.hh:183) [inlined]
24  com.couchbase.CouchbaseLite-C 	0x00000001098c9e71 decltype(std::__1::forward<void (*)(void*, CBLQuery*, CBLListenerToken*)>(fp)(std::__1::forward<cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::ListenerToken(CBLQuery*, void (*)(void*, CBLQuery*, CBLListenerToken*), void*)::'lambda'(C4Query*)::operator()(C4Query*) const::'lambda'(C4QueryObserver*)&>(fp0)...)) std::__1::__invoke<cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::ListenerToken(CBLQuery*, void (*)(void*, CBLQuery*, CBLListenerToken*), void*)::'lambda'(C4Query*)::operator()(C4Query*) const::'lambda'(C4QueryObserver*)&, C4QueryObserver*>(void (*&&)(void*, CBLQuery*, CBLListenerToken*), cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::ListenerToken(CBLQuery*, void (*)(void*, CBLQuery*, CBLListenerToken*), void*)::'lambda'(C4Query*)::operator()(C4Query*) const::'lambda'(C4QueryObserver*)&...) + 72 (type_traits:3747) [inlined]
25  com.couchbase.CouchbaseLite-C 	0x00000001098c9e71 void std::__1::__invoke_void_return_wrapper<void>::__call<cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::ListenerToken(CBLQuery*, void (*)(void*, CBLQuery*, CBLListenerToken*), void*)::'lambda'(C4Query*)::operator()(C4Query*) const::'lambda'(C4QueryObserver*)&, C4QueryObserver*>(void (*&&)(void*, CBLQuery*, CBLListenerToken*)...) + 72 (__functional_base:348) [inlined]
26  com.couchbase.CouchbaseLite-C 	0x00000001098c9e71 std::__1::__function::__alloc_func<cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::ListenerToken(CBLQuery*, void (*)(void*, CBLQuery*, CBLListenerToken*), void*)::'lambda'(C4Query*)::operator()(C4Query*) const::'lambda'(C4QueryObserver*), std::__1::allocator<cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::ListenerToken(CBLQuery*, void (*)(void*, CBLQuery*, CBLListenerToken*), void*)::'lambda'(C4Query*)::operator()(C4Query*) const::'lambda'(C4QueryObserver*)>, void (C4QueryObserver*)>::operator()(C4QueryObserver*&&) + 72 (functional:1553) [inlined]
27  com.couchbase.CouchbaseLite-C 	0x00000001098c9e71 std::__1::__function::__func<cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::ListenerToken(CBLQuery*, void (*)(void*, CBLQuery*, CBLListenerToken*), void*)::'lambda'(C4Query*)::operator()(C4Query*) const::'lambda'(C4QueryObserver*), std::__1::allocator<cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::ListenerToken(CBLQuery*, void (*)(void*, CBLQuery*, CBLListenerToken*), void*)::'lambda'(C4Query*)::operator()(C4Query*) const::'lambda'(C4QueryObserver*)>, void (C4QueryObserver*)>::operator()(C4QueryObserver*&&) + 101 (functional:1727)
28  com.couchbase.CouchbaseLite-C 	0x0000000109907933 std::__1::__function::__value_func<void (C4QueryObserver*)>::operator()(C4QueryObserver*&&) const + 19 (functional:1880) [inlined]
29  com.couchbase.CouchbaseLite-C 	0x0000000109907933 std::__1::function<void (C4QueryObserver*)>::operator()(C4QueryObserver*) const + 19 (functional:2555) [inlined]
30  com.couchbase.CouchbaseLite-C 	0x0000000109907933 litecore::C4QueryObserverImpl::notify(litecore::C4QueryEnumeratorImpl*, C4Error) + 75 (c4QueryImpl.hh:143) [inlined]
31  com.couchbase.CouchbaseLite-C 	0x0000000109907933 C4Query::notifyObservers(std::__1::set<litecore::C4QueryObserverImpl*, std::__1::less<litecore::C4QueryObserverImpl*>, std::__1::allocator<litecore::C4QueryObserverImpl*> > const&, litecore::QueryEnumerator*, C4Error) + 199 (c4Query.cc:318)
32  com.couchbase.CouchbaseLite-C 	0x0000000109907b3a C4Query::liveQuerierUpdated(litecore::QueryEnumerator*, C4Error) + 99 (c4Query.cc:302) [inlined]
33  com.couchbase.CouchbaseLite-C 	0x0000000109907b3a C4Query::LiveQuerierDelegate::liveQuerierUpdated(litecore::QueryEnumerator*, C4Error) + 120 (c4Query.cc:214)
34  com.couchbase.CouchbaseLite-C 	0x000000010994db3f litecore::LiveQuerier::_runQuery(litecore::Query::Options) + 819
35  com.couchbase.CouchbaseLite-C 	0x000000010994de91 litecore::LiveQuerier::_changeOptions(litecore::Query::Options) + 105 (LiveQuerier.cc:218)
36  com.couchbase.CouchbaseLite-C 	0x000000010994de01 ___ZN8litecore5actor5Actor7enqueueINS_11LiveQuerierEJNS_5Query7OptionsEEEEvPKcMT_FvDpT0_ESA__block_invoke + 81 (Actor.hh:111)
37  com.couchbase.CouchbaseLite-C 	0x00000001098fde7e litecore::actor::GCDMailbox::safelyCall(void () block_pointer) const + 16 (GCDMailbox.cc:86)
38  com.couchbase.CouchbaseLite-C 	0x00000001098fdf36 ___ZN8litecore5actor10GCDMailbox7enqueueEPKcU13block_pointerFvvE_block_invoke + 22 (GCDMailbox.cc:121)
39  libdispatch.dylib             	0x000000010c4a165a _dispatch_call_block_and_release + 12
40  libdispatch.dylib             	0x000000010c4a283a _dispatch_client_callout + 8
41  libdispatch.dylib             	0x000000010c4a8e0c _dispatch_lane_serial_drain + 743
42  libdispatch.dylib             	0x000000010c4a99d0 _dispatch_lane_invoke + 400
43  libdispatch.dylib             	0x000000010c4b457d _dispatch_workloop_worker_thread + 772
44  libsystem_pthread.dylib       	0x000000010c7a545d _pthread_wqthread + 314
45  libsystem_pthread.dylib       	0x000000010c7a442f start_wqthread + 15

Thread 19 Crashed:: DartWorker
0   com.couchbase.CouchbaseLite-C 	0x00000001098bc287 cbl_internal::ListenerToken<void (*)(void*, CBLQuery*, CBLListenerToken*)>::setEnabled(bool) + 69 (CBLQuery.cc:39)
1   com.couchbase.CouchbaseLite-C 	0x00000001098c372b CBLDatabase::stopActiveStoppables() + 239 (CBLDatabase_Internal.hh:415)
2   com.couchbase.CouchbaseLite-C 	0x00000001098c35cd CBLDatabase::close() + 5 (CBLDatabase_Internal.hh:104) [inlined]
3   com.couchbase.CouchbaseLite-C 	0x00000001098c35cd CBLDatabase_Close + 32 (CBLDatabase_CAPI.cc:78)
4   com.terwesten.gabriel.dart.cbl	0x00000001096400e3 CBLDart_CBLDatabase_Close + 339
5   ???                           	0x000000012d685a6b 0 + 5056780907
6   ???                           	0x000000013548e35d 0 + 5188936541
7   ???                           	0x000000013548e16d 0 + 5188936045
8   ???                           	0x0000000134a6e6ca 0 + 5178320586
9   ???                           	0x00000001348fa37a 0 + 5176796026
10  ???                           	0x000000013548dffb 0 + 5188935675
11  ???                           	0x000000013548ddbf 0 + 5188935103
12  ???                           	0x0000000134a7197c 0 + 5178333564
13  ???                           	0x000000013548db6e 0 + 5188934510
14  ???                           	0x000000013548d8a0 0 + 5188933792
15  ???                           	0x000000013548cb1e 0 + 5188930334
16  ???                           	0x000000013497b0c8 0 + 5177323720
17  ???                           	0x0000000134941aee 0 + 5177088750
18  ???                           	0x000000013492ed53 0 + 5177011539
19  ???                           	0x0000000134b1d606 0 + 5179037190
20  ???                           	0x0000000134a9ad2f 0 + 5178502447
21  ???                           	0x00000001344d52c9 0 + 5172449993
22  ???                           	0x00000001344d51fa 0 + 5172449786
23  ???                           	0x0000000134ad9136 0 + 5178757430
24  ???                           	0x000000012d6829b5 0 + 5056768437
25  io.flutter.flutter            	0x000000010d9453b8 dart::DartEntry::InvokeCode(dart::Code const&, unsigned long, dart::Array const&, dart::Array const&, dart::Thread*) + 296
26  io.flutter.flutter            	0x000000010d945224 dart::DartEntry::InvokeFunction(dart::Function const&, dart::Array const&, dart::Array const&, unsigned long) + 324
27  io.flutter.flutter            	0x000000010d947592 dart::DartLibraryCalls::HandleMessage(long long, dart::Instance const&) + 354
28  io.flutter.flutter            	0x000000010d969196 dart::IsolateMessageHandler::HandleMessage(std::__1::unique_ptr<dart::Message, std::__1::default_delete<dart::Message> >) + 966
29  io.flutter.flutter            	0x000000010d992433 dart::MessageHandler::HandleMessages(dart::MonitorLocker*, bool, bool) + 291
30  io.flutter.flutter            	0x000000010d992a4b dart::MessageHandler::TaskCallback() + 475
31  io.flutter.flutter            	0x000000010daafdc8 dart::ThreadPool::WorkerLoop(dart::ThreadPool::Worker*) + 328
32  io.flutter.flutter            	0x000000010dab00cd dart::ThreadPool::Worker::Main(unsigned long) + 93
33  io.flutter.flutter            	0x000000010da2e26f dart::ThreadStart(void*) + 159
34  libsystem_pthread.dylib       	0x000000010c7a88fc _pthread_start + 224
35  libsystem_pthread.dylib       	0x000000010c7a4443 thread_start + 15

As far as I can tell, this issue is triggered by closing the database directly after receiving a query change notification.

This might be related to https://github.com/couchbase/couchbase-lite-C/issues/209.

blaugold avatar Feb 24 '22 14:02 blaugold

As far as I can tell, this issue is triggered by closing the database directly after receiving a query change notification.

Is the database closed inside the CBLQueryChangeListener?

pasin avatar Feb 24 '22 16:02 pasin

No, the query change triggers a notification for a different thread on which CBLDatabase_Close is called.

blaugold avatar Feb 24 '22 16:02 blaugold

Jira : https://issues.couchbase.com/browse/CBL-2914

pasin avatar Mar 16 '22 20:03 pasin

I think I have figured out what is happening here.

  1. A live query notifies its listener of a change by calling the CBLListenerTokens callback. This is happening on the background thread of the live query. The notification goes through CBLDatabase::notify:

    https://github.com/couchbase/couchbase-lite-C/blob/f6d2b672b24be2508e83469c3d614d123a278517/src/CBLDatabase_Internal.hh#L248-L254

    Here, the CBLListenerToken is retained. Its ref count is now 2.

  2. The listener callback removes the CBLListenerToken. Its ref count is now 1. The listener token callback notifies another thread, which in turn closes the database.

  3. While the database is closing, it calls CBLDatabase::stopActiveStoppables. The database does not retain CBLStoppables. It just holds pointers.

  4. Concurrently with CBLDatabase::stopActiveStoppables, the listener callback returns and in CBLDatabase::notify the ref count of the ListenerToken is decremented to 0, causing the CBLListenerToken to be destroyed, possibly before CBLDatabase::stopActiveStoppables is able to get to the CBLListenerToken.

blaugold avatar Oct 15 '22 14:10 blaugold

Sorry for delay. I have jus had a chance to look at this issue.

The listener callback removes the ListenerToken. Its ref count is now 1. The listener token notifies another thread, which in turn closes the database.

Do you mean the CBLListener_Remove(CBLListenerToken*) is called at the same time?

pasin avatar Oct 28 '22 19:10 pasin

No problem :)

Do you mean the CBLListener_Remove(CBLListenerToken*) is called at the same time?

Ah, sorry. What I should have said is: The listener callback calls CBLListener_Remove, passing the CBLListenerToken. Its ref count is now 1. The listener callback (not token 🙉 ) notifies another thread, which in turn closes the database.

blaugold avatar Oct 28 '22 19:10 blaugold

@pasin I think there's a fix for this issue now, right?

blaugold avatar Nov 30 '22 14:11 blaugold

We have fixed the issue in helium (3.1) but the fix is pending to be port / merge into the lithium branch. How critical of this issue? Can you wait for 3.1?

pasin avatar Mar 15 '23 18:03 pasin

It's not critical and is more of an edge case that would be nice to have fixed eventually because it is making CI flake from time to time. So, it can wait for 3.1. 👍

blaugold avatar Mar 15 '23 18:03 blaugold

Fixed in 3.1. For now, it won't be ported

velicuvlad avatar May 30 '23 11:05 velicuvlad