Bug 98853

Hi!

I noticed a strange behavior happening in gabble, when two streams (audio+video) are proposed by A to B, both incoming streams are accepted by B, but only single stream (audio) is locally provided by B to A (typically a reply with audio only in empathy).

In this case, for B, the local sending state of the video stream should stay at value TP_SENDING_STATE_NONE or TP_SENDING_STATE_PENDING_SEND, but should not go  to TP_SENDING_STATE_SENDING.

This is what happens with the local video stream state of B. This problem prevents empathy from switching on video stream transmission from B to A at a later time, as gabble consider that the video stream in in SENDING state already. The empathy user typically has to toggle the video transmission several times, to resync the video transmission state between empathy and gabble.

The problem is that tp_base_call_stream_update_local_sending_state() is called two times consecutively from tp_base_media_call_channel_try_accept(). The local sending state evolving from state TP_SENDING_STATE_NONE, to TP_SENDING_STATE_PENDING_SEND, and incorrectly from state TP_SENDING_STATE_PENDING_SEND to TP_SENDING_STATE_SENDING in this second invocation.

1st is base-media-call-channel.c:196
2nd is base-media-call-channel.c:198

        static void
        tp_base_media_call_channel_try_accept (TpBaseMediaCallChannel *self)
        {
          TpBaseCallChannel *bcc = TP_BASE_CALL_CHANNEL (self);
          TpBaseMediaCallChannelClass *klass =
              TP_BASE_MEDIA_CALL_CHANNEL_GET_CLASS (self);
          GList *l;
          gboolean notready = FALSE;
        
          if (self->priv->accepted)
            return;
        
          for (l = tp_base_call_channel_get_contents (bcc); l; l = l->next)
            notready |= !_tp_base_media_call_content_ready_to_accept (l->data);
        
          if (notready && !_tp_base_media_channel_is_held (self))
            return;
        
          if (klass->accept != NULL)
 1st-->     klass->accept (self);
        
 2nd-->   TP_BASE_CALL_CHANNEL_CLASS (tp_base_media_call_channel_parent_class)->accept (bcc);
        
          self->priv->accepted = TRUE;
        }


Here are the two backtraces corresponding to #16 for the 2nd call in the first backtrace, and #4 for 2nd call in the second backtrace :

