RealmTasks macOS 100% CPU consumption

[gritzko]

Once a Task is created by another app and comes to the macOS app through sync, the app starts consuming 100% CPU and never stops doing so. Otherwise works normally. The iOS version does not display such a behavior. Albeit, for the duration of syncing it eats up 100% CPU too (that takes several seconds, if some changes accumulated while offline).

[stel]

I noticed that behavior a couple of times but wasn't able to reproduce it constantly. Here is (probably) related crash stack trace from our conversation in Slack:

#0  0x0000000100dddd53 in specialized _assertionFailed(StaticString, String, StaticString, UInt) -> () ()
#1  0x0000000100cbe90b in swift_unexpectedError ()
#2  0x000000010002fcb3 in ((setDefaultRealmConfigurationWithUser in _FBB928AAD0AD5DB76504FB1C8E7E219B)(RLMSyncUser) -> ()).(closure #2).(closure #1) at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/RealmTasks Shared/SharedFunctionality.swift:52
#3  0x000000010000e347 in thunk ()
#4  0x00000001011d66e5 in _dispatch_call_block_and_release ()
#5  0x00000001011ccf5c in _dispatch_client_callout ()
#6  0x00000001011e4a59 in _dispatch_queue_serial_drain ()
#7  0x00000001011d6489 in _dispatch_queue_invoke ()
#8  0x00000001011dd707 in _dispatch_queue_override_invoke ()
#9  0x00000001011cf1d7 in _dispatch_root_queue_drain ()
#10 0x00000001011ceee8 in _dispatch_worker_thread3 ()
#11 0x000000010124489a in _pthread_wqthread ()
#12 0x0000000101244375 in start_wqthread ()
Enqueued from com.apple.main-thread (Thread 1)Queue : com.apple.main-thread (serial)
#0  0x00000001011e35e4 in _dispatch_queue_push ()
#1  0x000000010002fa0e in ((setDefaultRealmConfigurationWithUser in _FBB928AAD0AD5DB76504FB1C8E7E219B)(RLMSyncUser) -> ()).(closure #2) at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/RealmTasks Shared/SharedFunctionality.swift:65
#2  0x0000000100b7ad22 in Realm.(addNotificationBlock((notification : Notification, realm : Realm) -> ()) -> RLMNotificationToken).(closure #1) at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/Pods/RealmSwift/RealmSwift/Realm.swift:1170
#3  0x0000000100b7b54b in partial apply for Realm.(addNotificationBlock((notification : Notification, realm : Realm) -> ()) -> RLMNotificationToken).(closure #1) ()
#4  0x0000000100b7b08f in thunk ()
#5  0x00000001003f88f9 in -[RLMRealm sendNotifications:] at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/Pods/Realm/Realm/RLMRealm.mm:419
#6  0x00000001004057fc in (anonymous namespace)::RLMNotificationHelper::did_change(std::__1::vector<realm::BindingContext::ObserverState, std::__1::allocator<realm::BindingContext::ObserverState> > const&, std::__1::vector<void*, std::__1::allocator<void*> > const&, bool) at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/Pods/Realm/Realm/RLMRealmUtil.mm:119
#7  0x00000001004b7d92 in (anonymous namespace)::TransactLogObserver::TransactLogObserver<realm::_impl::transaction::advance(realm::SharedGroup&, realm::BindingContext*, realm::SchemaMode, realm::_impl::NotifierPackage&)::$_1>(realm::BindingContext*, realm::SharedGroup&, realm::_impl::transaction::advance(realm::SharedGroup&, realm::BindingContext*, realm::SchemaMode, realm::_impl::NotifierPackage&)::$_1&&, realm::util::Optional<realm::SchemaMode>, realm::_impl::NotifierPackage&) at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/Pods/Realm/Realm/ObjectStore/src/impl/transact_log_handler.cpp:280
#8  0x00000001004a04f5 in (anonymous namespace)::TransactLogObserver::TransactLogObserver<realm::_impl::transaction::advance(realm::SharedGroup&, realm::BindingContext*, realm::SchemaMode, realm::_impl::NotifierPackage&)::$_1>(realm::BindingContext*, realm::SharedGroup&, realm::_impl::transaction::advance(realm::SharedGroup&, realm::BindingContext*, realm::SchemaMode, realm::_impl::NotifierPackage&)::$_1&&, realm::util::Optional<realm::SchemaMode>, realm::_impl::NotifierPackage&) at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/Pods/Realm/Realm/ObjectStore/src/impl/transact_log_handler.cpp:262
#9  0x00000001004a04aa in realm::_impl::transaction::advance(realm::SharedGroup&, realm::BindingContext*, realm::SchemaMode, realm::_impl::NotifierPackage&) at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/Pods/Realm/Realm/ObjectStore/src/impl/transact_log_handler.cpp:829
#10 0x000000010026643c in realm::_impl::RealmCoordinator::advance_to_ready(realm::Realm&) at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/Pods/Realm/Realm/ObjectStore/src/impl/realm_coordinator.cpp:669
#11 0x0000000100449171 in realm::Realm::notify() at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/Pods/Realm/Realm/ObjectStore/src/shared_realm.cpp:572
#12 0x00000001004d8d8b in realm::_impl::WeakRealmNotifier::Callback::operator()() at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/Pods/Realm/Realm/ObjectStore/src/impl/weak_realm_notifier.cpp:40
#13 0x00000001004d9bfc in realm::util::EventLoopSignal<realm::_impl::WeakRealmNotifier::Callback>::EventLoopSignal(realm::_impl::WeakRealmNotifier::Callback&&)::'lambda'(void*)::operator()(void*) const at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/Pods/Realm/include/util/apple/event_loop_signal.hpp:37
#14 0x00000001004d9bd8 in realm::util::EventLoopSignal<realm::_impl::WeakRealmNotifier::Callback>::EventLoopSignal(realm::_impl::WeakRealmNotifier::Callback&&)::'lambda'(void*)::__invoke(void*) at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/Pods/Realm/include/util/apple/event_loop_signal.hpp:36
#15 0x00007fffc0833981 in __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ ()
#16 0x00007fffc0814a7d in __CFRunLoopDoSources0 ()
#17 0x00007fffc0813f76 in __CFRunLoopRun ()
#18 0x00007fffc0813974 in CFRunLoopRunSpecific ()
#19 0x00007fffbfd9facc in RunCurrentEventLoopInMode ()
#20 0x00007fffbfd9f901 in ReceiveNextEventCommon ()
#21 0x00007fffbfd9f736 in _BlockUntilNextEventMatchingListInModeWithFilter ()
#22 0x00007fffbe345ae4 in _DPSNextEvent ()
#23 0x00007fffbeac021f in -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] ()
#24 0x00007fffbe33a465 in -[NSApplication run] ()
#25 0x00007fffbe304d80 in NSApplicationMain ()
#26 0x000000010002a6a4 in main at /Users/gritzko/Projects/RealmTasks/RealmTasks Apple/RealmTasks macOS/AppDelegate.swift:25
#27 0x00007fffd5d6c255 in start ()

