Bug 626652 - ibus memory leak with ibus_input_context_process_key_event
Summary: ibus memory leak with ibus_input_context_process_key_event
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: ibus
Version: 13
Hardware: All
OS: Linux
low
medium
Target Milestone: ---
Assignee: fujiwara
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2010-08-24 01:57 UTC by David Woodhouse
Modified: 2010-09-26 04:31 UTC (History)
6 users (show)

Fixed In Version: ibus-1.3.6-2.fc12
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2010-09-22 00:39:04 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
Test Program (8.73 KB, text/plain)
2010-08-27 08:25 UTC, fujiwara
no flags Details

Description David Woodhouse 2010-08-24 01:57:30 UTC
When running Evolution in valgrind, I found this:

==25376== 22,199 (6,536 direct, 15,663 indirect) bytes in 43 blocks are definitely lost in loss record 21,921 of 22,181
==25376==    at 0x4A0515D: malloc (vg_replace_malloc.c:195)
==25376==    by 0x35A0017C8A: ??? (in /lib64/libdbus-1.so.3.4.0)
==25376==    by 0x35A001B262: dbus_message_new_method_call (in /lib64/libdbus-1.so.3.4.0)
==25376==    by 0x24E5D5A2: ibus_proxy_call_with_reply (in /usr/lib64/libibus.so.2.0.0)
==25376==    by 0x24E672C7: ibus_input_context_process_key_event (in /usr/lib64/libibus.so.2.0.0)
==25376==    by 0x24C478B0: ??? (in /usr/lib64/gtk-2.0/2.10.0/immodules/im-ibus.so)
==25376==    by 0x34FA9314A6: ??? (in /usr/lib64/libgtk-x11-2.0.so.0.2000.1)
==25376==    by 0x700184A: key_press_event (gtkhtml.c:1059)
==25376==    by 0x34FA951002: ??? (in /usr/lib64/libgtk-x11-2.0.so.0.2000.1)
==25376==    by 0x3A4E40D708: g_closure_invoke (in /lib64/libgobject-2.0.so.0.2512.0)
==25376==    by 0x3A4E4259A1: ??? (in /lib64/libgobject-2.0.so.0.2512.0)
==25376==    by 0x3A4E42730B: g_signal_emit_valist (in /lib64/libgobject-2.0.so.0.2512.0)
==25376==

Comment 1 fujiwara 2010-08-24 09:17:36 UTC
Hmm.., interested bug. I could reproduce this bug.

==2254== 9,903 (2,432 direct, 7,471 indirect) bytes in 16 blocks are definitely lost in loss record 17,683 of 17,919
==2254==    at 0x4A0515D: malloc (vg_replace_malloc.c:195)
==2254==    by 0x7A9247D: dbus_malloc (dbus-memory.c:471)
==2254==    by 0x7A7D661: dbus_message_new_empty_header (dbus-message.c:966)
==2254==    by 0x7A7DECC: dbus_message_new_error (dbus-message.c:1219)
==2254==    by 0x7A83DF7: _dbus_pending_call_set_timeout_error_unlocked (dbus-pending-call.c:341)
==2254==    by 0x7A6FA2C: dbus_connection_send_with_reply (dbus-connection.c:3259)
==2254==    by 0x14606B6B: ibus_connection_send_with_reply (ibusconnection.c:677)
==2254==    by 0x14609CBC: ibus_proxy_call_with_reply (ibusproxy.c:672)
==2254==    by 0x146173BD: ibus_input_context_process_key_event (ibusinputcontext.c:806)
==2254==    by 0x143EEF4D: ibus_im_context_filter_keypress (ibusimcontext.c:480)
==2254==    by 0x32E9D74D32: gtk_im_context_filter_keypress (gtkimcontext.c:473)
==2254==    by 0x32E9D7916E: gtk_im_multicontext_filter_keypress (gtkimmulticontext.c:331)
==2254==

If I run a sample program with dbus_connection_send_with_reply() with session-bus, I don't see any leaks.
I will compare what is different.