(gdb) print self->priv->object_path
$70 = (gchar *) 0x60d00002d0f0 "/org/freedesktop/Telepathy/Connection/gabble/jabber/testuser1_40bellet_2einfo_2f5f842d89/CallChannel23/Content_video_2/Stream0x6210000173c0"
(gdb) bt
#0  tp_base_call_stream_update_local_sending_state (self=0x621000073c40, new_state=TP_SENDING_STATE_PENDING_SEND, actor_handle=0, reason=TP_CALL_STATE_CHANGE_REASON_PROGRESS_MADE, dbus_reason=0x5f0b40 "", message=0x5f0b40 "") at base-call-stream.c:553
#1  0x000000000055c5e5 in gabble_call_stream_update_member_states (self=0x621000073c40) at call-stream.c:447
#2  0x000000000055b65f in content_state_changed_cb (content=0x6210000173c0, spec=0x621000083da0, user_data=0x621000073c40) at call-stream.c:202
#3  0x00007f9e184893e5 in g_closure_invoke (closure=0x60700004afe0, return_value=return_value@entry=0x0, n_param_values=2, param_values=param_values@entry=0x7ffc209c6950, invocation_hint=invocation_hint@entry=0x7ffc209c68d0) at gclosure.c:804
#4  0x00007f9e1849b432 in signal_emit_unlocked_R (node=node@entry=0x60800000a3a0, detail=detail@entry=770, instance=instance@entry=0x6210000173c0, emission_return=emission_return@entry=0x0, instance_and_params=instance_and_params@entry=0x7ffc209c6950) at gsignal.c:3629
#5  0x00007f9e184a405f in g_signal_emit_valist (instance=<optimized out>, signal_id=<optimized out>, detail=<optimized out>, var_args=var_args@entry=0x7ffc209c6b20) at gsignal.c:3385
#6  0x00007f9e184a443f in g_signal_emit (instance=instance@entry=0x6210000173c0, signal_id=<optimized out>, detail=<optimized out>) at gsignal.c:3441
#7  0x00007f9e1848d814 in g_object_dispatch_properties_changed (object=0x6210000173c0, n_pspecs=<optimized out>, pspecs=<optimized out>) at gobject.c:1062
#8  0x00007f9e1848d0b6 in g_object_notify_queue_thaw (object=object@entry=0x6210000173c0, nqueue=nqueue@entry=0x61500006cd30) at gobject.c:296
#9  0x00007f9e18490b1d in g_object_set_valist (object=object@entry=0x6210000173c0, first_property_name=first_property_name@entry=0x7f9e1a46c360 "state", var_args=var_args@entry=0x7ffc209c6df0) at gobject.c:2171
#10 0x00007f9e1849130c in g_object_set (_object=0x6210000173c0, first_property_name=0x7f9e1a46c360 "state") at gobject.c:2275
#11 0x00007f9e1a3ef7ca in _fill_content (sess=0x6210000429c0, c=0x6210000173c0, user_data=0x619000098560) at wocky-jingle-session.c:1863
#12 0x00007f9e1a3ef565 in _map_initial_contents (sess=0x6210000429c0, mapper=0x7f9e1a3ef648 <_fill_content>, user_data=0x619000098560) at wocky-jingle-session.c:1817
#13 0x00007f9e1a3f0881 in try_session_initiate_or_accept (sess=0x6210000429c0) at wocky-jingle-session.c:2073
#14 0x00007f9e1a3f0de1 in wocky_jingle_session_accept (sess=0x6210000429c0) at wocky-jingle-session.c:2146
#15 0x00000000005053df in call_channel_accept (channel=0x62500000b200) at call-channel.c:647
#16 0x00007f9e19191ed5 in tp_base_media_call_channel_try_accept (self=0x62500000b200) at base-media-call-channel.c:196
#17 0x00007f9e19191fb7 in streams_changed_cb (stream=0x621000073c40, spec=0x621000083f20, self=0x62500000b200) at base-media-call-channel.c:208
#18 0x00007f9e184893e5 in g_closure_invoke (closure=0x607000049920, return_value=return_value@entry=0x0, n_param_values=2, param_values=param_values@entry=0x7ffc209c74c0, invocation_hint=invocation_hint@entry=0x7ffc209c7440) at gclosure.c:804
#19 0x00007f9e1849b432 in signal_emit_unlocked_R (node=node@entry=0x60800000a3a0, detail=detail@entry=1119, instance=instance@entry=0x621000073c40, emission_return=emission_return@entry=0x0, instance_and_params=instance_and_params@entry=0x7ffc209c74c0) at gsignal.c:3629
#20 0x00007f9e184a405f in g_signal_emit_valist (instance=<optimized out>, signal_id=<optimized out>, detail=<optimized out>, var_args=var_args@entry=0x7ffc209c7690) at gsignal.c:3385
#21 0x00007f9e184a443f in g_signal_emit (instance=instance@entry=0x621000073c40, signal_id=<optimized out>, detail=<optimized out>) at gsignal.c:3441
#22 0x00007f9e1848d814 in g_object_dispatch_properties_changed (object=0x621000073c40, n_pspecs=<optimized out>, pspecs=<optimized out>) at gobject.c:1062
#23 0x00007f9e1848fd01 in g_object_notify_by_spec_internal (pspec=0x621000083f20, object=0x621000073c40) at gobject.c:1155
#24 g_object_notify (object=0x621000073c40, property_name=<optimized out>) at gobject.c:1203
#25 0x00007f9e1919e2c3 in tp_base_media_call_stream_complete_receiving_state_change (iface=0x621000073c40, state=TP_STREAM_FLOW_STATE_STARTED, context=0x6040000d5990) at base-media-call-stream.c:1309
#26 0x00007f9e193be272 in tp_svc_call_stream_interface_media_complete_receiving_state_change (self=0x621000073c40, in_State=3, context=0x6040000d5990) at _gen/tp-svc-call-stream.c:331
#27 0x00007f9e14ff2c58 in ffi_call_unix64 () at ../src/x86/unix64.S:76
#28 0x00007f9e14ff26ba in ffi_call (cif=cif@entry=0x7ffc209c7bc0, fn=fn@entry=0x7f9e193be1e0 <tp_svc_call_stream_interface_media_complete_receiving_state_change>, rvalue=<optimized out>, avalue=avalue@entry=0x7ffc209c7ad0) at ../src/x86/ffi64.c:525
#29 0x00007f9e18489c1e in g_cclosure_marshal_generic (closure=0x7ffc209c7d90, return_gvalue=0x0, n_param_values=<optimized out>, param_values=<optimized out>, invocation_hint=<optimized out>, marshal_data=<optimized out>) at gclosure.c:1490
#30 0x00007f9e1a95255b in object_registration_message () from /lib64/libdbus-glib-1.so.2
#31 0x00007f9e1a719a33 in _dbus_object_tree_dispatch_and_unlock () from /lib64/libdbus-1.so.3
#32 0x00007f9e1a70b0a4 in dbus_connection_dispatch () from /lib64/libdbus-1.so.3
#33 0x00007f9e1a94f8d5 in message_queue_dispatch () from /lib64/libdbus-glib-1.so.2
#34 0x00007f9e17fb16ba in g_main_dispatch (context=0x60f00000ec80) at gmain.c:3154
#35 g_main_context_dispatch (context=context@entry=0x60f00000ec80) at gmain.c:3769
#36 0x00007f9e17fb1a70 in g_main_context_iterate (context=0x60f00000ec80, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3840
#37 0x00007f9e17fb1d92 in g_main_loop_run (loop=0x602000008110) at gmain.c:4034
#38 0x00007f9e19392850 in tp_run_connection_manager (prog_name=0x55dba0 "telepathy-gabble", version=0x55db60 "0.18.2", construct_cm=0x42752d <construct_cm>, argc=1, argv=0x7ffc209c83c8) at run.c:284
#39 0x0000000000427b1c in gabble_main (argc=1, argv=0x7ffc209c83c8) at gabble.c:177
#40 0x000000000042751b in main (argc=1, argv=0x7ffc209c83c8) at main.c:33