[gritzko]

Weight Self Weight Symbol Name 16.23 s 100.0% 0 s RealmTasks (15153) 6.70 s 41.2% 0 s _dispatch_worker_thread3 0x66303 6.70 s 41.2% 0 s start_wqthread 6.70 s 41.2% 0 s _pthread_wqthread 6.70 s 41.2% 0 s _dispatch_worker_thread3 6.70 s 41.2% 0 s _dispatch_root_queue_drain 6.30 s 38.7% 0 s _dispatch_queue_override_invoke 6.29 s 38.7% 2.00 ms _dispatch_queue_invoke 6.27 s 38.5% 7.00 ms _dispatch_queue_serial_drain 6.26 s 38.5% 0 s _dispatch_client_callout 6.25 s 38.5% 0 s _dispatch_call_block_and_release 6.25 s 38.4% 1.00 ms (setDefaultRealmConfigurationWithUser(RLMSyncUser) -> ()).(closure #2).(closure #1) 4.51 s 27.7% 1.00 ms Realm.write(() throws -> ()) throws -> () 4.16 s 25.6% 0 s -[RLMRealm commitWriteTransactionWithoutNotifying:error:] 4.15 s 25.5% 1.00 ms realm::_impl::RealmCoordinator::commit_write(realm::Realm&) 4.06 s 24.9% 0 s realm::SharedGroup::commit_and_continue_as_read() 4.04 s 24.9% 0 s realm::SharedGroup::do_commit() 3.95 s 24.3% 13.00 ms realm::SharedGroup::low_level_commit(unsigned long long) 3.52 s 21.7% 11.00 ms realm::GroupWriter::commit(unsigned long) 3.51 s 21.6% 5.00 ms realm::util::msync(void*, unsigned long) 3.51 s 21.5% 3.51 s __msync

Apparently, a thread or two keep calling realm::util::msync

[gritzko]

either the core is called repeatedly or it goes into a loop committing a transaction

[gritzko]

maybe @morten-krogh has some idea

[jpsim]

__msync is a system call combining both writing and flushing to disk. So the bulk of the time being spent there indicates that there's a lot of data being written. If you've created lots of data, then there's nothing too surprising here. If you've only created a small amount of data in the apps, and you're seeing 3-4 seconds of msync, that could indicate a problem. I think this is more @finnschiermer's expertise.