Comment 2 fujiwara 2010-08-25 07:01:01 UTC
I think dbus_message_unref() and dbus_pending_call_unref() are called properly in IBus side.
It seems the errors are different by CPU/memory condition however I guess this is a bug of valgrind or dbus.

Transferring to dbus if the engineers have an idea.

Comment 3 David Zeuthen 2010-08-25 14:31:29 UTC
Uhm, please don't reassign bugs just to ask questions - that's not how things work. Also, I seriously doubt this is a D-Bus problem (the D-Bus test suite checks for leaks and no other apps have this problem). Reassigning back.

Comment 4 fujiwara 2010-08-27 08:25:48 UTC
Created attachment 441434 [details]
Test Program

Attached the dbus test program which removed IBus application codes.

% cat /etc/dbus-1/session.d/dbus-example.conf
<!DOCTYPE busconfig PUBLIC
 "-//freedesktop//DTD D-BUS Bus Configuration 1.0//EN"
 "http://www.freedesktop.org/standards/dbus/1.0/busconfig.dtd">
<busconfig>

  <!-- Only root can own the service -->
  <policy user="*">
    <allow own="test.method.server"/>
  </policy>
</busconfig>

Comment 5 fujiwara 2010-08-27 08:31:23 UTC
If the program in comment #4, I could see several 'definitely lost' messages below.
Since there are no ibus source codes, I'll transfer to dbus.

% ./dbus-example listen

% valgrind --leak-check=full ./dbus-example query
==15109== HEAP SUMMARY:
==15109==     in use at exit: 21,247 bytes in 101 blocks
==15109==   total heap usage: 409 allocs, 308 frees, 30,104 bytes allocated
==15109== 
==15109== 496 bytes in 1 blocks are possibly lost in loss record 56 of 68
==15109==    at 0x4A04360: memalign (vg_replace_malloc.c:532)
==15109==    by 0x4A043B9: posix_memalign (vg_replace_malloc.c:660)
==15109==    by 0x3AF9059E57: ??? (in /lib64/libglib-2.0.so.0.2507.0)
==15109==    by 0x3AF905A6DB: g_slice_alloc (in /lib64/libglib-2.0.so.0.2507.0)
==15109==    by 0x3AF905A7F5: g_slice_alloc0 (in /lib64/libglib-2.0.so.0.2507.0)
==15109==    by 0x4016CF: query (dbus-example.c:177)
==15109==    by 0x4017B3: query_for_valgrind (dbus-example.c:204)
==15109==    by 0x401BF0: main (dbus-example.c:331)
==15109== 
==15109== 535 (152 direct, 383 indirect) bytes in 1 blocks are definitely lost in loss record 59 of 68
==15109==    at 0x4A0515D: malloc (vg_replace_malloc.c:195)
==15109==    by 0x4C6247D: dbus_malloc (dbus-memory.c:471)
==15109==    by 0x4C4D661: dbus_message_new_empty_header (dbus-message.c:966)
==15109==    by 0x4C4DA26: dbus_message_new_method_call (dbus-message.c:1083)
==15109==    by 0x4C3AD8B: dbus_bus_register (dbus-bus.c:685)
==15109==    by 0x4C3AB1C: internal_bus_get (dbus-bus.c:491)
==15109==    by 0x4C3AC0D: dbus_bus_get (dbus-bus.c:567)
==15109==    by 0x401480: query (dbus-example.c:120)
==15109==    by 0x4017B3: query_for_valgrind (dbus-example.c:204)
==15109==    by 0x401BF0: main (dbus-example.c:331)
==15109== 
==15109== 1,488 bytes in 3 blocks are possibly lost in loss record 63 of 68
==15109==    at 0x4A04360: memalign (vg_replace_malloc.c:532)
==15109==    by 0x4A043B9: posix_memalign (vg_replace_malloc.c:660)
==15109==    by 0x3AF9059E57: ??? (in /lib64/libglib-2.0.so.0.2507.0)
==15109==    by 0x3AF905A711: g_slice_alloc (in /lib64/libglib-2.0.so.0.2507.0)
==15109==    by 0x3AF905A7F5: g_slice_alloc0 (in /lib64/libglib-2.0.so.0.2507.0)
==15109==    by 0x4016CF: query (dbus-example.c:177)
==15109==    by 0x4017B3: query_for_valgrind (dbus-example.c:204)
==15109==    by 0x401BF0: main (dbus-example.c:331)
==15109== 
==15109== 4,408 (1,216 direct, 3,192 indirect) bytes in 8 blocks are definitely lost in loss record 68 of 68
==15109==    at 0x4A0515D: malloc (vg_replace_malloc.c:195)
==15109==    by 0x4C6247D: dbus_malloc (dbus-memory.c:471)
==15109==    by 0x4C4D661: dbus_message_new_empty_header (dbus-message.c:966)
==15109==    by 0x4C51CA1: _dbus_message_loader_queue_messages (dbus-message.c:3679)
==15109==    by 0x4C5B395: _dbus_transport_get_dispatch_status (dbus-transport.c:1080)
==15109==    by 0x4C5B44F: _dbus_transport_queue_messages (dbus-transport.c:1107)
==15109==    by 0x4C5C683: do_reading (dbus-transport-socket.c:792)
==15109==    by 0x4C5CC19: socket_do_iteration (dbus-transport-socket.c:1103)
==15109==    by 0x4C5B0F4: _dbus_transport_do_iteration (dbus-transport.c:956)
==15109==    by 0x4C3CD0E: _dbus_connection_do_iteration_unlocked (dbus-connection.c:1163)
==15109==    by 0x4C3E4C9: _dbus_connection_block_pending_call (dbus-connection.c:2335)
==15109==    by 0x4C54450: dbus_pending_call_block (dbus-pending-call.c:705)
==15109== 
==15109== LEAK SUMMARY:
==15109==    definitely lost: 1,368 bytes in 9 blocks
==15109==    indirectly lost: 3,575 bytes in 18 blocks
==15109==      possibly lost: 1,984 bytes in 4 blocks
==15109==    still reachable: 14,320 bytes in 70 blocks
==15109==         suppressed: 0 bytes in 0 blocks
==15109== Reachable blocks (those to which a pointer was found) are not shown.
==15109== To see them, rerun with: --leak-check=full --show-reachable=yes
==15109== 
==15109== For counts of detected and suppressed errors, rerun with: -v
==15109== Use --track-origins=yes to see where uninitialised values come from
==15109== ERROR SUMMARY: 10 errors from 10 contexts (suppressed: 0 from 0)

