[Evolution-hackers] Finding memory leaks in EWS with Valgrind

[David Woodhouse <dwmw2 infradead org>]

I started testing under Valgrind and fixed a bunch of memory leaks...
and now someone has introduced some more :)

Note that you have to use 'GSLICE=always-malloc' when testing for memory
leaks, because otherwise the glib internal pool allocator will confuse
valgrind.

I tend to ignore the 'probably lost' reports, and focus only on
'definitely lost'. For an explanation, see
http://valgrind.org/docs/manual/mc-manual.html#mc-manual.leaks

Here are a few things I found last night by running
 GSLICE=always-malloc EWS_DEBUG=2 valgrind --leak-check=full evolution

Note that you should also run e-calendar-factory and/or
e-addressbook-factory under valgrind, if you've been modifying that
code.

> ==28239== 18 bytes in 1 blocks are definitely lost in loss record 4,128 of 14,587
> ==28239==    at 0x4A05E46: malloc (vg_replace_malloc.c:195)
> ==28239==    by 0x3B6A048B52: g_malloc (gmem.c:164)
> ==28239==    by 0x3B6A06101D: g_strdup (gstrfuncs.c:102)
> ==28239==    by 0x4C6B310: summary_header_to_db (camel-folder-summary.c:299)
> ==28239==    by 0x1693E56A: summary_header_to_db (camel-ews-summary.c:191)
> ==28239==    by 0x4C6BCE2: camel_folder_summary_header_save_to_db (camel-folder-summary.c:2332)
> ==28239==    by 0x4C7144A: camel_folder_summary_save_to_db (camel-folder-summary.c:2253)
> ==28239==    by 0x16939E3F: ews_refresh_info_sync (camel-ews-folder.c:778)
> ==28239==    by 0x4C78C99: camel_folder_refresh_info (camel-folder.c:1156)
> ==28239==    by 0x33B6E857E5: refresh_folders_exec (mail-send-recv.c:912)
> ==28239==    by 0x33B6E7F0F7: mail_msg_proxy (mail-mt.c:469)
> ==28239==    by 0x3B6A06BBC3: g_thread_pool_thread_proxy (gthreadpool.c:319)

Not our fault; this is a leak which is already fixed in Evo HEAD by commit 
10aa841f3110a4f7084a35cbaaac1c211eb460e1

> ==28239== 41 bytes in 1 blocks are definitely lost in loss record 7,547 of 14,587
> ==28239==    at 0x4A05E46: malloc (vg_replace_malloc.c:195)
> ==28239==    by 0x3B6A048B52: g_malloc (gmem.c:164)
> ==28239==    by 0x3B6A06101D: g_strdup (gstrfuncs.c:102)
> ==28239==    by 0x1693E72A: message_info_from_db (camel-ews-summary.c:229)
> ==28239==    by 0x4C71978: camel_read_mir_callback (camel-folder-summary.c:1941)
> ==28239==    by 0x3B7CC5A778: sqlite3_exec (sqlite3.c:76874)
> ==28239==    by 0x33B1E2551C: camel_db_select (camel-db.c:963)
> ==28239==    by 0x33B1E2658D: camel_db_read_message_info_record_with_uid (camel-db.c:1893)
> ==28239==    by 0x4C72546: message_info_from_uid (camel-folder-summary.c:1276)
> ==28239==    by 0x169395EE: sync_updated_items (camel-ews-folder.c:576)
> ==28239==    by 0x16939D71: ews_refresh_info_sync (camel-ews-folder.c:763)
> ==28239==    by 0x4C78C99: camel_folder_refresh_info (camel-folder.c:1156)

camel_ews_summary:229 is setting ->change_key on a CamelEwsMessageInfo
structure. I thought I'd already fixed this class of leak by setting up
the free_message_info method in our summary class (commit 17bd52739), so
I'm not entirely sure what's going on here. Will investigate.

> ==28239== 41 bytes in 1 blocks are definitely lost in loss record 7,548 of 14,587
> ==28239==    at 0x4A05E46: malloc (vg_replace_malloc.c:195)
> ==28239==    by 0x3B6A048B52: g_malloc (gmem.c:164)
> ==28239==    by 0x3B6A06101D: g_strdup (gstrfuncs.c:102)
> ==28239==    by 0x1693E72A: message_info_from_db (camel-ews-summary.c:229)
> ==28239==    by 0x4C71978: camel_read_mir_callback (camel-folder-summary.c:1941)
> ==28239==    by 0x3B7CC5A778: sqlite3_exec (sqlite3.c:76874)
> ==28239==    by 0x33B1E2551C: camel_db_select (camel-db.c:963)
> ==28239==    by 0x33B1E2660C: camel_db_read_message_info_records (camel-db.c:1915)
> ==28239==    by 0x4C71559: camel_folder_summary_prepare_fetch_all (camel-folder-summary.c:1740)
> ==28239==    by 0x4C7327A: camel_folder_thread_messages_new (camel-folder-thread.c:619)
> ==28239==    by 0x33B6E8E0A5: regen_list_exec (message-list.c:4523)
> ==28239==    by 0x33B6E7F0F7: mail_msg_proxy (mail-mt.c:469)

