Bug 52362 - Crash on startup (version 0.16.1)
Summary: Crash on startup (version 0.16.1)
Status: RESOLVED FIXED
Alias: None
Product: Telepathy
Classification: Unclassified
Component: gabble (show other bugs)
Version: unspecified
Hardware: Other All
: medium normal
Assignee: Will Thompson
QA Contact: Telepathy bugs list
URL: http://cgit.collabora.com/git/user/wj...
Whiteboard: r+
Keywords: patch
Depends on:
Blocks:
 
Reported: 2012-07-22 15:53 UTC by Dominique Leuenberger
Modified: 2012-11-07 13:58 UTC (History)
0 users

See Also:
i915 platform:
i915 features:


Attachments

Description Dominique Leuenberger 2012-07-22 15:53:46 UTC
Seems, everytime telepathy-gabble fires up, it crashes and is respawned (where the 2nd launch apparently works, as I do see the task running in ps)

As my system is configured to save all coredumps, it's easy to extract those.

A backtrace from such a crash typically looks something like:

#0  g_logv (log_domain=0x7fee782fa5ce "GLib", log_level=G_LOG_LEVEL_CRITICAL, format=0x7fee7830351a "%s: assertion `%s' failed", 
    args1=args1@entry=0x7fffa79c66c8) at gmessages.h:101
#1  0x00007fee782c2682 in g_log (log_domain=<optimized out>, log_level=log_level@entry=G_LOG_LEVEL_CRITICAL, format=format@entry=
    0x7fee7830351a "%s: assertion `%s' failed") at gmessages.c:792
#2  0x00007fee782c26a9 in g_return_if_fail_warning (log_domain=<optimized out>, pretty_function=<optimized out>, 
    expression=<optimized out>) at gmessages.c:801
#3  0x00000000004811d0 in gabble_muc_factory_broadcast_presence (self=<optimized out>) at muc-factory.c:833
#4  0x0000000000469d7c in set_shared_status_cb (source_object=<optimized out>, res=0x108a420, user_data=<optimized out>)
    at conn-presence.c:349
#5  0x00007fee78a2b587 in g_simple_async_result_complete (simple=0x108a420 [GSimpleAsyncResult]) at gsimpleasyncresult.c:767
#6  0x000000000046b76a in conn_util_send_iq_cb (source_object=<optimized out>, res=0x8f8590, user_data=<optimized out>)
    at conn-util.c:55
#7  0x00007fee78a2b587 in g_simple_async_result_complete (simple=0x8f8590 [GSimpleAsyncResult]) at gsimpleasyncresult.c:767
#8  0x00007fee795e709d in handle_iq_reply (porter=<optimized out>, reply=reply@entry=0x10a7b00 [WockyStanza], user_data=user_data@entry=
    0x1093030) at wocky-c2s-porter.c:924
#9  0x00007fee795e4992 in handle_stanza (self=self@entry=0x1093030 [WockyC2SPorter], stanza=stanza@entry=0x10a7b00 [WockyStanza])
    at wocky-c2s-porter.c:1017
#10 0x00007fee795e62e3 in queue_or_handle_stanza (stanza=0x10a7b00 [WockyStanza], self=0x1093030 [WockyC2SPorter])
    at wocky-c2s-porter.c:1140
#11 stanza_received_cb (source=0x1061830 [WockyXmppConnection], res=0x108a6c0, user_data=<optimized out>) at wocky-c2s-porter.c:1330
#12 0x00007fee78a2b587 in g_simple_async_result_complete (simple=0x108a6c0 [GSimpleAsyncResult]) at gsimpleasyncresult.c:767
#13 0x00007fee7960ecc8 in _xmpp_connection_received_data (source=0x8e8b40 [WockyTLSInputStream], result=0x10ac470, 
    user_data=<optimized out>) at wocky-xmpp-connection.c:562
#14 0x00007fee78a18fb9 in async_ready_callback_wrapper (source_object=0x8e8b40 [WockyTLSInputStream], res=0x10ac470, user_data=
    0x1061830) at ginputstream.c:470
#15 0x00007fee78a2b587 in g_simple_async_result_complete (simple=0x10ac470 [GSimpleAsyncResult]) at gsimpleasyncresult.c:767
#16 0x00007fee79612b26 in wocky_tls_job_result_gssize (job=<optimized out>, result=122) at wocky-tls.c:369
#17 0x00007fee78a18fb9 in async_ready_callback_wrapper (source_object=0x8f84b0 [GSocketInputStream], res=0x10ac400, user_data=0x88a180)
    at ginputstream.c:470
