Bug 18117

Summary:	Disconnected while AV call
Product:	Telepathy	Reporter:	Guillaume Desmottes <guillaume.desmottes>
Component:	gabble	Assignee:	Telepathy bugs list <telepathy-bugs>
Status:	RESOLVED WONTFIX	QA Contact:	Telepathy bugs list <telepathy-bugs>
Severity:	normal
Priority:	medium	CC:	jjardon, om26er
Version:	unspecified
Hardware:	Other
OS:	All
Whiteboard:
i915 platform:		i915 features:

Description Guillaume Desmottes 2008-10-18 11:15:35 UTC

I accepted a jingle call using Empathy, tried to send video and the jabber connection was disconnected after few seconds.

ii  telepathy-gabble                           0.7.7-2~ppa8.04+2                                    Jabber/XMPP connection manager
ii  libtelepathy-glib-dev                      0.7.13-1~ppa8.04+2                                   GLib Telepathy connection manager library (h
ii  telepathy-stream-engine                    0.5.3-1~ppa8.04+1                                    stream handler for the Telepathy framework
ii  libloudmouth1-0                            1.3.4-1                                              Lightweight C Jabber library
ii  gstreamer0.10-plugins-farsight             0.12.9-2ubuntu1~ppa8.04+2                            plugins for GStreamer for Audio/Video confer
ii  libfarsight0.1-3                           0.1.28-2~ppa8.04+1                                   audio/video stream library
ii  empathy                                    2.24.0-1ubuntu1~ppa8.04+1                            High-level library and user-interface for Te



Here is the end of the log file:


RECV [579]:
-----------------------------------
'<iq from="cassidy@jabber.belnet.be/Laptop" to="chadoko@gmail.com/Telepathy4976F728" type="set" id="976028069"> <jingle initiator="cassidy@jabber.belnet.be/Laptop" action="transport-info" sid="734737906" xmlns="http://jabber.org/protocol/jingle"> <content creator="initiator" name="audio1"> <transport xmlns="http://www.google.com/transport/p2p"> <candidate generation="0" network="0" type="local" protocol="tcp" preference="0.800000" password="/t0bjB4MVbZg1uLM" username="wFq4KSzZ3W9slbFS" port="41466" address="192.168.0.101" name="rtp"/>
</transport>
</content>
</jingle>
</iq>'
-----------------------------------
** (telepathy-gabble:13773): DEBUG: media_factory_jingle_cb: dispatching to session 734737906
[[1m[37m19:04:31[0m] [1m[44mJS_STATE_ACTIVE           [0m [1m[37mgot jingle session action "transport-info" from peer[0m
[[1m[37m19:04:31[0m] [1m[44mJS_STATE_ACTIVE           [0m [1m[37mput 1 remote candidate from peer into cache[0m
[[1m[37m19:04:31[0m] [1m[44mJS_STATE_ACTIVE           [0m [1m[32m  from Jingle XML: [[22m<candidate name="rtp" address="192.168.0.101" port="41466" username="wFq4KSzZ3W9slbFS" password="/t0bjB4MVbZg1uLM" preference="0.800000" protocol="tcp" type="local" network="0" generation="0"></candidate>
[1m][0m
[[1m[37m19:04:31[0m] [1m[44mJS_STATE_ACTIVE           [0m [1m[32m  to Telepathy D-Bus struct: [[22m"R5", [1m[[22m1, "192.168.0.101", 41466, TP_MEDIA_STREAM_BASE_PROTO_TCP (1), "RTP", "AVP", 0.800000, TP_MEDIA_STREAM_TRANSPORT_TYPE_LOCAL (0), "wFq4KSzZ3W9slbFS", "/t0bjB4MVbZg1uLM"[1m]][0m
[[1m[37m19:04:31[0m] [1m[44mJS_STATE_ACTIVE           [0m [1m[36mpassing 1 remote candidate to stream-engine[0m

SEND:
-----------------------------------
<iq type="result" to="cassidy@jabber.belnet.be/Laptop" id="976028069"></iq>

-----------------------------------
[[1m[37m19:04:35[0m] [1m[44mJS_STATE_ACTIVE           [0m [1m[32mpresence for peer 2:
nickname: (null)
accumulated status: 7
accumulated status msg: (null)
accumulated capabilities: 895
kept while unavailable: 0
resources:
  Laptop
    capabilities: 895
    status: 7
    status msg: (null)
    priority: 10
[0m
[[1m[37m19:04:35[0m] [1m[44mJS_STATE_ACTIVE           [0m [1m[37mwant audio: no; want video: yes[0m
[[1m[37m19:04:35[0m] [1m[44mJS_STATE_ACTIVE           [0m [1m[37min Jingle mode, and have necessary caps[0m
[[1m[37m19:04:35[0m] [1m[44mJS_STATE_ACTIVE           [0m [1m[37mcreating new jingle video stream called "video1" with id 2[0m
[[1m[37m19:04:35[0m] [1m[44mJS_STATE_ACTIVE           [0m [1m[37mstream video1 connection state 0[0m
[[1m[37m19:04:35[0m] [1m[44mJS_STATE_ACTIVE           [0m [1m[37mstream video1 sig_state 0->0[0m
** (telepathy-gabble:13773): DEBUG: stream_hold_state_changed: Stream at index 0 has local-hold=0
** (telepathy-gabble:13773): DEBUG: stream_hold_state_changed: Stream at index 1 has local-hold=0
** (telepathy-gabble:13773): DEBUG: stream_hold_state_changed: all_held=0, any_held=0
Freeing up IOChannel and file descriptor
** (telepathy-gabble:13773): DEBUG: connection_disconnected_cb: called with reason 3
** (telepathy-gabble:13773): DEBUG: connection_disconnected_cb: unexpected; calling tp_base_connection_change_status
(telepathy-gabble:13773): tp-glib-DEBUG: tp_base_connection_change_status: was 0, now 2, for reason 2
** (telepathy-gabble:13773): DEBUG: gabble_roster_factory_iface_close_all: closing channels
** (telepathy-gabble:13773): DEBUG: gabble_muc_factory_iface_close_all: closing channels
** (telepathy-gabble:13773): DEBUG: gabble_media_factory_iface_close_all: closing channels
** (telepathy-gabble:13773): DEBUG: gabble_media_factory_iface_close_all: about to unref channel with ref_count 1
** (telepathy-gabble:13773): DEBUG: gabble_media_channel_close: called on 0x8104c68
[[1m[37m19:04:59[0m] [1m[44mJS_STATE_ACTIVE           [0m [1m[37msending jingle session action "session-terminate" to peer[0m
Connection is not open.
** (telepathy-gabble:13773): DEBUG: _gabble_connection_send_with_reply: failed: Connection is not open, call lm_connection_open() first
** (telepathy-gabble:13773): DEBUG: stream_hold_state_changed: Stream at index 0 has local-hold=0
** (telepathy-gabble:13773): DEBUG: stream_hold_state_changed: all_held=0, any_held=0
** (telepathy-gabble:13773): DEBUG: stream_hold_state_changed: all_held=1, any_held=0
** (telepathy-gabble:13773): DEBUG: stream_hold_state_changed: Unexpectedly entered HELD state!
[[1m[37m19:04:59[0m] [41mJS_STATE_ENDED            [0m [1m[36mstate changed from JS_STATE_ACTIVE to JS_STATE_ENDED[0m
[1m[36mtp_group_mixin_change_members: emitting members changed
  message       : ""
  added         : [[22m[1m]
  removed       : [[22m1 (chadoko@gmail.com)
              2 (cassidy@jabber.belnet.be)[1m]
  local_pending : [[22m[1m]
  remote_pending: [[22m[1m]
  actor         : 1
  reason        : 0: unspecified reason
[0m[1m[37mtp_group_mixin_change_flags: emitting group flags changed
  added    : [[22mCAN_ADD[1m]
  removed  : [[22mCAN_REMOVE[1m]
  flags now: [[22mCAN_ADD[1m]
[0m** (telepathy-gabble:13773): DEBUG: gabble_media_channel_close: called on 0x8104c68
** (telepathy-gabble:13773): DEBUG: gabble_media_session_dispose: called
** (telepathy-gabble:13773): DEBUG: gabble_im_factory_iface_close_all: closing channels
** (telepathy-gabble:13773): DEBUG: gabble_private_tubes_factory_iface_close_all: closing 1-1 tubes channels
(telepathy-gabble:13773): tp-glib-DEBUG: tp_base_connection_change_status: emitting status-changed to 2, for reason 2
** (telepathy-gabble:13773): DEBUG: gabble_roster_factory_iface_disconnected: removing callbacks
** (telepathy-gabble:13773): DEBUG: gabble_muc_factory_iface_disconnected: removing callbacks
** (telepathy-gabble:13773): DEBUG: gabble_media_factory_iface_disconnected: removing callbacks
** (telepathy-gabble:13773): DEBUG: gabble_im_factory_iface_disconnected: removing callbacks
** (telepathy-gabble:13773): DEBUG: connection_shut_down: closed; emitting DISCONNECTED
(telepathy-gabble:13773): tp-glib-DEBUG: connection_shutdown_finished_cb: dereferenced connection
** (telepathy-gabble:13773): DEBUG: gabble_connection_dispose: called
** (telepathy-gabble:13773): DEBUG: gabble_bytestream_factory_dispose: dispose called
** (telepathy-gabble:13773): DEBUG: gabble_disco_dispose: dispose called
** (telepathy-gabble:13773): DEBUG: gabble_disco_finalize: called with 0x80bf480
** (telepathy-gabble:13773): DEBUG: gabble_request_pipeline_dispose: disposing request-pipeline
** (telepathy-gabble:13773): DEBUG: gabble_vcard_manager_dispose: 0x80c20f0
** (telepathy-gabble:13773): DEBUG: gabble_vcard_manager_finalize: 0x80c20f0
** (telepathy-gabble:13773): DEBUG: gabble_presence_cache_dispose: dispose called
** (telepathy-gabble:13773): DEBUG: disco_waiter_list_free: list (nil)
** (telepathy-gabble:13773): DEBUG: disco_waiter_list_free: list (nil)
** (telepathy-gabble:13773): DEBUG: disco_waiter_list_free: list (nil)
** (telepathy-gabble:13773): DEBUG: disco_waiter_list_free: list (nil)
** (telepathy-gabble:13773): DEBUG: disco_waiter_list_free: list (nil)
** (telepathy-gabble:13773): DEBUG: disco_waiter_list_free: list (nil)
** (telepathy-gabble:13773): DEBUG: disco_waiter_list_free: list (nil)
** (telepathy-gabble:13773): DEBUG: disco_waiter_list_free: list (nil)
** (telepathy-gabble:13773): DEBUG: disco_waiter_list_free: list (nil)
** (telepathy-gabble:13773): DEBUG: disco_waiter_list_free: list (nil)
** (telepathy-gabble:13773): DEBUG: gabble_presence_cache_finalize: called with 0x80c2128
** (telepathy-gabble:13773): DEBUG: gabble_roster_dispose: dispose called
** (telepathy-gabble:13773): DEBUG: gabble_roster_factory_iface_close_all: closing channels
** (telepathy-gabble:13773): DEBUG: gabble_roster_finalize: called with 0x80c7230
** (telepathy-gabble:13773): DEBUG: gabble_muc_factory_dispose: dispose called
** (telepathy-gabble:13773): DEBUG: gabble_muc_factory_iface_close_all: closing channels
** (telepathy-gabble:13773): DEBUG: gabble_media_factory_dispose: dispose called
** (telepathy-gabble:13773): DEBUG: gabble_media_factory_iface_close_all: closing channels
** (telepathy-gabble:13773): DEBUG: gabble_im_factory_dispose: dispose called
** (telepathy-gabble:13773): DEBUG: gabble_im_factory_iface_close_all: closing channels
** (telepathy-gabble:13773): DEBUG: gabble_private_tubes_factory_dispose: dispose called
** (telepathy-gabble:13773): DEBUG: gabble_private_tubes_factory_iface_close_all: closing 1-1 tubes channels
(telepathy-gabble:13773): tp-glib-DEBUG: tp_proxy_signal_connection_lost_weak_ref: 0x80c2010: lost weak ref to 0x80c7150
(telepathy-gabble:13773): tp-glib-DEBUG: tp_proxy_signal_connection_lost_weak_ref: 0x80c2048: lost weak ref to 0x80c7180
(telepathy-gabble:13773): tp-glib-DEBUG: tp_proxy_signal_connection_lost_weak_ref: 0x80c2080: lost weak ref to 0x80c71b0
** (telepathy-gabble:13773): DEBUG: gabble_connection_finalize: called with 0x80c8068
(telepathy-gabble:13773): tp-glib-DEBUG: tp_presence_mixin_finalize: 0x80c8068
(telepathy-gabble:13773): tp-glib-DEBUG: no connections, and timed out

Comment 1 Guillaume Desmottes 2008-10-18 11:48:48 UTC

Same problem with loudmouth 1.4.2

Comment 2 Guillaume Desmottes 2008-10-18 12:32:18 UTC

http://people.collabora.co.uk/~cassidy/trace2.log.gz contains full log and strace output.
It seems that's the server (google talk) who close the connection.

This problem is reproductible using either old SSL or TLS.

Comment 3 Javier Jardón 2009-08-12 15:59:14 UTC

Maybe related with this downstream bug:

https://bugs.launchpad.net/telepathy-gabble/+bug/411978

( reported in gnome bugzilla here: http://bugzilla.gnome.org/show_bug.cgi?id=591620 )

Comment 4 Daniel Stone 2019-12-09 11:18:42 UTC

Unfortunately Bugzilla generates invalid XML when trying to export this bug, so I can't move it to GitLab. However, it does seem very unlikely that it would get fixed ...

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.