GNOME Bugzilla – Bug 770476
Crash on exit in object_bag_notify()
Last modified: 2021-05-19 11:04:08 UTC
Created attachment 334266 [details] Backtrace. Exited Evolution with a couple of tasks running (opening a folder, global body search), and the main window went away successfully. However, it got stuck and the process never exited. Main thread seems to be stuck on a mutex in object_bag_notify().
Looks like this happens because the object bag was destroyed, but a weak ref it held stuck around and caused a notify to be sent to the dead bag. (gdb)
+ Trace 236594
$1 = {key_table = 0x0, object_table = 0x0, key_equal_func = 0x0, key_copy_func = 0x0, key_free_func = 0x0, reserved = 0x0, mutex = {p = 0x2, i = {2, 0}}}
The weak ref management in CamelObjectBag looks ok, but I wonder if there might be a problem if the bag is destroyed in one thread while a weak ref notify is being generated in another. There doesn't seem to be anything stopping the notify from arriving after the bag is fully destroyed, even if the bag is clearing its refs in the destroy method.
Thanks for a bug report. I also do not see anything obvious in the CamelObjectBag code. I guess this is about use-after-free, but even that I do not see how it could happen directly in this code, thus I guess a memory corruption after using something freed. Are you able to reproduce this reliably? What if you try valgrind? My valgrind command looks like this usually: $ G_SLICE=always-malloc valgrind evolution &>log.txt
I have G_DEBUG=gc-friendly and G_SLICE=always-malloc set in .bashrc. I think the former may be why I'm seeing some bugs you don't; memory gets cleared on free. In this case, it looks like the mutex' memory gets cleared when the object bag is freed, and when the notify comes in, it hangs on the cleared mutex struct. I also think it's a race -- I have only seen it once or twice among dozens of Evo shutdowns. Based on code inspection, what I think happens is this: - Thread A: Containee gets added to bag, bag adds weak ref. - Thread A: Containee gets disposed, weak ref notify is triggered but not yet delivered. - Thread B: Bag gets destroyed and freed, mutex memory is cleared (G_DEBUG=gc-friendly). - Thread A: Weak ref notify arrives, bag code tries to lock mutex; hangs.
I also use G_DEBUG=gc-friendly, but I do not use G_SLICE=always-malloc. I use it only when I run the code under valgrind. Your code inspection is scary, if that can happen. The weak-ref notifies, like other signals, are delivered synchronously, within the thread which frees the object (unrefs its last reference), as far as I know.
Triggered it again, this time under Valgrind. I was hoping to see where the object bag was freed, but alas, Valgrind couldn't figure it out. It only says "unallocated block". ==3074== Thread 1: ==3074== Invalid read of size 4 ==3074== at 0x10724E7D: g_mutex_lock (gthread-posix.c:1336) ==3074== by 0x5B7B81B: object_bag_notify (camel-object-bag.c:122) ==3074== by 0x1043EE37: weak_refs_notify (gobject.c:2638) ==3074== by 0x106AEC51: g_data_set_internal (gdataset.c:407) ==3074== by 0x106AF10A: g_datalist_id_set_data_full (gdataset.c:670) ==3074== by 0x1043AED3: g_object_real_dispose (gobject.c:1032) ==3074== by 0x1043FB8A: g_object_unref (gobject.c:3148) ==3074== by 0x23E31D95: store_info_unref (mail-folder-cache.c:343) ==3074== by 0x106BB2DC: g_hash_table_remove_all_nodes.part.5 (ghash.c:520) ==3074== by 0x106BBF02: g_hash_table_remove_all_nodes (ghash.c:1519) ==3074== by 0x106BBF02: g_hash_table_remove_all (ghash.c:1522) ==3074== by 0x23E3290C: mail_folder_cache_dispose (mail-folder-cache.c:1395) ==3074== by 0x1043FB8A: g_object_unref (gobject.c:3148) ==3074== by 0x23E2B56F: mail_session_dispose (e-mail-session.c:946) ==3074== by 0x1043FB8A: g_object_unref (gobject.c:3148) ==3074== by 0x236F5A72: mail_backend_dispose (e-mail-backend.c:1004) ==3074== by 0x1043FB8A: g_object_unref (gobject.c:3148) ==3074== by 0x1069A7E7: g_ptr_array_foreach (garray.c:1502) ==3074== by 0x10699DA5: ptr_array_free (garray.c:1088) ==3074== by 0x10699CD6: g_ptr_array_unref (garray.c:1036) ==3074== by 0x106AE926: g_datalist_clear (gdataset.c:273) ==3074== by 0x1043AF3E: g_object_finalize (gobject.c:1044) ==3074== by 0x1010715E: g_application_finalize (gapplication.c:1276) ==3074== by 0x1043FC86: g_object_unref (gobject.c:3185) ==3074== by 0x404853: main (main.c:673) ==3074== Address 0x1f9e9690 is 688 bytes inside an unallocated block of size 704 in arena "client" ==3074== Invalid read of size 8 ==3074== at 0x5B7B81C: object_bag_notify (camel-object-bag.c:124) ==3074== by 0x1043EE37: weak_refs_notify (gobject.c:2638) ==3074== by 0x106AEC51: g_data_set_internal (gdataset.c:407) ==3074== by 0x106AF10A: g_datalist_id_set_data_full (gdataset.c:670) ==3074== by 0x1043AED3: g_object_real_dispose (gobject.c:1032) ==3074== by 0x1043FB8A: g_object_unref (gobject.c:3148) ==3074== by 0x23E31D95: store_info_unref (mail-folder-cache.c:343) ==3074== by 0x106BB2DC: g_hash_table_remove_all_nodes.part.5 (ghash.c:520) ==3074== by 0x106BBF02: g_hash_table_remove_all_nodes (ghash.c:1519) ==3074== by 0x106BBF02: g_hash_table_remove_all (ghash.c:1522) ==3074== by 0x23E3290C: mail_folder_cache_dispose (mail-folder-cache.c:1395) ==3074== by 0x1043FB8A: g_object_unref (gobject.c:3148) ==3074== by 0x23E2B56F: mail_session_dispose (e-mail-session.c:946) ==3074== by 0x1043FB8A: g_object_unref (gobject.c:3148) ==3074== by 0x236F5A72: mail_backend_dispose (e-mail-backend.c:1004) ==3074== by 0x1043FB8A: g_object_unref (gobject.c:3148) ==3074== by 0x1069A7E7: g_ptr_array_foreach (garray.c:1502) ==3074== by 0x10699DA5: ptr_array_free (garray.c:1088) ==3074== by 0x10699CD6: g_ptr_array_unref (garray.c:1036) ==3074== by 0x106AE926: g_datalist_clear (gdataset.c:273) ==3074== by 0x1043AF3E: g_object_finalize (gobject.c:1044) ==3074== by 0x1010715E: g_application_finalize (gapplication.c:1276) ==3074== by 0x1043FC86: g_object_unref (gobject.c:3185) ==3074== by 0x404853: main (main.c:673) ==3074== Address 0x1f9e9660 is 640 bytes inside an unallocated block of size 704 in arena "client" (evolution:3074): GLib-CRITICAL **: g_hash_table_lookup: assertion 'hash_table != NULL' failed ==3074== Invalid read of size 4 ==3074== at 0x10724EAB: g_mutex_unlock (gthread-posix.c:1345) ==3074== by 0x1043EE37: weak_refs_notify (gobject.c:2638) ==3074== by 0x106AEC51: g_data_set_internal (gdataset.c:407) ==3074== by 0x106AF10A: g_datalist_id_set_data_full (gdataset.c:670) ==3074== by 0x1043AED3: g_object_real_dispose (gobject.c:1032) ==3074== by 0x1043FB8A: g_object_unref (gobject.c:3148) ==3074== by 0x23E31D95: store_info_unref (mail-folder-cache.c:343) ==3074== by 0x106BB2DC: g_hash_table_remove_all_nodes.part.5 (ghash.c:520) ==3074== by 0x106BBF02: g_hash_table_remove_all_nodes (ghash.c:1519) ==3074== by 0x106BBF02: g_hash_table_remove_all (ghash.c:1522) ==3074== by 0x23E3290C: mail_folder_cache_dispose (mail-folder-cache.c:1395) ==3074== by 0x1043FB8A: g_object_unref (gobject.c:3148) ==3074== by 0x23E2B56F: mail_session_dispose (e-mail-session.c:946) ==3074== by 0x1043FB8A: g_object_unref (gobject.c:3148) ==3074== by 0x236F5A72: mail_backend_dispose (e-mail-backend.c:1004) ==3074== by 0x1043FB8A: g_object_unref (gobject.c:3148) ==3074== by 0x1069A7E7: g_ptr_array_foreach (garray.c:1502) ==3074== by 0x10699DA5: ptr_array_free (garray.c:1088) ==3074== by 0x10699CD6: g_ptr_array_unref (garray.c:1036) ==3074== by 0x106AE926: g_datalist_clear (gdataset.c:273) ==3074== by 0x1043AF3E: g_object_finalize (gobject.c:1044) ==3074== by 0x1010715E: g_application_finalize (gapplication.c:1276) ==3074== by 0x1043FC86: g_object_unref (gobject.c:3185) ==3074== by 0x404853: main (main.c:673) ==3074== Address 0x1f9e9690 is 688 bytes inside an unallocated block of size 704 in arena "client"
Ouch, I missed your reply for some odd reason. I'm sorry about that. I just hit the same issue and it's as you said, the object bag is already freed. My valgrind output says: Invalid read of size 4 at 0x10EB8875: g_mutex_lock (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x6D6F09B: object_bag_notify (camel-object-bag.c:122) by 0x10BE9F7E: ??? (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x10BEB095: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x6DA3F84: vee_folder_dispose (camel-vee-folder.c:571) by 0x10BEB095: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x2C6805F5: store_info_unref (mail-folder-cache.c:343) by 0x10E611F9: ??? (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E62042: g_hash_table_remove_all by 0x2C68116C: mail_folder_cache_dispose (mail-folder-cache.c:1395) by 0x10BEB095: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x2C67999F: mail_session_dispose (e-mail-session.c:946) Address 0x2a89be80 is 48 bytes inside a block of size 56 free'd at 0x4C2ED4A: free (vg_replace_malloc.c:530) by 0x10E786CD: g_free (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E9121F: g_slice_free1 (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x6D8F149: store_finalize (camel-store.c:351) by 0x10BEB116: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x108CC7C9: ??? (in /usr/lib64/libgio-2.0.so.0.5000.3) by 0x10BEB116: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x108CD19C: ??? (in /usr/lib64/libgio-2.0.so.0.5000.3) by 0x10E9B58D: ??? (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E9AB92: ??? (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x94A76C9: start_thread (in /usr/lib64/libpthread-2.24.so) by 0x11243F7E: clone (in /usr/lib64/libc-2.24.so) Block was alloc'd at at 0x4C2DB9D: malloc (vg_replace_malloc.c:299) by 0x10E785B8: g_malloc (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E90B12: g_slice_alloc (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E9113D: g_slice_alloc0 (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x6D6F295: camel_object_bag_new (camel-object-bag.c:191) by 0x6D8F0CB: store_constructed (camel-store.c:378) by 0x6D724C2: offline_store_constructed (camel-offline-store.c:63) by 0x10BEBC16: ??? (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x10BED5AD: g_object_new_valist by 0x108A3055: g_initable_new_valist (in /usr/lib64/libgio-2.0.so.0.5000.3) by 0x108A3115: g_initable_new (in /usr/lib64/libgio-2.0.so.0.5000.3) by 0x6D84D8E: session_add_service (camel-session.c:450) Invalid read of size 8 at 0x6D6F09C: object_bag_notify (camel-object-bag.c:124) by 0x10BE9F7E: ??? (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x10BEB095: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x6DA3F84: vee_folder_dispose (camel-vee-folder.c:571) by 0x10BEB095: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x2C6805F5: store_info_unref (mail-folder-cache.c:343) by 0x10E611F9: ??? (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E62042: g_hash_table_remove_all by 0x2C68116C: mail_folder_cache_dispose (mail-folder-cache.c:1395) by 0x10BEB095: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x2C67999F: mail_session_dispose (e-mail-session.c:946) by 0x10BEB095: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) Address 0x2a89be50 is 0 bytes inside a block of size 56 free'd at 0x4C2ED4A: free (vg_replace_malloc.c:530) by 0x10E786CD: g_free (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E9121F: g_slice_free1 (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x6D8F149: store_finalize (camel-store.c:351) by 0x10BEB116: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x108CC7C9: ??? (in /usr/lib64/libgio-2.0.so.0.5000.3) by 0x10BEB116: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x108CD19C: ??? (in /usr/lib64/libgio-2.0.so.0.5000.3) by 0x10E9B58D: ??? (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E9AB92: ??? (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x94A76C9: start_thread (in /usr/lib64/libpthread-2.24.so) by 0x11243F7E: clone (in /usr/lib64/libc-2.24.so) Block was alloc'd at at 0x4C2DB9D: malloc (vg_replace_malloc.c:299) by 0x10E785B8: g_malloc (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E90B12: g_slice_alloc (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E9113D: g_slice_alloc0 (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x6D6F295: camel_object_bag_new (camel-object-bag.c:191) by 0x6D8F0CB: store_constructed (camel-store.c:378) by 0x6D724C2: offline_store_constructed (camel-offline-store.c:63) by 0x10BEBC16: ??? (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x10BED5AD: g_object_new_valist by 0x108A3055: g_initable_new_valist (in /usr/lib64/libgio-2.0.so.0.5000.3) by 0x108A3115: g_initable_new (in /usr/lib64/libgio-2.0.so.0.5000.3) by 0x6D84D8E: session_add_service (camel-session.c:450) Invalid read of size 4 at 0x10E61B5C: g_hash_table_lookup (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x6D6F0A6: object_bag_notify (camel-object-bag.c:124) by 0x10BE9F7E: ??? (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x10BEB095: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x6DA3F84: vee_folder_dispose (camel-vee-folder.c:571) by 0x10BEB095: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x2C6805F5: store_info_unref (mail-folder-cache.c:343) by 0x10E611F9: ??? (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E62042: g_hash_table_remove_all by 0x2C68116C: mail_folder_cache_dispose (mail-folder-cache.c:1395) by 0x10BEB095: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x2C67999F: mail_session_dispose (e-mail-session.c:946) Address 0x2a8eb240 is 64 bytes inside a block of size 88 free'd at 0x4C2ED4A: free (vg_replace_malloc.c:530) by 0x10E786CD: g_free (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E9121F: g_slice_free1 (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x6D6FCDB: camel_object_bag_destroy (camel-object-bag.c:608) by 0x6D8F149: store_finalize (camel-store.c:351) by 0x10BEB116: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x108CC7C9: ??? (in /usr/lib64/libgio-2.0.so.0.5000.3) by 0x10BEB116: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x108CD19C: ??? (in /usr/lib64/libgio-2.0.so.0.5000.3) by 0x10E9B58D: ??? (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E9AB92: ??? (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x94A76C9: start_thread (in /usr/lib64/libpthread-2.24.so) Block was alloc'd at at 0x4C2DB9D: malloc (vg_replace_malloc.c:299) by 0x10E785B8: g_malloc (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E90B12: g_slice_alloc (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E6172D: g_hash_table_new_full (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x6D6F270: camel_object_bag_new (camel-object-bag.c:184) by 0x6D8F0CB: store_constructed (camel-store.c:378) by 0x6D724C2: offline_store_constructed (camel-offline-store.c:63) by 0x10BEBC16: ??? (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x10BED5AD: g_object_new_valist by 0x108A3055: g_initable_new_valist (in /usr/lib64/libgio-2.0.so.0.5000.3) by 0x108A3115: g_initable_new (in /usr/lib64/libgio-2.0.so.0.5000.3) by 0x6D84D8E: session_add_service (camel-session.c:450) ** GLib:ERROR:ghash.c:373:g_hash_table_lookup_node: assertion failed: (hash_table->ref_count > 0) Process terminating with default action of signal 6 (SIGABRT): dumping core at 0x1117191F: raise (in /usr/lib64/libc-2.24.so) by 0x11173519: abort (in /usr/lib64/libc-2.24.so) by 0x10E99D54: g_assertion_message (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x10E99DE9: g_assertion_message_expr by 0x10E61C7D: g_hash_table_lookup (in /usr/lib64/libglib-2.0.so.0.5000.3) by 0x6D6F0A6: object_bag_notify (camel-object-bag.c:124) by 0x10BE9F7E: ??? (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x10BEB095: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x6DA3F84: vee_folder_dispose (camel-vee-folder.c:571) by 0x10BEB095: g_object_unref (in /usr/lib64/libgobject-2.0.so.0.5000.3) by 0x2C6805F5: store_info_unref (mail-folder-cache.c:343) by 0x10E611F9: ??? (in /usr/lib64/libglib-2.0.so.0.5000.3) and it didn't hang, but simply crashed here. That's with evolution-3.22.6-2.fc25.x86_64 evolution-data-server-3.22.7-2.fc25.x86_64
The problem was the the object bag in question had been freed in the finalize() function, but GWeakRef "calls the inner object NULL" right after the dispose() function, thus the attempt to unregister the object_bag_notify() weak-ref callback didn't happen, due to the GWeakRef returning NULL. Moving the object bag free into the CamelStore's dispose() function makes the trick. The patch itself is slightly longer, due to added some safety checks around the bag usage (some places had those checks, but most of them do not). Created commit 51fa0c4 in eds master (3.25.3+) Created commit 99f6d33 in eds gnome-3-24 (3.24.3+)
*** Bug 792223 has been marked as a duplicate of this bug. ***
The bug #792223 reports quite the same crash from 3.26.3, thus it seems the above change didn't fix everything. I'm reopening this bug report for further investigation. Having a reproducer from 3.26.x would be very helpful.
GNOME is going to shut down bugzilla.gnome.org in favor of gitlab.gnome.org. As part of that, we are mass-closing older open tickets in bugzilla.gnome.org which have not seen updates for a longer time (resources are unfortunately quite limited so not every ticket can get handled). If you can still reproduce the situation described in this ticket in a recent and supported software version, then please follow https://wiki.gnome.org/Community/GettingInTouch/BugReportingGuidelines and create a new ticket at https://gitlab.gnome.org/GNOME/evolution-data-server/-/issues/ Thank you for your understanding and your help.