Essentially the same as above.

> ==28239== 110 bytes in 22 blocks are definitely lost in loss record 11,022 of 14,587
> ==28239==    at 0x4A05E46: malloc (vg_replace_malloc.c:195)
> ==28239==    by 0x3B6A048B52: g_malloc (gmem.c:164)
> ==28239==    by 0x3B6A06101D: g_strdup (gstrfuncs.c:102)
> ==28239==    by 0x16520929: e_soap_parameter_get_string_value (e-soap-response.c:351)
> ==28239==    by 0x1651CB82: e_ews_item_mailbox_from_soap_param (e-ews-item.c:757)
> ==28239==    by 0x1651B987: e_ews_item_set_from_soap_parameter (e-ews-item.c:505)
> ==28239==    by 0x1651BB9C: e_ews_item_new_from_soap_parameter (e-ews-item.c:536)
> ==28239==    by 0x16514564: get_items_response_cb (e-ews-connection.c:541)
> ==28239==    by 0x1651413C: ews_response_cb (e-ews-connection.c:425)
> ==28239==    by 0x313AE3A119: process_queue_item (soup-session-async.c:383)
> ==28239==    by 0x313AE3A37C: run_queue (soup-session-async.c:418)
> ==28239==    by 0x313AE3A9D2: idle_run_queue (soup-session-async.c:443)

e-ews-item.c:757 is a blatant memory leak:
	if (g_ascii_strcasecmp (e_soap_parameter_get_string_value (subparam), "SMTP"))

It's *always* going to leak the string returned from e_soap_parameter_get_string_value().

[dwmw2@macbook evolution-ews]$ git blame src/server/e-ews-item.c | grep \"SMTP\"
cfb0c668 (Mandy Wu             2011-04-11 16:37:01 +0800 757) 	if (g_ascii_strcasecmp (e_soap_parameter_get_string_value (subparam), "SMTP"))

Bad Mandy. No biscuit.

> ==28239== 115 bytes in 23 blocks are definitely lost in loss record 11,112 of 14,587
> ==28239==    at 0x4A05E46: malloc (vg_replace_malloc.c:195)
> ==28239==    by 0x3B6A048B52: g_malloc (gmem.c:164)
> ==28239==    by 0x3B6A06101D: g_strdup (gstrfuncs.c:102)
> ==28239==    by 0x16520929: e_soap_parameter_get_string_value (e-soap-response.c:351)
> ==28239==    by 0x1651CB82: e_ews_item_mailbox_from_soap_param (e-ews-item.c:757)
> ==28239==    by 0x1651B7B7: e_ews_item_set_from_soap_parameter (e-ews-item.c:475)
> ==28239==    by 0x1651BB9C: e_ews_item_new_from_soap_parameter (e-ews-item.c:536)
> ==28239==    by 0x16514564: get_items_response_cb (e-ews-connection.c:541)
> ==28239==    by 0x1651413C: ews_response_cb (e-ews-connection.c:425)
> ==28239==    by 0x313AE3A119: process_queue_item (soup-session-async.c:383)
> ==28239==    by 0x313AE3A37C: run_queue (soup-session-async.c:418)
> ==28239==    by 0x313AE3A9D2: idle_run_queue (soup-session-async.c:443)
> ==28239== 

Same as above.

> ==28239== 285 bytes in 57 blocks are definitely lost in loss record 12,323 of 14,587
> ==28239==    at 0x4A05E46: malloc (vg_replace_malloc.c:195)
> ==28239==    by 0x3B6A048B52: g_malloc (gmem.c:164)
> ==28239==    by 0x3B6A06101D: g_strdup (gstrfuncs.c:102)
> ==28239==    by 0x16520929: e_soap_parameter_get_string_value (e-soap-response.c:351)
> ==28239==    by 0x1651CB82: e_ews_item_mailbox_from_soap_param (e-ews-item.c:757)
> ==28239==    by 0x1651B804: e_ews_item_set_from_soap_parameter (e-ews-item.c:481)
> ==28239==    by 0x1651BB9C: e_ews_item_new_from_soap_parameter (e-ews-item.c:536)
> ==28239==    by 0x16514564: get_items_response_cb (e-ews-connection.c:541)
> ==28239==    by 0x1651413C: ews_response_cb (e-ews-connection.c:425)
> ==28239==    by 0x313AE3A119: process_queue_item (soup-session-async.c:383)
> ==28239==    by 0x313AE3A37C: run_queue (soup-session-async.c:418)
> ==28239==    by 0x313AE3A9D2: idle_run_queue (soup-session-async.c:443)

