Bug 3145

Summary: Memory corruption in imap_disconnect_all
Product: Claws Mail (GTK 2) Reporter: Aleksander Mazur <deweloper>
Component: OtherAssignee: users
Status: VERIFIED FIXED    
Severity: normal CC: jpgaulier, mail
Priority: P3    
Version: 3.9.3   
Hardware: PC   
OS: Linux   
Attachments:
Description Flags
Valgrind log (most errors are false positives - "optimized strlen" issue) none

Description Aleksander Mazur 2014-04-19 08:13:26 UTC
claws-mail-3.9.3-1.fc20.i686 crashed due to a memory leak. Here comes the backtrace:

Thread 1 (Thread 0xb7fcb900 (LWP 5052)):
#0  0xb7fff424 in __kernel_vsyscall ()
#1  0x47d21b96 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#2  0x47d233d3 in __GI_abort () at abort.c:89
#3  0x47d612f8 in __libc_message (do_abort=do_abort@entry=2, fmt=fmt@entry=0x47e6b614 "*** Error in `%s': %s: 0x%s ***\n") at ../sysdeps/posix/libc_fatal.c:175
#4  0x47d67b24 in malloc_printerr (action=<optimized out>, str=<optimized out>, ptr=0x900df08) at malloc.c:4930
#5  0x47d6a7c7 in _int_malloc (av=av@entry=0x47ead420 <main_arena>, bytes=bytes@entry=4336) at malloc.c:3547
#6  0x47d6c48b in __libc_calloc (n=1, elem_size=4336) at malloc.c:3187
#7  0x4806b52a in g_malloc0 (n_bytes=n_bytes@entry=4336) at gmem.c:134
#8  0x080e5ab2 in imap_session_new (account=0x86e84e8, folder=0x871cf20) at imap.c:1161
#9  imap_session_get (folder=folder@entry=0x871cf20) at imap.c:1013
#10 0x080e7698 in imap_scan_required (folder=0x871cf20, _item=0x871d930) at imap.c:4691
#11 0x080dc8ef in folderview_check_new (folder=0x871cf20) at folderview.c:1186
#12 0x080f7033 in inc_all_account_mail (mainwin=0x84d9ec8, autocheck=1, notify=0) at inc.c:360
#13 0x080f71fa in inc_autocheck_func (data=data@entry=0x84d9ec8) at inc.c:1493
#14 0x48066262 in g_timeout_dispatch (source=source@entry=0x880b438, callback=0x80f71d0 <inc_autocheck_func>, user_data=0x84d9ec8) at gmain.c:4451
#15 0x48065556 in g_main_dispatch (context=0x8497de0) at gmain.c:3066
#16 g_main_context_dispatch (context=context@entry=0x8497de0) at gmain.c:3642
#17 0x48065920 in g_main_context_iterate (context=0x8497de0, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3713
#18 0x48065dc3 in g_main_loop_run (loop=loop@entry=0x840a7e8) at gmain.c:3907
#19 0x4372d700 in IA__gtk_main () at gtkmain.c:1257
#20 0x080828cf in main (argc=1, argv=0xbffff214) at main.c:1551

The program was just running in the background, periodically (10 minutes) fetching mails from a few IMAP accounts. It has been up for several days, but most of the time the PC was suspended.
"fancy" plugin was active.
Comment 1 Michael Schwendt 2014-04-19 09:57:46 UTC
What makes you think it's a "memory leak"?

The backtrace (a crash in glibc memory management) looks very much like heap corruption caused by an earlier interruption of the IMAP session, which has been plagueing Claws Mail for a very long time ( https://bugzilla.redhat.com/1070480#c5 ). As such, the backtrace is rather useless because it doesn't tell what code had corrupted the memory prior to calling malloc.

#7  0x4806b52a in g_malloc0 (n_bytes=n_bytes@entry=4336) at gmem.c:134
#8  0x080e5ab2 in imap_session_new (account=0x86e84e8, folder=0x871cf20) at imap.c:1161
Comment 2 Aleksander Mazur 2014-04-19 17:45:47 UTC
OK, I misinterpreted intentional abort in malloc as a symptom of lack of memory what led me to a conclusion that this is a memory leak.

I've run claws-mail under valgrind instead of gdb and I spotted invalid writes (writing over an already released memory) under 2 circumstances:
1) unplugging and plugging ethernet cable
2) clicking offline/online switch
while claws-mail was in the middle of checking IMAP accounts.
I guess similar problem may occur when suspending/resuming machine.