#18 0x00007fee78a2b587 in g_simple_async_result_complete (simple=0x10ac400 [GSimpleAsyncResult]) at gsimpleasyncresult.c:767
#19 0x00007fee78a34a2e in g_socket_input_stream_read_ready (socket=<optimized out>, condition=<optimized out>, stream=
    0x8f84b0 [GSocketInputStream]) at gsocketinputstream.c:166
#20 0x00007fee78a2bf36 in socket_source_dispatch (source=source@entry=0x10aa160, callback=<optimized out>, user_data=<optimized out>)
    at gsocket.c:3168
#21 0x00007fee782bb3b5 in g_main_dispatch (context=0x874e50) at gmain.c:2539
#22 g_main_context_dispatch (context=context@entry=0x874e50) at gmain.c:3075
#23 0x00007fee782bb6e8 in g_main_context_iterate (context=0x874e50, block=block@entry=1, dispatch=dispatch@entry=1, 
---Type <return> to continue, or q <return> to quit---
    self=<error reading variable: Unhandled dwarf expression opcode 0xfa>) at gmain.c:3146
#24 0x00007fee782bbae2 in g_main_loop_run (loop=0x87b340) at gmain.c:3340
#25 0x00007fee792ffeb2 in tp_run_connection_manager (prog_name=prog_name@entry=0x4c1527 "telepathy-gabble", version=version@entry=
    0x4cdfa7 "0.16.1", construct_cm=construct_cm@entry=0x42b710 <construct_cm>, argc=argc@entry=1, argv=argv@entry=0x7fffa79c6dd8)
    at run.c:285
#26 0x000000000042ba0c in gabble_main (argc=1, argv=0x7fffa79c6dd8) at gabble.c:182
#27 0x00007fee77cd1455 in __libc_start_main (main=0x42b5e0 <main>, argc=1, ubp_av=0x7fffa79c6dd8, init=<optimized out>, 
    fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fffa79c6dc8) at libc-start.c:226
#28 0x000000000042b629 in _start () at ../sysdeps/x86_64/elf/start.S:113
(gdb) bt full
#0  g_logv (log_domain=0x7fee782fa5ce "GLib", log_level=G_LOG_LEVEL_CRITICAL, format=0x7fee7830351a "%s: assertion `%s' failed", 
    args1=args1@entry=0x7fffa79c66c8) at gmessages.h:101
        domain = 0x0
        data = <optimized out>
        depth = <optimized out>
        log_func = <optimized out>
        domain_fatal_mask = <optimized out>
        masquerade_fatal = <optimized out>
        test_level = <optimized out>
        was_fatal = <optimized out>
        was_recursion = <optimized out>
        i = <optimized out>
#1  0x00007fee782c2682 in g_log (log_domain=<optimized out>, log_level=log_level@entry=G_LOG_LEVEL_CRITICAL, format=format@entry=
    0x7fee7830351a "%s: assertion `%s' failed") at gmessages.c:792
        args = {{gp_offset = 24, fp_offset = 48, overflow_arg_area = 0x7fffa79c67a0, reg_save_area = 0x7fffa79c66e0}}
#2  0x00007fee782c26a9 in g_return_if_fail_warning (log_domain=<optimized out>, pretty_function=<optimized out>, 
    expression=<optimized out>) at gmessages.c:801
No locals.
#3  0x00000000004811d0 in gabble_muc_factory_broadcast_presence (self=<optimized out>) at muc-factory.c:833
        priv = <optimized out>
        iter = {dummy1 = 0x8f8590, dummy2 = 0x0, dummy3 = 0x874e50, dummy4 = 9077616, dummy5 = 0, dummy6 = 0x108a0f0}
        channel = 0x0
        __PRETTY_FUNCTION__ = "gabble_muc_factory_broadcast_presence"
#4  0x0000000000469d7c in set_shared_status_cb (source_object=<optimized out>, res=0x108a420, user_data=<optimized out>)
    at conn-presence.c:349
        result = 0x108a0f0 [GSimpleAsyncResult]
        self = 0x8a8370 [GabbleConnection]
        priv = 0x86f500
        presence = 0x8b69a0 [GabblePresence]
        error = 0x0