Comment 6 David Zeuthen 2010-08-27 15:15:56 UTC
(In reply to comment #5)
> If the program in comment #4, I could see several 'definitely lost' messages
> below.
> Since there are no ibus source codes, I'll transfer to dbus.

Seriously, what kind of logic is this? Sorry but your example doesn't really demonstrate that there is a memory leak in the D-Bus library. For starters, you don't call dbus_shutdown() in your test program so of course it will look like the D-Bus library is leaking.

Did you even look at the D-Bus test suite as I suggested in comment 3? If not, then please do. In particular, please read what's in this file

 http://cgit.freedesktop.org/dbus/dbus/tree/dbus/dbus-test.c?id=dbus-1.2.24#n39

and the surrounding test suite. As you can see, the D-Bus test suite actually checks that all allocated memory is released. Heck, it even checks the failure paths by counting the mallocs, then running the test suite N times, failing each malloc. With this in mind, what is more realistic? That we leak memory in such a central function as dbus_message_new_method_call() or that, just maybe, the user library or user application is leaking the object?

I'd really appreciate you would stop reassigning your bugs to D-Bus until it has actually been, you know, established, that the bug is with D-Bus and not just your code or some random example code using D-Bus. Thank you.

Comment 7 David Woodhouse 2010-08-27 15:17:42 UTC
Using G_SLICE=always-malloc would also be useful when testing.

Comment 8 David Zeuthen 2010-08-27 15:20:14 UTC
(In reply to comment #7)
> Using G_SLICE=always-malloc would also be useful when testing.

That's good advice when debugging GLib apps (G_DEBUG=gc-friendly is helpful too). But libdbus, for better or worse, doesn't use GLib so it won't matter.

Comment 9 Colin Walters 2010-08-27 17:36:28 UTC
(In reply to comment #5)

> % valgrind --leak-check=full ./dbus-example query
> ==15109== HEAP SUMMARY:
> ==15109==     in use at exit: 21,247 bytes in 101 blocks
> ==15109==   total heap usage: 409 allocs, 308 frees, 30,104 bytes allocated
> ==15109== 
> ==15109== 496 bytes in 1 blocks are possibly lost in loss record 56 of 68
> ==15109==    at 0x4A04360: memalign (vg_replace_malloc.c:532)
> ==15109==    by 0x4A043B9: posix_memalign (vg_replace_malloc.c:660)
> ==15109==    by 0x3AF9059E57: ??? (in /lib64/libglib-2.0.so.0.2507.0)
> ==15109==    by 0x3AF905A6DB: g_slice_alloc (in /lib64/libglib-2.0.so.0.2507.0)
> ==15109==    by 0x3AF905A7F5: g_slice_alloc0 (in
> /lib64/libglib-2.0.so.0.2507.0)
> ==15109==    by 0x4016CF: query (dbus-example.c:177)
> ==15109==    by 0x4017B3: query_for_valgrind (dbus-example.c:204)
> ==15109==    by 0x401BF0: main (dbus-example.c:331)

This one is clearly a leak in your test program.

> ==15109== 
> ==15109== 535 (152 direct, 383 indirect) bytes in 1 blocks are definitely lost
> in loss record 59 of 68
> ==15109==    at 0x4A0515D: malloc (vg_replace_malloc.c:195)
> ==15109==    by 0x4C6247D: dbus_malloc (dbus-memory.c:471)
> ==15109==    by 0x4C4D661: dbus_message_new_empty_header (dbus-message.c:966)
> ==15109==    by 0x4C4DA26: dbus_message_new_method_call (dbus-message.c:1083)
> ==15109==    by 0x4C3AD8B: dbus_bus_register (dbus-bus.c:685)
> ==15109==    by 0x4C3AB1C: internal_bus_get (dbus-bus.c:491)
> ==15109==    by 0x4C3AC0D: dbus_bus_get (dbus-bus.c:567)
> ==15109==    by 0x401480: query (dbus-example.c:120)
> ==15109==    by 0x4017B3: query_for_valgrind (dbus-example.c:204)
> ==15109==    by 0x401BF0: main (dbus-example.c:331)

You'd need to call dbus_shutdown() to clear this one.  There's an internal cache of message buffers.

> ==15109== 
> ==15109== 1,488 bytes in 3 blocks are possibly lost in loss record 63 of 68
> ==15109==    at 0x4A04360: memalign (vg_replace_malloc.c:532)
> ==15109==    by 0x4A043B9: posix_memalign (vg_replace_malloc.c:660)
> ==15109==    by 0x3AF9059E57: ??? (in /lib64/libglib-2.0.so.0.2507.0)
> ==15109==    by 0x3AF905A711: g_slice_alloc (in /lib64/libglib-2.0.so.0.2507.0)
> ==15109==    by 0x3AF905A7F5: g_slice_alloc0 (in
> /lib64/libglib-2.0.so.0.2507.0)
> ==15109==    by 0x4016CF: query (dbus-example.c:177)
> ==15109==    by 0x4017B3: query_for_valgrind (dbus-example.c:204)
> ==15109==    by 0x401BF0: main (dbus-example.c:331)

Ditto, this is a leak in your app.

> ==15109== 
> ==15109== 4,408 (1,216 direct, 3,192 indirect) bytes in 8 blocks are definitely
> lost in loss record 68 of 68
> ==15109==    at 0x4A0515D: malloc (vg_replace_malloc.c:195)
> ==15109==    by 0x4C6247D: dbus_malloc (dbus-memory.c:471)
> ==15109==    by 0x4C4D661: dbus_message_new_empty_header (dbus-message.c:966)
> ==15109==    by 0x4C51CA1: _dbus_message_loader_queue_messages
> (dbus-message.c:3679)
> ==15109==    by 0x4C5B395: _dbus_transport_get_dispatch_status
> (dbus-transport.c:1080)
> ==15109==    by 0x4C5B44F: _dbus_transport_queue_messages
> (dbus-transport.c:1107)
> ==15109==    by 0x4C5C683: do_reading (dbus-transport-socket.c:792)
> ==15109==    by 0x4C5CC19: socket_do_iteration (dbus-transport-socket.c:1103)
> ==15109==    by 0x4C5B0F4: _dbus_transport_do_iteration (dbus-transport.c:956)
> ==15109==    by 0x4C3CD0E: _dbus_connection_do_iteration_unlocked
> (dbus-connection.c:1163)
> ==15109==    by 0x4C3E4C9: _dbus_connection_block_pending_call
> (dbus-connection.c:2335)
> ==15109==    by 0x4C54450: dbus_pending_call_block (dbus-pending-call.c:705)

This one is also probably a missing dbus_shutdown().

Comment 10 fujiwara 2010-08-31 08:49:58 UTC
It seems dbus_shutdown() doesn't resolve this issue in my test.
I called dbus_shutdown() out of for loop because it calls _exit(). I guess using dbus_connection_set_exit_on_disconnect() may not be good to avoid _exit() because several components(e.g. gconfd) also uses dbus.
It seems dbus_shutdown() calls dbus_message_cache_shutdown() and shared_connections_shutdown() but probably I'd like to call dbus_message_cache_shutdown() only.

I had some tests with dbus/dbus/dbus-test.c but I could not find a test using  both DBusMessage and DBusConnection.

Comment 11 fujiwara 2010-09-02 03:41:24 UTC
I had the furthermore investigations.
It seems valgrind doesn't indicate the correct leak stack because dbus_message_get_cached() reuses DBusMessage and it would cause the difficult debugging.

Finally I found my test program has a problem.
_process_key_event_reply_cb() didn't call dbus_message_unref().
If I fixed it, valgrind shows no definitely leak.

If I applied the similar fix in ibus, valgrind also shows no definitely leak in my test.
Now I accept this bug as probably my fix is right.

I also saw other definitely leaks with evolution but probably they are not ibus but evolution. e.g. could free gchar and unref PangoAttrList with gtk_im_context_get_preedit_string().

Comment 13 fujiwara 2010-09-02 04:45:53 UTC
Test packages are created:
http://koji.fedoraproject.org/koji/taskinfo?taskID=2442124

Bug repoter:
Could you confirm the fix?

Installation:
# rpm -e --nodeps ibus
# rpm -ivh ibus-1.3.7-1.fc13.x86_64.rpm

Uninstallation:
# rpm -e --nodeps ibus
# yum install ibus

Comment 15 Fedora Update System 2010-09-15 02:02:06 UTC
ibus-1.3.6-2.fc13 has been submitted as an update for Fedora 13.
https://admin.fedoraproject.org/updates/ibus-1.3.6-2.fc13

Comment 16 Fedora Update System 2010-09-15 02:02:21 UTC
ibus-1.3.6-2.fc12 has been submitted as an update for Fedora 12.
https://admin.fedoraproject.org/updates/ibus-1.3.6-2.fc12

Comment 17 David Woodhouse 2010-09-15 09:15:12 UTC
I haven't seen this leak since installing the updated packages; I think it's fixed. Thanks.

Comment 18 Fedora Update System 2010-09-15 22:30:21 UTC
ibus-1.3.6-2.fc12 has been pushed to the Fedora 12 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update ibus'.  You can provide feedback for this update here: https://admin.fedoraproject.org/updates/ibus-1.3.6-2.fc12

Comment 19 Fedora Update System 2010-09-22 00:38:55 UTC
ibus-1.3.6-2.fc13 has been pushed to the Fedora 13 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 20 Fedora Update System 2010-09-26 04:31:36 UTC
ibus-1.3.6-2.fc12 has been pushed to the Fedora 12 stable repository.  If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.