==00:00:16:54.870 12568== Invalid write of size 4
==00:00:16:54.870 12568==    at 0x80E4305: unlock_session (imap.c:540)
==00:00:16:54.870 12568==    by 0x80E9B9F: imap_get_num_list (imap.c:4449)
==00:00:16:54.870 12568==    by 0x80CE79D: folder_item_scan_full (folder.c:2167)
==00:00:16:54.870 12568==    by 0x80D0F67: folder_item_scan (folder.c:2507)
==00:00:16:54.870 12568==    by 0x80DC9A6: folderview_check_new (folderview.c:1190)
==00:00:16:54.870 12568==    by 0x80F7032: inc_all_account_mail (inc.c:360)
==00:00:16:54.870 12568==    by 0x81D1AEF: toolbar_inc_all_cb (toolbar.c:2667)
==00:00:16:54.870 12568==    by 0x48187548: g_cclosure_marshal_VOID__VOIDv (gmarshal.c:115)
==00:00:16:54.870 12568==    by 0x48185A25: _g_closure_invoke_va (gclosure.c:840)
==00:00:16:54.870 12568==    by 0x4819FA82: g_signal_emit_valist (gsignal.c:3238)
==00:00:16:54.870 12568==    by 0x481A0B80: g_signal_emit_by_name (gsignal.c:3426)
==00:00:16:54.870 12568==    by 0x438264EB: button_clicked (gtktoolbutton.c:773)
==00:00:16:54.870 12568==  Address 0x4b68df4 is 4,324 bytes inside a block of size 4,336 free'd
==00:00:16:54.870 12568==    at 0x4007BCD: free (in /usr/lib/valgrind/vgpreload_memcheck-x86-linux.so)
==00:00:16:54.870 12568==    by 0x4806B631: g_free (gmem.c:197)
==00:00:16:54.870 12568==    by 0x8240004: session_destroy (session.c:237)
==00:00:16:54.870 12568==    by 0x80E6B7D: imap_disconnect_all (imap.c:5852)
==00:00:16:54.870 12568==    by 0x80FDD34: online_switch_clicked (mainwindow.c:4239)
==00:00:16:54.870 12568==    by 0x8109B1D: main_window_toggle_work_offline (mainwindow.c:4166)
==00:00:16:54.870 12568==    by 0x80FA4E1: networkmanager_state_change_cb (main.c:2822)
==00:00:16:54.871 12568==    by 0x481879CD: g_cclosure_marshal_VOID(unsigned intXX_t) (gmarshal.c:446)
==00:00:16:54.871 12568==    by 0x490575D8: marshal_dbus_message_to_g_marshaller (dbus-gproxy.c:1736)
==00:00:16:54.871 12568==    by 0x481857DD: g_closure_invoke (gclosure.c:777)
==00:00:16:54.871 12568==    by 0x4819856D: signal_emit_unlocked_R (gsignal.c:3586)
==00:00:16:54.871 12568==    by 0x481A03C0: g_signal_emit_valist (gsignal.c:3330)
==00:00:16:54.871 12568== 

It looks like the program destroys a session in direct response to an event while another thread still holds the pointer to that session and tries to use it (?)

Then I unplugged/plugged eth cable twice and application crashed with SIGSEGV.

==00:00:56:02.712 12568== Invalid write of size 4
==00:00:56:02.712 12568==    at 0x80E4971: imap_cmd_noop (imap.c:4027)
==00:00:56:02.712 12568==    by 0x80E5F5D: imap_ping (imap.c:559)
==00:00:56:02.712 12568==    by 0x48066261: g_timeout_dispatch (gmain.c:4451)
==00:00:56:02.712 12568==    by 0x48065555: g_main_context_dispatch (gmain.c:3066)
==00:00:56:02.712 12568==    by 0x4806591F: g_main_context_iterate.isra.23 (gmain.c:3713)
==00:00:56:02.712 12568==    by 0x480659E8: g_main_context_iteration (gmain.c:3774)
==00:00:56:02.712 12568==    by 0x4372D981: gtk_main_iteration (gtkmain.c:1345)
==00:00:56:02.712 12568==    by 0x822E5D4: threaded_run (imap-thread.c:440)
==00:00:56:02.712 12568==    by 0x8232071: imap_threaded_noop (imap-thread.c:1096)
==00:00:56:02.712 12568==    by 0x80E4942: imap_cmd_noop (imap.c:4016)
==00:00:56:02.712 12568==    by 0x80E5F5D: imap_ping (imap.c:559)
==00:00:56:02.712 12568==    by 0x48066261: g_timeout_dispatch (gmain.c:4451)
==00:00:56:02.712 12568==  Address 0xa0e294c is not stack'd, malloc'd or (recently) free'd
==00:00:56:02.712 12568== 
==00:00:56:02.712 12568== 
==00:00:56:02.712 12568== Process terminating with default action of signal 11 (SIGSEGV)
==00:00:56:02.712 12568==  Access not within mapped region at address 0x31202044
==00:00:56:02.712 12568==    at 0x82320D0: imap_threaded_noop (imap-thread.c:1113)
==00:00:56:02.712 12568==    by 0x80E4942: imap_cmd_noop (imap.c:4016)
==00:00:56:02.712 12568==    by 0x80E5F5D: imap_ping (imap.c:559)
==00:00:56:02.712 12568==    by 0x48066261: g_timeout_dispatch (gmain.c:4451)
==00:00:56:02.712 12568==    by 0x48065555: g_main_context_dispatch (gmain.c:3066)
==00:00:56:02.712 12568==    by 0x4806591F: g_main_context_iterate.isra.23 (gmain.c:3713)
==00:00:56:02.712 12568==    by 0x480659E8: g_main_context_iteration (gmain.c:3774)
==00:00:56:02.712 12568==    by 0x4372D981: gtk_main_iteration (gtkmain.c:1345)
==00:00:56:02.712 12568==    by 0x822E5D4: threaded_run (imap-thread.c:440)
==00:00:56:02.712 12568==    by 0x8232071: imap_threaded_noop (imap-thread.c:1096)
==00:00:56:02.712 12568==    by 0x80E4942: imap_cmd_noop (imap.c:4016)
==00:00:56:02.712 12568==    by 0x80E5F5D: imap_ping (imap.c:559)