#5  0x00007fee78a2b587 in g_simple_async_result_complete (simple=0x108a420 [GSimpleAsyncResult]) at gsimpleasyncresult.c:767
        current_source = 0x10aa160
        current_context = 0x130eca0
        __PRETTY_FUNCTION__ = "g_simple_async_result_complete"
#6  0x000000000046b76a in conn_util_send_iq_cb (source_object=<optimized out>, res=0x8f8590, user_data=<optimized out>)
    at conn-util.c:55
        porter = 0x1093030
---Type <return> to continue, or q <return> to quit---
        reply = <optimized out>
        result = 0x108a420 [GSimpleAsyncResult]
        error = 0x0
#7  0x00007fee78a2b587 in g_simple_async_result_complete (simple=0x8f8590 [GSimpleAsyncResult]) at gsimpleasyncresult.c:767
        current_source = 0x10aa160
        current_context = 0x130eca0
        __PRETTY_FUNCTION__ = "g_simple_async_result_complete"
#8  0x00007fee795e709d in handle_iq_reply (porter=<optimized out>, reply=reply@entry=0x10a7b00 [WockyStanza], user_data=user_data@entry=
    0x1093030) at wocky-c2s-porter.c:924
        r = 0x8f8590 [GSimpleAsyncResult]
        self = 0x1093030 [WockyC2SPorter]
        priv = <optimized out>
        id = <optimized out>
        handler = 0x8e8d00
        ret = 0
        __PRETTY_FUNCTION__ = "handle_iq_reply"
#9  0x00007fee795e4992 in handle_stanza (self=self@entry=0x1093030 [WockyC2SPorter], stanza=stanza@entry=0x10a7b00 [WockyStanza])
    at wocky-c2s-porter.c:1017
        handler = <optimized out>
        priv = <optimized out>
        l = 0x7fee5c001800 = {0x1085320, 0x9280f0, 0x927e30, 0x927de0, 0x927d90, 0x1085720}
        from = <optimized out>
        type = WOCKY_STANZA_TYPE_IQ
        sub_type = WOCKY_STANZA_SUB_TYPE_RESULT
        node = 0x10adfb0 "dominique.leuenberger"
        domain = 0x13175e0 "gmail.com"
        resource = 0x0
        is_from_server = 1
        handled = <optimized out>
        __PRETTY_FUNCTION__ = "handle_stanza"
#10 0x00007fee795e62e3 in queue_or_handle_stanza (stanza=0x10a7b00 [WockyStanza], self=0x1093030 [WockyC2SPorter])
    at wocky-c2s-porter.c:1140
        priv = 0x1093050
#11 stanza_received_cb (source=0x1061830 [WockyXmppConnection], res=0x108a6c0, user_data=<optimized out>) at wocky-c2s-porter.c:1330
        self = 0x1093030 [WockyC2SPorter]
        priv = 0x1093050
        stanza = 0x10a7b00 [WockyStanza]
---Type <return> to continue, or q <return> to quit---
        error = 0x0
        __PRETTY_FUNCTION__ = "stanza_received_cb"
#12 0x00007fee78a2b587 in g_simple_async_result_complete (simple=0x108a6c0 [GSimpleAsyncResult]) at gsimpleasyncresult.c:767
        current_source = 0x10aa160
        current_context = 0x130eca0
        __PRETTY_FUNCTION__ = "g_simple_async_result_complete"
#13 0x00007fee7960ecc8 in _xmpp_connection_received_data (source=0x8e8b40 [WockyTLSInputStream], result=0x10ac470, 
    user_data=<optimized out>) at wocky-xmpp-connection.c:562
        r = 0x108a6c0 [GSimpleAsyncResult]
        self = <optimized out>
        priv = 0x1061850
        size = <optimized out>
        error = 0x0
#14 0x00007fee78a18fb9 in async_ready_callback_wrapper (source_object=0x8e8b40 [WockyTLSInputStream], res=0x10ac470, user_data=
    0x1061830) at ginputstream.c:470
        stream = 0x8e8b40 [WockyTLSInputStream]
#15 0x00007fee78a2b587 in g_simple_async_result_complete (simple=0x10ac470 [GSimpleAsyncResult]) at gsimpleasyncresult.c:767
        current_source = 0x10aa160
        current_context = 0x130eca0
        __PRETTY_FUNCTION__ = "g_simple_async_result_complete"