(gdb) print self->priv->object_path
$71 = (gchar *) 0x60d00002d0f0 "/org/freedesktop/Telepathy/Connection/gabble/jabber/testuser1_40bellet_2einfo_2f5f842d89/CallChannel23/Content_video_2/Stream0x6210000173c0"
(gdb) bt
#0  tp_base_call_stream_update_local_sending_state (self=0x621000073c40, new_state=TP_SENDING_STATE_SENDING, actor_handle=0, reason=TP_CALL_STATE_CHANGE_REASON_USER_REQUESTED, dbus_reason=0x7f9e193f1820 "", message=0x7f9e193f24e0 "User accepted the Call") at base-call-stream.c:
553
#1  0x00007f9e1916460e in _tp_base_call_content_accepted (self=0x62500015a730, actor_handle=0) at base-call-content.c:857
#2  0x00007f9e17fadb5d in g_list_foreach (list=<optimized out>, func=0x7f9e191643ff <_tp_base_call_content_accepted>, user_data=0x0) at glist.c:1005
#3  0x00007f9e1916060a in tp_base_call_channel_accept_real (self=0x62500000b200) at base-call-channel.c:1435
#4  0x00007f9e19191f23 in tp_base_media_call_channel_try_accept (self=0x62500000b200) at base-media-call-channel.c:198
#5  0x00007f9e19191fb7 in streams_changed_cb (stream=0x621000073c40, spec=0x621000083f20, self=0x62500000b200) at base-media-call-channel.c:208
#6  0x00007f9e184893e5 in g_closure_invoke (closure=0x607000049920, return_value=return_value@entry=0x0, n_param_values=2, param_values=param_values@entry=0x7ffc209c74c0, invocation_hint=invocation_hint@entry=0x7ffc209c7440) at gclosure.c:804
#7  0x00007f9e1849b432 in signal_emit_unlocked_R (node=node@entry=0x60800000a3a0, detail=detail@entry=1119, instance=instance@entry=0x621000073c40, emission_return=emission_return@entry=0x0, instance_and_params=instance_and_params@entry=0x7ffc209c74c0) at gsignal.c:3629
#8  0x00007f9e184a405f in g_signal_emit_valist (instance=<optimized out>, signal_id=<optimized out>, detail=<optimized out>, var_args=var_args@entry=0x7ffc209c7690) at gsignal.c:3385
#9  0x00007f9e184a443f in g_signal_emit (instance=instance@entry=0x621000073c40, signal_id=<optimized out>, detail=<optimized out>) at gsignal.c:3441
#10 0x00007f9e1848d814 in g_object_dispatch_properties_changed (object=0x621000073c40, n_pspecs=<optimized out>, pspecs=<optimized out>) at gobject.c:1062
#11 0x00007f9e1848fd01 in g_object_notify_by_spec_internal (pspec=0x621000083f20, object=0x621000073c40) at gobject.c:1155
#12 g_object_notify (object=0x621000073c40, property_name=<optimized out>) at gobject.c:1203
#13 0x00007f9e1919e2c3 in tp_base_media_call_stream_complete_receiving_state_change (iface=0x621000073c40, state=TP_STREAM_FLOW_STATE_STARTED, context=0x6040000d5990) at base-media-call-stream.c:1309
#14 0x00007f9e193be272 in tp_svc_call_stream_interface_media_complete_receiving_state_change (self=0x621000073c40, in_State=3, context=0x6040000d5990) at _gen/tp-svc-call-stream.c:331
#15 0x00007f9e14ff2c58 in ffi_call_unix64 () at ../src/x86/unix64.S:76
#16 0x00007f9e14ff26ba in ffi_call (cif=cif@entry=0x7ffc209c7bc0, fn=fn@entry=0x7f9e193be1e0 <tp_svc_call_stream_interface_media_complete_receiving_state_change>, rvalue=<optimized out>, avalue=avalue@entry=0x7ffc209c7ad0) at ../src/x86/ffi64.c:525
#17 0x00007f9e18489c1e in g_cclosure_marshal_generic (closure=0x7ffc209c7d90, return_gvalue=0x0, n_param_values=<optimized out>, param_values=<optimized out>, invocation_hint=<optimized out>, marshal_data=<optimized out>) at gclosure.c:1490
#18 0x00007f9e1a95255b in object_registration_message () from /lib64/libdbus-glib-1.so.2
#19 0x00007f9e1a719a33 in _dbus_object_tree_dispatch_and_unlock () from /lib64/libdbus-1.so.3
#20 0x00007f9e1a70b0a4 in dbus_connection_dispatch () from /lib64/libdbus-1.so.3
#21 0x00007f9e1a94f8d5 in message_queue_dispatch () from /lib64/libdbus-glib-1.so.2
#22 0x00007f9e17fb16ba in g_main_dispatch (context=0x60f00000ec80) at gmain.c:3154
#23 g_main_context_dispatch (context=context@entry=0x60f00000ec80) at gmain.c:3769
#24 0x00007f9e17fb1a70 in g_main_context_iterate (context=0x60f00000ec80, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3840
#25 0x00007f9e17fb1d92 in g_main_loop_run (loop=0x602000008110) at gmain.c:4034
#26 0x00007f9e19392850 in tp_run_connection_manager (prog_name=0x55dba0 "telepathy-gabble", version=0x55db60 "0.18.2", construct_cm=0x42752d <construct_cm>, argc=1, argv=0x7ffc209c83c8) at run.c:284
#27 0x0000000000427b1c in gabble_main (argc=1, argv=0x7ffc209c83c8) at gabble.c:177
#28 0x000000000042751b in main (argc=1, argv=0x7ffc209c83c8) at main.c:33

Just dropping the call to the accept method of the parent class line 198 is just ok to make it work for me, but I'm wondering if there may be other situations where that is required ?