I'll attach full valgrind memcheck log.
Comment 3 Aleksander Mazur 2014-04-19 17:50:14 UTC
Created attachment 1364 [details]
Valgrind log (most errors are false positives - "optimized strlen" issue)
Comment 4 Michael Schwendt 2014-04-19 18:47:35 UTC
Activating offline mode crash is bug 2769.
Comment 5 Colin Leroy 2014-04-21 07:48:25 UTC
*** Bug 3149 has been marked as a duplicate of this bug. ***
Comment 6 users 2014-04-21 08:02:53 UTC
Changes related to this bug have been committed.
Please check latest Git and update the bug accordingly.
You can also get the patch from:
http://git.claws-mail.org/

++ ChangeLog	2014-04-21 10:02:04.033851311 +0200
http://git.claws-mail.org/?p=claws.git;a=commitdiff;h=2588900ab245eec48f5ccc915b29581997038d6a
Merge: e857a07 7445f4f
Author: Colin Leroy <colin@colino.net>
Date:   Mon Apr 21 10:02:03 2014 +0200

    Merge branch 'master' of file:///home/git/claws

http://git.claws-mail.org/?p=claws.git;a=commitdiff;h=7445f4f8674ea0a02e4baff42342b0d9f7754114
Author: Colin Leroy <colin@colino.net>
Date:   Mon Apr 21 10:01:39 2014 +0200

    Fix bug #3150, "etpan_certificate_check() leaks memory"

http://git.claws-mail.org/?p=claws.git;a=commitdiff;h=46063c48ccc0d379e546946563e5047775d62640
Author: Colin Leroy <colin@colino.net>
Date:   Mon Apr 21 10:00:55 2014 +0200

    Fix bug #3148, "Logic error in claws_get_socket_name()"

http://git.claws-mail.org/?p=claws.git;a=commitdiff;h=f933992350613b35e5181fee532f1415e166fefb
Author: Colin Leroy <colin@colino.net>
Date:   Mon Apr 21 10:00:25 2014 +0200

    Fix bug #3147, "verify_folderlist_xml() leaks memory"

http://git.claws-mail.org/?p=claws.git;a=commitdiff;h=e240402b874071ffafe74aaffe60c177cb798567
Author: Colin Leroy <colin@colino.net>
Date:   Mon Apr 21 09:59:11 2014 +0200

    Fix bug #3146, "Memory corruption when deleting a message from folder"
    Reference msginfo before passing to the mark_as_read_timeout deferred
    callback.

http://git.claws-mail.org/?p=claws.git;a=commitdiff;h=f69b3bab9d66372a56e19867f458c3012aefd141
Author: Colin Leroy <colin@colino.net>
Date:   Mon Apr 21 09:57:52 2014 +0200

    Fix bug #3145, "Memory corruption in imap_disconnect_all"
Comment 7 Colin Leroy 2014-04-26 09:35:48 UTC
*** Bug 1809 has been marked as a duplicate of this bug. ***
Comment 8 Aleksander Mazur 2014-04-27 08:05:54 UTC
Cannot reproduce using claws-mail a9065aec26499a0e1294c73b6d9e6f039976521e.
When I go offline during IMAP activity, claws-mail prints dangerously looking messages:
(claws-mail:6957): Claws-Mail-CRITICAL **: imap_scan_required: assertion 'session != NULL' failed
but it neither crashes nor corrupts memory anymore.
Comment 9 Colin Leroy 2014-05-22 20:55:54 UTC
*** Bug 2926 has been marked as a duplicate of this bug. ***