#16 0x00007fee79612b26 in wocky_tls_job_result_gssize (job=<optimized out>, result=122) at wocky-tls.c:369
        simple = 0x10ac470 [GSimpleAsyncResult]
#17 0x00007fee78a18fb9 in async_ready_callback_wrapper (source_object=0x8f84b0 [GSocketInputStream], res=0x10ac400, user_data=0x88a180)
    at ginputstream.c:470
        stream = 0x8f84b0 [GSocketInputStream]
#18 0x00007fee78a2b587 in g_simple_async_result_complete (simple=0x10ac400 [GSimpleAsyncResult]) at gsimpleasyncresult.c:767
        current_source = 0x10aa160
        current_context = 0x130eca0
        __PRETTY_FUNCTION__ = "g_simple_async_result_complete"
#19 0x00007fee78a34a2e in g_socket_input_stream_read_ready (socket=<optimized out>, condition=<optimized out>, stream=
    0x8f84b0 [GSocketInputStream]) at gsocketinputstream.c:166
        simple = 0x10ac400 [GSimpleAsyncResult]
        error = 0x0
        result = 144
#20 0x00007fee78a2bf36 in socket_source_dispatch (source=source@entry=0x10aa160, callback=<optimized out>, user_data=<optimized out>)
    at gsocket.c:3168
        func = <optimized out>
---Type <return> to continue, or q <return> to quit---
        socket_source = 0x10aa160
        socket = 0x7fee64004190 [GSocket]
        ret = <optimized out>
#21 0x00007fee782bb3b5 in g_main_dispatch (context=0x874e50) at gmain.c:2539
        dispatch = 0x7fee78a2bf00 <socket_source_dispatch>
        was_in_call = 0
        user_data = 0x8f84b0
        callback = 0x7fee78a34980 <g_socket_input_stream_read_ready>
        cb_funcs = 0x7fee785669a0 <g_source_callback_funcs>
        cb_data = 0x8c6d30
        current_source_link = {data = 0x10aa160, next = 0x0}
        need_destroy = <optimized out>
        source = 0x10aa160
        current = 0x883560
        i = <optimized out>
#22 g_main_context_dispatch (context=context@entry=0x874e50) at gmain.c:3075
No locals.
#23 0x00007fee782bb6e8 in g_main_context_iterate (context=0x874e50, block=block@entry=1, dispatch=dispatch@entry=1, 
    self=<error reading variable: Unhandled dwarf expression opcode 0xfa>) at gmain.c:3146
        max_priority = 2147483647
        timeout = 5356
        some_ready = 1
        nfds = <optimized out>
        allocated_nfds = <optimized out>
        fds = 0x89b300
#24 0x00007fee782bbae2 in g_main_loop_run (loop=0x87b340) at gmain.c:3340
        __PRETTY_FUNCTION__ = "g_main_loop_run"
#25 0x00007fee792ffeb2 in tp_run_connection_manager (prog_name=prog_name@entry=0x4c1527 "telepathy-gabble", version=version@entry=
    0x4cdfa7 "0.16.1", construct_cm=construct_cm@entry=0x42b710 <construct_cm>, argc=argc@entry=1, argv=argv@entry=0x7fffa79c6dd8)
    at run.c:285
        connection = 0x871fd0
        bus_daemon = 0x877090 [TpDBusDaemon]
        error = 0x0
        ret = 1
        __PRETTY_FUNCTION__ = "tp_run_connection_manager"
#26 0x000000000042ba0c in gabble_main (argc=1, argv=0x7fffa79c6dd8) at gabble.c:182
        loader = 0x86ea60 [GabblePluginLoader]
---Type <return> to continue, or q <return> to quit---
        out = <optimized out>
        fatal_mask = <optimized out>
#27 0x00007fee77cd1455 in __libc_start_main (main=0x42b5e0 <main>, argc=1, ubp_av=0x7fffa79c6dd8, init=<optimized out>, 
    fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fffa79c6dc8) at libc-start.c:226
        result = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {0, -4260275920128522505, 4371968, 140736005434832, 0, 0, 4260188263690979063, 
    4268455895111616247}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x4c1410 <__libc_csu_init>, 0x7fffa79c6dd8}, data = {prev = 
    0x0, cleanup = 0x0, canceltype = 4985872}}}
        not_first_call = <optimized out>