And again.

> ==28239== 315 bytes in 3 blocks are definitely lost in loss record 12,380 of 14,587
> ==28239==    at 0x4A05E46: malloc (vg_replace_malloc.c:195)
> ==28239==    by 0x3B6A048B52: g_malloc (gmem.c:164)
> ==28239==    by 0x3B6A06101D: g_strdup (gstrfuncs.c:102)
> ==28239==    by 0x16520BBD: e_soap_parameter_get_property (e-soap-response.c:485)
> ==28239==    by 0x1651440D: sync_xxx_response_cb (e-ews-connection.c:502)
> ==28239==    by 0x165144D1: sync_hierarchy_response_cb (e-ews-connection.c:518)
> ==28239==    by 0x1651413C: ews_response_cb (e-ews-connection.c:425)
> ==28239==    by 0x313AE3A119: process_queue_item (soup-session-async.c:383)
> ==28239==    by 0x313AE3A37C: run_queue (soup-session-async.c:418)
> ==28239==    by 0x313AE3A9D2: idle_run_queue (soup-session-async.c:443)
> ==28239==    by 0x3B6A041E32: g_main_context_dispatch (gmain.c:2149)
> ==28239==    by 0x3B6A04260F: g_main_context_iterate.clone.5 (gmain.c:2780)

e-ews-connection.c:502 is fetching the ID string for a deleted item.
It's in the SyncFolderHierarchy call. Looks like we're not actually
freeing the strings.

In ews_update_folder_hierarchy() in camel-ews-store.c we go through the
created and updated lists, and we free the strings. But not the deleted
list for some reason. I'll go back through the git history to see if
there's a *reason* for that (and I hope not, or there should have been a
comment about it).


> ==28239== 725 bytes in 145 blocks are definitely lost in loss record 12,896 of 14,587
> ==28239==    at 0x4A05E46: malloc (vg_replace_malloc.c:195)
> ==28239==    by 0x3B6A048B52: g_malloc (gmem.c:164)
> ==28239==    by 0x3B6A06101D: g_strdup (gstrfuncs.c:102)
> ==28239==    by 0x16520929: e_soap_parameter_get_string_value (e-soap-response.c:351)
> ==28239==    by 0x1651CB82: e_ews_item_mailbox_from_soap_param (e-ews-item.c:757)
> ==28239==    by 0x1651B884: e_ews_item_set_from_soap_parameter (e-ews-item.c:490)
> ==28239==    by 0x1651BB9C: e_ews_item_new_from_soap_parameter (e-ews-item.c:536)
> ==28239==    by 0x16514564: get_items_response_cb (e-ews-connection.c:541)
> ==28239==    by 0x1651413C: ews_response_cb (e-ews-connection.c:425)
> ==28239==    by 0x313AE3A119: process_queue_item (soup-session-async.c:383)
> ==28239==    by 0x313AE3A37C: run_queue (soup-session-async.c:418)
> ==28239==    by 0x313AE3A9D2: idle_run_queue (soup-session-async.c:443)

Mandy's SMTP strcmp again.

> ==28239== 1,665 bytes in 1 blocks are definitely lost in loss record 13,627 of 14,587
> ==28239==    at 0x4A05E46: malloc (vg_replace_malloc.c:195)
> ==28239==    by 0x3B6A048B52: g_malloc (gmem.c:164)
> ==28239==    by 0x3B6A038EFC: g_key_file_parse_value_as_string.clone.23 (gkeyfile.c:3601)
> ==28239==    by 0x3B6A03AAA2: g_key_file_get_string (gkeyfile.c:1404)
> ==28239==    by 0x1693BCB1: camel_ews_store_summary_get_string_val (camel-ews-store-summary.c:564)
> ==28239==    by 0x1693D038: ews_get_folder_info_sync (camel-ews-store.c:488)
> ==28239==    by 0x4C95402: camel_store_rename_folder (camel-store.c:746)
> ==28239==    by 0x33B6E67FA9: emft_copy_folders(...)(long long,...)(char) (em-folder-utils.c:149)
> ==28239==    by 0x33B6E7F0F7: mail_msg_proxy (mail-mt.c:469)
> ==28239==    by 0x3B6A06BBC3: g_thread_pool_thread_proxy (gthreadpool.c:319)
> ==28239==    by 0x3B6A069445: g_thread_create_proxy (gthread.c:1897)
> ==28239==    by 0x3B68406CCA: start_thread (pthread_create.c:301)

camel-ews-store.c:488 is fetching 'sync_state' from the store summary
database... and evidently never actually freeing it. Will investigate...

-- 
dwmw2