#28 0x000000000042b629 in _start () at ../sysdeps/x86_64/elf/start.S:113
Comment 1 Will Thompson 2012-11-06 15:49:17 UTC
(In reply to comment #0)
> (gdb) bt full
> #0  g_logv (log_domain=0x7fee782fa5ce "GLib",
> log_level=G_LOG_LEVEL_CRITICAL, format=0x7fee7830351a "%s: assertion `%s'
> failed", 
>     args1=args1@entry=0x7fffa79c66c8) at gmessages.h:101
>         domain = 0x0
>         data = <optimized out>
>         depth = <optimized out>
>         log_func = <optimized out>
>         domain_fatal_mask = <optimized out>
>         masquerade_fatal = <optimized out>
>         test_level = <optimized out>
>         was_fatal = <optimized out>
>         was_recursion = <optimized out>
>         i = <optimized out>
> #1  0x00007fee782c2682 in g_log (log_domain=<optimized out>,
> log_level=log_level@entry=G_LOG_LEVEL_CRITICAL, format=format@entry=
>     0x7fee7830351a "%s: assertion `%s' failed") at gmessages.c:792
>         args = {{gp_offset = 24, fp_offset = 48, overflow_arg_area =
> 0x7fffa79c67a0, reg_save_area = 0x7fffa79c66e0}}
> #2  0x00007fee782c26a9 in g_return_if_fail_warning (log_domain=<optimized
> out>, pretty_function=<optimized out>, 
>     expression=<optimized out>) at gmessages.c:801
> No locals.
> #3  0x00000000004811d0 in gabble_muc_factory_broadcast_presence
> (self=<optimized out>) at muc-factory.c:833
>         priv = <optimized out>
>         iter = {dummy1 = 0x8f8590, dummy2 = 0x0, dummy3 = 0x874e50, dummy4 =
> 9077616, dummy5 = 0, dummy6 = 0x108a0f0}
>         channel = 0x0
>         __PRETTY_FUNCTION__ = "gabble_muc_factory_broadcast_presence"

In 0.16.1, line 833 is:

  g_hash_table_iter_init (&iter, priv->text_channels);

Peering inside g_hash_table_iter_init, there are unsurprisingly two g_return_if_fail()s:

  g_return_if_fail (iter != NULL);
  g_return_if_fail (hash_table != NULL);

So this case must be the latter case: priv->text_channels is NULL. It is set to NULL in gabble_muc_factory_close_all(), which is called from dispose() and when the GabbleConnection goes to state DISCONNECTED.

So a surface-level fix is to check if text_channels is NULL in gabble_muc_factory_broadcast_presence(), for which a patch will follow. But I'm interested in figuring out how this can happen. Onwards down the stack trace:

> #4  0x0000000000469d7c in set_shared_status_cb (source_object=<optimized
> out>, res=0x108a420, user_data=<optimized out>)
>     at conn-presence.c:349
>         result = 0x108a0f0 [GSimpleAsyncResult]
>         self = 0x8a8370 [GabbleConnection]
>         priv = 0x86f500
>         presence = 0x8b69a0 [GabblePresence]
>         error = 0x0

This is the successful path, where we've got a positive reply to our IQ setting a new Google shared status.

So this looks like the following sequence of events:

• Sign in;
• Change status, triggering a shared status IQ being sent;
• Before we get a reply, Disconnect(), which will cause GabbleMucFactory->priv->text_channels to be NULL;
• Now get a reply from the server. set_shared_status_cb() calls gabble_muc_factory_broadcast_presence() which crashes.

But I wrote a test case for this, and it passed :/
Comment 2 Will Thompson 2012-11-06 16:44:59 UTC
So I think this is because the </stream:stream> may not be sent on the wire immediately when Disconnect() is called, because data is waiting to be sent, so there is a window in which the connection is DISCONNECTED (and hence priv->text_channels is NULL) but IQ replies are still dispatched. I haven't managed to write a test, though.
Comment 3 Will Thompson 2012-11-06 16:54:41 UTC
Well, here's a branch that should fix the crash, anyway.
Comment 4 Simon McVittie 2012-11-07 12:01:08 UTC
Looks good to me.
Comment 5 Will Thompson 2012-11-07 13:58:10 UTC
Merged to master (for 0.17.2: http://cgit.freedesktop.org/telepathy/telepathy-gabble/log/?id=1bd50bc9f) and cherry-picked the top patch to 0.16 (for 0.16.4: http://cgit.freedesktop.org/telepathy/telepathy-gabble/commit/?h=telepathy-gabble-0.16&id=64b405cb0).


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.