After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 620056 - Audio Calls using Google Talk (Jabber/XMPP) get stuck during connection phase
Audio Calls using Google Talk (Jabber/XMPP) get stuck during connection phase
Status: RESOLVED NOTGNOME
Product: empathy
Classification: Core
Component: VoIP
2.30.x
Other Linux
: Normal major
: ---
Assigned To: empathy-maint
Depends on:
Blocks:
 
 
Reported: 2010-05-29 23:01 UTC by tarunkhanna
Modified: 2010-06-02 14:39 UTC
See Also:
GNOME target: ---
GNOME version: ---

Attachments
Debug Information for Empathy (10.57 KB, text/plain)
2010-05-29 23:02 UTC, tarunkhanna 		Details
Debug Information for Gabble (19.89 KB, text/plain)
2010-05-29 23:03 UTC, tarunkhanna 		Details

Description tarunkhanna 2010-05-29 23:01:18 UTC 
I trying to make an audio call in empathy using Google Talk account with another Windows Laptop running google talk within firefox in gmail. The call never goes past the connecting stage. I have attached the debugging information for both empathy and gabble.

Here is the debug info for empathy followed by debug information for gabble ...

empathy/Other-DEBUG: 05/29/2010 18:45:21.658870: builder_get_file_valist: Loading file /usr/share/empathy/empathy-call-window.ui
empathy/Other-DEBUG: 05/29/2010 18:45:21.976522: empathy_signal_connect_weak: connecting to 0x1587700:peak-level-changed with context 0x16300a0
empathy/Other-DEBUG: 05/29/2010 18:45:22.24013: builder_get_file_valist: Loading file /usr/share/empathy/empathy-call-window-fullscreen.ui
empathy/(null)-DEBUG: 05/29/2010 18:45:22.130932: tp_contact_factory_add_contact: Contact added: xxx@yy.com (1)
empathy/(null)-DEBUG: 05/29/2010 18:45:22.160115: tp_contact_factory_weak_notify: Remove finalized contact 0x1666980
empathy/Contact-DEBUG: 05/29/2010 18:45:22.166188: contact_finalize: finalize: 0x1666980
empathy/(null)-DEBUG: 05/29/2010 18:45:22.183268: tp_contact_factory_got_known_avatar_tokens: Got 1 tokens, need to request 0 avatars
empathy/Dispatcher-DEBUG: 05/29/2010 18:45:22.203097: dispatcher_connection_new_channel: outgoing channel of type org.freedesktop.Telepathy.Channel.Type.StreamedMedia on /org/freedesktop/Telepathy/Connection/gabble/jabber/xxx@yy_2ecom_2f5e344a23/MediaChannel4
empathy/Dispatcher-DEBUG: 05/29/2010 18:45:22.203721: dispatcher_connection_new_channel: Channel satified request /com/nokia/MissionControl/requests/r6(already dispatched: 0)
empathy/Dispatcher-DEBUG: 05/29/2010 18:45:22.203774: dispatcher_start_dispatching: Dispatching process started for /org/freedesktop/Telepathy/Connection/gabble/jabber/xxx@yy_2ecom_2f5e344a23/MediaChannel4
empathy/Dispatcher-DEBUG: 05/29/2010 18:45:22.240291: dispatcher_channel_request_succeeded_cb: Request succeeded: /com/nokia/MissionControl/requests/r6
empathy/Dispatcher-DEBUG: 05/29/2010 18:45:22.355253: empathy_dispatch_operation_set_status: Dispatch operation /org/freedesktop/Telepathy/Connection/gabble/jabber/xxx@yy_2ecom_2f5e344a23/MediaChannel4 status: 0 -> 1
empathy/Dispatcher-DEBUG: 05/29/2010 18:45:22.355326: dispatch_operation_ready_cb: Send to observers: /org/freedesktop/Telepathy/Connection/gabble/jabber/xxx@yy_2ecom_2f5e344a23/MediaChannel4
empathy/Dispatcher-DEBUG: 05/29/2010 18:45:22.355380: empathy_dispatch_operation_set_status: Dispatch operation /org/freedesktop/Telepathy/Connection/gabble/jabber/xxx@yy_2ecom_2f5e344a23/MediaChannel4 status: 1 -> 3
empathy/Other-DEBUG: 05/29/2010 18:45:22.355441: empathy_signal_connect_weak: connecting to 0x155c370:audio-stream-error with context 0x15f22c0
empathy/Other-DEBUG: 05/29/2010 18:45:22.355492: empathy_signal_connect_weak: connecting to 0x155c370:video-stream-error with context 0x14f7940
empathy/Voip-DEBUG: 05/29/2010 18:45:22.355576: tp_call_request_streams_for_capabilities: Requesting new stream for capabilities 1
empathy/Dispatcher-DEBUG: 05/29/2010 18:45:22.355685: empathy_dispatch_operation_set_status: Dispatch operation /org/freedesktop/Telepathy/Connection/gabble/jabber/xxx@yy_2ecom_2f5e344a23/MediaChannel4 status: 3 -> 4
empathy/Dispatcher-DEBUG: 05/29/2010 18:45:22.355741: dispatch_operation_claimed_cb: Channel claimed: /org/freedesktop/Telepathy/Connection/gabble/jabber/xxx@yy_2ecom_2f5e344a23/MediaChannel4
empathy/Voip-DEBUG: 05/29/2010 18:45:22.370340: tp_call_add_stream: Audio stream - id: 1, state: 0, direction: 3
empathy/Voip-DEBUG: 05/29/2010 18:45:22.370448: tp_call_stream_added_cb: Stream added - stream id: 1, contact handle: 5, stream type: 0
empathy/Voip-DEBUG: 05/29/2010 18:45:22.370496: tp_call_add_stream: Audio stream - id: 1, state: 0, direction: 0
empathy/Voip-DEBUG: 05/29/2010 18:45:22.370577: tp_call_stream_direction_changed_cb: Stream direction changed - stream: 1, direction: 3
tp-fs-DEBUG: 05/29/2010 18:45:22.372277: GetSessionHandlers replied: 
tp-fs-DEBUG: 05/29/2010 18:45:22.372452:   - session /org/freedesktop/Telepathy/Connection/gabble/jabber/xxx@yy_2ecom_2f5e344a23/MediaChannel4
tp-fs-DEBUG: 05/29/2010 18:45:22.372517:     type rtp
tp-fs-DEBUG: 05/29/2010 18:45:22.372581: adding session handler /org/freedesktop/Telepathy/Connection/gabble/jabber/xxx@yy_2ecom_2f5e344a23/MediaChannel4, type rtp
tp-fs-DEBUG: 05/29/2010 18:45:22.372993: calling MediaSessionHandler::Ready
tp-fs-DEBUG: 05/29/2010 18:45:22.379175: New stream, stream_id=1, media_type=0, direction=3
tp-fs-DEBUG: 05/29/2010 18:45:22.388186: stream 1 0x14d8910 (audio) get_all_properties_cb: Adding STUN server 74.125.47.126:19302
tp-fs-DEBUG: 05/29/2010 18:45:22.639502: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: called (send_local:1 send_supported:0)
tp-fs-DEBUG: 05/29/2010 18:45:22.639659: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 103: audio SPEEX clock:8000 channels:1
tp-fs-DEBUG: 05/29/2010 18:45:22.639760: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 104: audio SPEEX clock:16000 channels:1
tp-fs-DEBUG: 05/29/2010 18:45:22.639830: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 98: audio AMR clock:8000 channels:1 octet-align=1 crc=0 robust-sorting=0 interleaving=0
tp-fs-DEBUG: 05/29/2010 18:45:22.639895: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 96: audio SIREN clock:16000 channels:0 bitrate=16000
tp-fs-DEBUG: 05/29/2010 18:45:22.639959: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 0: audio PCMU clock:8000 channels:0
tp-fs-DEBUG: 05/29/2010 18:45:22.640022: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 8: audio PCMA clock:8000 channels:0
tp-fs-DEBUG: 05/29/2010 18:45:22.640084: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 3: audio GSM clock:8000 channels:0
tp-fs-DEBUG: 05/29/2010 18:45:22.640147: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 100: audio telephone-event clock:16000 channels:0 events=0-15
tp-fs-DEBUG: 05/29/2010 18:45:22.640212: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 101: audio telephone-event clock:8000 channels:0 events=0-15
tp-fs-DEBUG: 05/29/2010 18:45:22.640300: stream 1 0x14d8910 (audio) fs_codecs_to_tp: adding codec SPEEX [103]
tp-fs-DEBUG: 05/29/2010 18:45:22.640378: stream 1 0x14d8910 (audio) fs_codecs_to_tp: adding codec SPEEX [104]
tp-fs-DEBUG: 05/29/2010 18:45:22.640465: stream 1 0x14d8910 (audio) fs_codecs_to_tp: adding codec AMR [98]
tp-fs-DEBUG: 05/29/2010 18:45:22.640543: stream 1 0x14d8910 (audio) fs_codecs_to_tp: adding codec SIREN [96]
tp-fs-DEBUG: 05/29/2010 18:45:22.640619: stream 1 0x14d8910 (audio) fs_codecs_to_tp: adding codec PCMU [0]
tp-fs-DEBUG: 05/29/2010 18:45:22.640696: stream 1 0x14d8910 (audio) fs_codecs_to_tp: adding codec PCMA [8]
tp-fs-DEBUG: 05/29/2010 18:45:22.640770: stream 1 0x14d8910 (audio) fs_codecs_to_tp: adding codec GSM [3]
tp-fs-DEBUG: 05/29/2010 18:45:22.640849: stream 1 0x14d8910 (audio) fs_codecs_to_tp: adding codec telephone-event [100]
tp-fs-DEBUG: 05/29/2010 18:45:22.640928: stream 1 0x14d8910 (audio) fs_codecs_to_tp: adding codec telephone-event [101]
tp-fs-DEBUG: 05/29/2010 18:45:22.640989: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: calling MediaStreamHandler::Ready
tp-fs-DEBUG: 05/29/2010 18:45:22.657552: stream 1 0x14d8910 (audio) set_stream_playing: 0
tp-fs-DEBUG: 05/29/2010 18:45:22.658818: stream 1 0x14d8910 (audio) set_stream_sending: 0
tp-fs-DEBUG: 05/29/2010 18:45:22.662602: stream 1 0x14d8910 (audio) cb_fs_new_local_candidate: called
tp-fs-DEBUG: 05/29/2010 18:45:22.666122: stream 1 0x14d8910 (audio) cb_fs_new_local_candidate: called
tp-fs-DEBUG: 05/29/2010 18:45:22.668656: stream 1 0x14d8910 (audio) cb_fs_new_local_candidate: called
tp-fs-DEBUG: 05/29/2010 18:45:22.669770: stream 1 0x14d8910 (audio) cb_fs_new_local_candidate: called
tp-fs-DEBUG: 05/29/2010 18:45:22.669992: stream 1 0x14d8910 (audio) _tf_stream_bus_message: Codecs changed
tp-fs-DEBUG: 05/29/2010 18:45:22.670058: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: called (send_local:0 send_supported:0)
tp-fs-DEBUG: 05/29/2010 18:45:22.670161: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 103: audio SPEEX clock:8000 channels:1
tp-fs-DEBUG: 05/29/2010 18:45:22.670226: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 104: audio SPEEX clock:16000 channels:1
tp-fs-DEBUG: 05/29/2010 18:45:22.670296: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 98: audio AMR clock:8000 channels:1 octet-align=1 crc=0 robust-sorting=0 interleaving=0
tp-fs-DEBUG: 05/29/2010 18:45:22.670363: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 96: audio SIREN clock:16000 channels:0 bitrate=16000
tp-fs-DEBUG: 05/29/2010 18:45:22.670428: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 0: audio PCMU clock:8000 channels:0
tp-fs-DEBUG: 05/29/2010 18:45:22.670490: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 8: audio PCMA clock:8000 channels:0
tp-fs-DEBUG: 05/29/2010 18:45:22.670552: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 3: audio GSM clock:8000 channels:0
tp-fs-DEBUG: 05/29/2010 18:45:22.670618: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 100: audio telephone-event clock:16000 channels:0 events=0-15
tp-fs-DEBUG: 05/29/2010 18:45:22.670681: stream 1 0x14d8910 (audio) _tf_stream_try_sending_codecs: 101: audio telephone-event clock:8000 channels:0 events=0-15
tp-fs-DEBUG: 05/29/2010 18:45:22.670815: stream 1 0x14d8910 (audio) cb_fs_new_local_candidate: called
tp-fs-DEBUG: 05/29/2010 18:45:22.670896: stream 1 0x14d8910 (audio) cb_fs_new_local_candidate: called
tp-fs-DEBUG: 05/29/2010 18:45:22.670972: stream 1 0x14d8910 (audio) cb_fs_new_local_candidate: called
tp-fs-DEBUG: 05/29/2010 18:45:22.671047: stream 1 0x14d8910 (audio) cb_fs_new_local_candidate: called
tp-fs-DEBUG: 05/29/2010 18:45:22.671169: stream 1 0x14d8910 (audio) cb_fs_local_candidates_prepared: called
tp-fs-DEBUG: 05/29/2010 18:45:22.671241: stream 1 0x14d8910 (audio) cb_fs_local_candidates_prepared: candidate->ip = '192.168.3.1'
tp-fs-DEBUG: 05/29/2010 18:45:22.671323: stream 1 0x14d8910 (audio) cb_fs_local_candidates_prepared: candidate->ip = '192.168.3.1'
tp-fs-DEBUG: 05/29/2010 18:45:22.687321: stream 1 0x14d8910 (audio) cb_fs_local_candidates_prepared: candidate->ip = '192.168.1.3'
tp-fs-DEBUG: 05/29/2010 18:45:22.687535: stream 1 0x14d8910 (audio) cb_fs_local_candidates_prepared: candidate->ip = '192.168.1.3'
tp-fs-DEBUG: 05/29/2010 18:45:22.687756: stream 1 0x14d8910 (audio) cb_fs_local_candidates_prepared: candidate->ip = '173.76.13.97'
tp-fs-DEBUG: 05/29/2010 18:45:22.687835: stream 1 0x14d8910 (audio) cb_fs_local_candidates_prepared: candidate->ip = '173.76.13.97'
tp-fs-DEBUG: 05/29/2010 18:45:22.688235: stream 1 0x14d8910 (audio) cb_fs_local_candidates_prepared: candidate->ip = '173.76.13.97'
tp-fs-DEBUG: 05/29/2010 18:45:22.688314: stream 1 0x14d8910 (audio) cb_fs_local_candidates_prepared: candidate->ip = '173.76.13.97'
empathy/Voip-DEBUG: 05/29/2010 18:45:22.688637: tp_call_stream_state_changed_cb: Stream state changed - stream id: 1, state state: 1


















--------------------- Gabble Debug Information ----------------------------

gabble/location-DEBUG: 05/29/2010 18:47:29.419630: location_get_locations: GetLocation for contacts:
LM-DEBUG: 05/29/2010 18:47:29.419750: 
SEND:
LM-DEBUG: 05/29/2010 18:47:29.419796: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:29.419842: <iq type="get" to="xxx@yy.com" id="583419712"> <pubsub xmlns="http://jabber.org/protocol/pubsub"> <items node="http://jabber.org/protocol/geoloc"></items>
</pubsub>
</iq>
LM-DEBUG: 05/29/2010 18:47:29.419883: -----------------------------------
gabble/location-DEBUG: 05/29/2010 18:47:29.420078: get_cached_location_or_query:  - xxx@yy.com: requested
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.453454: new_media_channel: object path /org/freedesktop/Telepathy/Connection/gabble/jabber/xxx@yy_2ecom_2f5e344a23/MediaChannel5
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.453510: media_channel_request_streams: no streams to request
LM-DEBUG: 05/29/2010 18:47:29.463735: 
RECV [328]:
LM-DEBUG: 05/29/2010 18:47:29.463857: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:29.463907: '<iq type="error" to="xxx@yy.com"> <pubsub xmlns="http://jabber.org/protocol/pubsub"> <items node="http://jabber.org/protocol/geoloc"/>
</pubsub>
<error code="501" type="cancel"><feature-not-implemented xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/></error></iq>'
LM-DEBUG: 05/29/2010 18:47:29.463948: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:29.463989: Read: 328 chars
LM-DEBUG: 05/29/2010 18:47:29.464044: ATTRIBUTE: type = error
LM-DEBUG: 05/29/2010 18:47:29.464087: ATTRIBUTE: to = xxx@yy.com/5e344a23
LM-DEBUG: 05/29/2010 18:47:29.464129: ATTRIBUTE: id = 583419712
LM-DEBUG: 05/29/2010 18:47:29.464171: ATTRIBUTE: from = xxx@yy.com
LM-DEBUG: 05/29/2010 18:47:29.464217: ATTRIBUTE: xmlns = http://jabber.org/protocol/pubsub
LM-DEBUG: 05/29/2010 18:47:29.464262: ATTRIBUTE: node = http://jabber.org/protocol/geoloc
LM-DEBUG: 05/29/2010 18:47:29.464304: Trying to close node: items
LM-DEBUG: 05/29/2010 18:47:29.464346: Trying to close node: pubsub
LM-DEBUG: 05/29/2010 18:47:29.464390: ATTRIBUTE: code = 501
LM-DEBUG: 05/29/2010 18:47:29.464432: ATTRIBUTE: type = cancel
LM-DEBUG: 05/29/2010 18:47:29.464474: ATTRIBUTE: xmlns = urn:ietf:params:xml:ns:xmpp-stanzas
LM-DEBUG: 05/29/2010 18:47:29.464517: Trying to close node: feature-not-implemented
LM-DEBUG: 05/29/2010 18:47:29.464559: Trying to close node: error
LM-DEBUG: 05/29/2010 18:47:29.464601: Trying to close node: iq
LM-DEBUG: 05/29/2010 18:47:29.464643: Have a new message
LM-DEBUG: 05/29/2010 18:47:29.477253: New message with type="iq" from: xxx@yy.com
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.639296: _gabble_media_channel_request_contents: called
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.639363: _gabble_media_channel_request_contents: picking the best resource (want audio: 1, want video: 0
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.639411: _gabble_media_channel_request_contents: Picking resource 'Home1E9B0768' (transport: urn:xmpp:jingle:transports:ice-udp:1, dialect: 4)
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.639456: create_session: 0x2091d10: Creating new outgoing session
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.639550: create_session: new session (5, Home1E9B0768, 468460027) @ 0x208ece0
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.639595: _latch_to_session: 0x2091d10: Latching onto session 0x208ece0
gabble/jid-DEBUG: 05/29/2010 18:47:29.639646: gabble_signal_connect_weak: connecting to 0x208ece0:remote-state-changed with context 0x240b6c0
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.639734: _gabble_media_channel_request_contents: changing nat-traversal property to ice-udp
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.639842: _gabble_media_channel_request_contents: Creating new jingle content with ns urn:xmpp:jingle:apps:rtp:1 : urn:xmpp:jingle:transports:ice-udp:1
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.639889: create_content: session creating new content type, conn == 0x20a00d0, jf == 0x20a8010
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.639944: gabble_jingle_content_init: 0x2091270
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.640022: create_content: inserting content stream1 into initiator_contents
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.640068: session_new_content_cb: called
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.640259: gabble_media_stream_set_property: 0x242c5c0: connecting to content 0x2091270 signals
gabble/jid-DEBUG: 05/29/2010 18:47:29.640305: gabble_signal_connect_weak: connecting to 0x2091270:new-candidates with context 0x20abea0
gabble/jid-DEBUG: 05/29/2010 18:47:29.640352: gabble_signal_connect_weak: connecting to 0x2091270:remote-codecs with context 0x242cd60
gabble/jid-DEBUG: 05/29/2010 18:47:29.640398: gabble_signal_connect_weak: connecting to 0x2091270:notify::state with context 0x23a2e80
gabble/jid-DEBUG: 05/29/2010 18:47:29.640444: gabble_signal_connect_weak: connecting to 0x2091270:notify::senders with context 0x2422160
gabble/jid-DEBUG: 05/29/2010 18:47:29.640491: gabble_signal_connect_weak: connecting to 0x208ece0:remote-state-changed with context 0x240b660
gabble/jid-DEBUG: 05/29/2010 18:47:29.640537: gabble_signal_connect_weak: connecting to 0x2091270:removed with context 0x241bcc0
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.640592: gabble_media_stream_set_property: stream stream1 connection state 0
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.640638: gabble_media_stream_set_property: changing combined direction from 0 to 0
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.649940: update_direction: called
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.650023: update_direction: setting pending local send flag
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.650075: gabble_media_stream_set_property: changing combined direction from 0 to 6
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.650125: gabble_media_stream_set_property: changing combined direction from 6 to 3
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.650186: construct_stream: 0x2091d10: created new MediaStream 0x242c5c0 for content 'stream1'
gabble/jid-DEBUG: 05/29/2010 18:47:29.650290: gabble_signal_connect_weak: connecting to 0x242c5c0:close with context 0x240b520
gabble/jid-DEBUG: 05/29/2010 18:47:29.650340: gabble_signal_connect_weak: connecting to 0x242c5c0:error with context 0x242ce60
gabble/jid-DEBUG: 05/29/2010 18:47:29.650387: gabble_signal_connect_weak: connecting to 0x242c5c0:notify::connection-state with context 0x239f800
gabble/jid-DEBUG: 05/29/2010 18:47:29.650435: gabble_signal_connect_weak: connecting to 0x242c5c0:notify::combined-direction with context 0x239f4a0
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.650482: construct_stream: emitting StreamAdded with type 'audio'
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.650559: stream_direction_changed_cb: direction: 3, pending_send: 0
gabble/jid-DEBUG: 05/29/2010 18:47:29.650635: gabble_signal_connect_weak: connecting to 0x242c5c0:unhold-failed with context 0x23688a0
gabble/jid-DEBUG: 05/29/2010 18:47:29.650682: gabble_signal_connect_weak: connecting to 0x242c5c0:notify::local-hold with context 0x20a5a80
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.650731: stream_hold_state_changed: Stream at index 0 has local-hold=0
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.650773: stream_hold_state_changed: all_held=0, any_held=0
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.650908: new_remote_codecs_cb: called
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.650954: new_remote_codecs_cb: pushing remote codecs
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.650999: new_remote_candidates_cb: got new remote candidates
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.674954: gabble_media_channel_ready: emitting NewStreamHandler for each stream
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.675055: _emit_new_stream: emitting MediaSessionHandler:NewStreamHandler signal for audio stream 1 
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.897409: gabble_media_stream_ready: ready called
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.897511: push_playing: stream stream1 emitting SetStreamPlaying(false)
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.897574: push_sending: stream stream1 emitting SetStreamSending(false); sending=false, on_hold=false
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.897634: gabble_media_stream_set_local_codecs: called
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.897680: pass_local_codecs: putting list of 9 supported codecs from stream-engine into cache
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.897782: pass_local_codecs: adding codec SPEEX (103 8000 1)
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.897839: pass_local_codecs: adding codec SPEEX (104 16000 1)
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.897902: pass_local_codecs: adding codec AMR (98 8000 1)
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.897958: pass_local_codecs: adding codec SIREN (96 16000 0)
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.898013: pass_local_codecs: adding codec PCMU (0 8000 0)
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.898066: pass_local_codecs: adding codec PCMA (8 8000 0)
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.898118: pass_local_codecs: adding codec GSM (3 8000 0)
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.898174: pass_local_codecs: adding codec telephone-event (100 16000 0)
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.898228: pass_local_codecs: adding codec telephone-event (101 8000 0)
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.898272: jingle_media_rtp_set_local_codecs: setting new local codecs
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.911945: gabble_media_stream_set_property: stream stream1 connection state 0
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.935900: gabble_jingle_content_add_candidates: called
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.935990: content_ready_cb: called
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.936136: content_state_changed_cb: called
LM-DEBUG: 05/29/2010 18:47:29.936332: 
SEND:
LM-DEBUG: 05/29/2010 18:47:29.936377: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:29.936427: <iq type="set" to="to@zz.com/Home1E9B0768" id="2249936039"> <jingle action="session-initiate" sid="468460027" initiator="xxx@yy.com/5e344a23" xmlns="urn:xmpp:jingle:1"> <content creator="initiator" senders="both" name="stream1"> <description xmlns="urn:xmpp:jingle:apps:rtp:1" media="audio"> <payload-type channels="1" clockrate="8000" name="SPEEX" id="103"></payload-type>
 <payload-type channels="1" clockrate="16000" name="SPEEX" id="104"></payload-type>
 <payload-type channels="1" clockrate="8000" name="AMR" id="98"> <parameter value="1" name="octet-align"></parameter>
 <parameter value="0" name="crc"></parameter>
 <parameter value="0" name="robust-sorting"></parameter>
 <parameter value="0" name="interleaving"></parameter>
</payload-type>
 <payload-type clockrate="16000" name="SIREN" id="96"> <parameter value="16000" name="bitrate"></parameter>
</payload-type>
 <payload-type clockrate="8000" name="PCMU" id="0"></payload-type>
 <payload-type clockrate="8000" name="PCMA" id="8"></payload-type>
 <payload-type clockrate="8000" name="GSM" id="3"></payload-type>
 <payload-type clockrate="16000" name="telephone-event" id="100"> <parameter value="0-15" name="events"></parameter>
</payload-type>
 <payload-type clockrate="8000" name="telephone-event" id="101"> <parameter value="0-15" name="events"></parameter>
</payload-type>
</description>
 <transport pwd="xcVzHT1CG/4O+fq7mMnw5O" ufrag="8rog" xmlns="urn:xmpp:jingle:transports:ice-udp:1"> <candidate generation="0" network="0" id="1" foundation="1" component="2" type="host" protocol="udp" priority="2013266430" port="33048" ip="192.168.3.1"></candidate>
 <candidate generation="0" network="0" id="2" foundation="1" component="1" type="host" protocol="udp" priority="2013266431" port="59653" ip="192.168.3.1"></candidate>
</transport>
</content>
</jingle>
</iq>
LM-DEBUG: 05/29/2010 18:47:29.936475: -----------------------------------
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.936738: set_state: Setting state of JingleSession: 0x208ece0 (priv = 0x208ed10) from 0 to 1
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.936796: session_state_changed_cb: called
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.940582: send_candidates: sent all pending candidates
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.940640: send_candidates: sent all pending candidates
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.940825: gabble_jingle_content_add_candidates: called
LM-DEBUG: 05/29/2010 18:47:29.940984: 
SEND:
LM-DEBUG: 05/29/2010 18:47:29.941030: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:29.941077: <iq type="set" to="to@zz.com/Home1E9B0768" id="6601940874"> <jingle action="transport-info" sid="468460027" initiator="xxx@yy.com/5e344a23" xmlns="urn:xmpp:jingle:1"> <content creator="initiator" senders="both" name="stream1"> <transport pwd="xcVzHT1CG/4O+fq7mMnw5O" ufrag="8rog" xmlns="urn:xmpp:jingle:transports:ice-udp:1"> <candidate generation="0" network="0" id="3" foundation="2" component="2" type="host" protocol="udp" priority="2013266430" port="39968" ip="192.168.1.3"></candidate>
 <candidate generation="0" network="0" id="4" foundation="2" component="1" type="host" protocol="udp" priority="2013266431" port="41922" ip="192.168.1.3"></candidate>
</transport>
</content>
</jingle>
</iq>
LM-DEBUG: 05/29/2010 18:47:29.941123: -----------------------------------
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.941257: send_candidates: sent all pending candidates
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.941386: gabble_jingle_content_add_candidates: called
LM-DEBUG: 05/29/2010 18:47:29.941519: 
SEND:
LM-DEBUG: 05/29/2010 18:47:29.941564: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:29.941612: <iq type="set" to="to@zz.com/Home1E9B0768" id="6603941433"> <jingle action="transport-info" sid="468460027" initiator="xxx@yy.com/5e344a23" xmlns="urn:xmpp:jingle:1"> <content creator="initiator" senders="both" name="stream1"> <transport pwd="xcVzHT1CG/4O+fq7mMnw5O" ufrag="8rog" xmlns="urn:xmpp:jingle:transports:ice-udp:1"> <candidate generation="0" network="0" id="5" foundation="3" component="2" type="srflx" protocol="udp" priority="1677721854" port="33048" ip="173.76.13.97"></candidate>
 <candidate generation="0" network="0" id="6" foundation="3" component="1" type="srflx" protocol="udp" priority="1677721855" port="59653" ip="173.76.13.97"></candidate>
</transport>
</content>
</jingle>
</iq>
LM-DEBUG: 05/29/2010 18:47:29.941656: -----------------------------------
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.941811: send_candidates: sent all pending candidates
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.959237: gabble_jingle_content_add_candidates: called
LM-DEBUG: 05/29/2010 18:47:29.959454: 
SEND:
LM-DEBUG: 05/29/2010 18:47:29.959501: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:29.959548: <iq type="set" to="to@zz.com/Home1E9B0768" id="33228959339"> <jingle action="transport-info" sid="468460027" initiator="xxx@yy.com/5e344a23" xmlns="urn:xmpp:jingle:1"> <content creator="initiator" senders="both" name="stream1"> <transport pwd="xcVzHT1CG/4O+fq7mMnw5O" ufrag="8rog" xmlns="urn:xmpp:jingle:transports:ice-udp:1"> <candidate generation="0" network="0" id="7" foundation="4" component="2" type="srflx" protocol="udp" priority="1677721854" port="39968" ip="173.76.13.97"></candidate>
 <candidate generation="0" network="0" id="8" foundation="4" component="1" type="srflx" protocol="udp" priority="1677721855" port="41922" ip="173.76.13.97"></candidate>
</transport>
</content>
</jingle>
</iq>
LM-DEBUG: 05/29/2010 18:47:29.959594: -----------------------------------
gabble/media-channel-DEBUG: 05/29/2010 18:47:29.959748: send_candidates: sent all pending candidates
LM-DEBUG: 05/29/2010 18:47:30.95706: 
RECV [115]:
LM-DEBUG: 05/29/2010 18:47:30.95827: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:30.95875: '<iq type="result" id="2249936039" from="to@zz.com/Home1E9B0768" to="xxx@yy.com/5e344a23"/>'
LM-DEBUG: 05/29/2010 18:47:30.95916: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:30.95958: Read: 115 chars
LM-DEBUG: 05/29/2010 18:47:30.96013: ATTRIBUTE: type = result
LM-DEBUG: 05/29/2010 18:47:30.96056: ATTRIBUTE: id = 2249936039
LM-DEBUG: 05/29/2010 18:47:30.96100: ATTRIBUTE: from = to@zz.com/Home1E9B0768
LM-DEBUG: 05/29/2010 18:47:30.96143: ATTRIBUTE: to = xxx@yy.com/5e344a23
LM-DEBUG: 05/29/2010 18:47:30.96187: Trying to close node: iq
LM-DEBUG: 05/29/2010 18:47:30.96231: Have a new message
LM-DEBUG: 05/29/2010 18:47:30.96275: New message with type="iq" from: to@zz.com/Home1E9B0768
LM-DEBUG: 05/29/2010 18:47:30.96374: 
RECV [115]:
LM-DEBUG: 05/29/2010 18:47:30.96417: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:30.96461: '<iq type="result" id="6601940874" from="to@zz.com/Home1E9B0768" to="xxx@yy.com/5e344a23"/>'
LM-DEBUG: 05/29/2010 18:47:30.96503: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:30.103255: Read: 115 chars
LM-DEBUG: 05/29/2010 18:47:30.103334: ATTRIBUTE: type = result
LM-DEBUG: 05/29/2010 18:47:30.103379: ATTRIBUTE: id = 6601940874
LM-DEBUG: 05/29/2010 18:47:30.104774: ATTRIBUTE: from = to@zz.com/Home1E9B0768
LM-DEBUG: 05/29/2010 18:47:30.104825: ATTRIBUTE: to = xxx@yy.com/5e344a23
LM-DEBUG: 05/29/2010 18:47:30.104872: Trying to close node: iq
LM-DEBUG: 05/29/2010 18:47:30.104918: Have a new message
LM-DEBUG: 05/29/2010 18:47:30.104962: New message with type="iq" from: to@zz.com/Home1E9B0768
LM-DEBUG: 05/29/2010 18:47:30.105083: 
RECV [115]:
LM-DEBUG: 05/29/2010 18:47:30.105129: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:30.105173: '<iq type="result" id="6603941433" from="to@zz.com/Home1E9B0768" to="xxx@yy.com/5e344a23"/>'
LM-DEBUG: 05/29/2010 18:47:30.105214: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:30.105254: Read: 115 chars
LM-DEBUG: 05/29/2010 18:47:30.105304: ATTRIBUTE: type = result
LM-DEBUG: 05/29/2010 18:47:30.105346: ATTRIBUTE: id = 6603941433
LM-DEBUG: 05/29/2010 18:47:30.105389: ATTRIBUTE: from = to@zz.com/Home1E9B0768
LM-DEBUG: 05/29/2010 18:47:30.105432: ATTRIBUTE: to = xxx@yy.com/5e344a23
LM-DEBUG: 05/29/2010 18:47:30.105474: Trying to close node: iq
LM-DEBUG: 05/29/2010 18:47:30.105516: Have a new message
LM-DEBUG: 05/29/2010 18:47:30.105607: New message with type="iq" from: to@zz.com/Home1E9B0768
gabble/media-channel-DEBUG: 05/29/2010 18:47:30.105669: set_state: Setting state of JingleSession: 0x208ece0 (priv = 0x208ed10) from 1 to 2
gabble/media-channel-DEBUG: 05/29/2010 18:47:30.105729: session_state_changed_cb: called
LM-DEBUG: 05/29/2010 18:47:30.111475: 
RECV [116]:
LM-DEBUG: 05/29/2010 18:47:30.111637: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:30.111682: '<iq type="result" id="33228959339" from="to@zz.com/Home1E9B0768" to="xxx@yy.com/5e344a23"/>'
LM-DEBUG: 05/29/2010 18:47:30.111726: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:30.111767: Read: 116 chars
LM-DEBUG: 05/29/2010 18:47:30.111820: ATTRIBUTE: type = result
LM-DEBUG: 05/29/2010 18:47:30.111864: ATTRIBUTE: id = 33228959339
LM-DEBUG: 05/29/2010 18:47:30.111906: ATTRIBUTE: from = to@zz.com/Home1E9B0768
LM-DEBUG: 05/29/2010 18:47:30.111948: ATTRIBUTE: to = xxx@yy.com/5e344a23
LM-DEBUG: 05/29/2010 18:47:30.111993: Trying to close node: iq
LM-DEBUG: 05/29/2010 18:47:30.112035: Have a new message
LM-DEBUG: 05/29/2010 18:47:30.112077: New message with type="iq" from: to@zz.com/Home1E9B0768
LM-DEBUG: 05/29/2010 18:47:44.171785: 
SEND:
LM-DEBUG: 05/29/2010 18:47:44.171895: -----------------------------------
LM-DEBUG: 05/29/2010 18:47:44.171941: 
LM-DEBUG: 05/29/2010 18:47:44.171986: -----------------------------------
LM-DEBUG: 05/29/2010 18:48:14.198945: 
SEND:
LM-DEBUG: 05/29/2010 18:48:14.199069: -----------------------------------
LM-DEBUG: 05/29/2010 18:48:14.199115: 
LM-DEBUG: 05/29/2010 18:48:14.199157: -----------------------------------
LM-DEBUG: 05/29/2010 18:48:44.228988: 
SEND:
LM-DEBUG: 05/29/2010 18:48:44.229104: -----------------------------------
LM-DEBUG: 05/29/2010 18:48:44.229151: 
LM-DEBUG: 05/29/2010 18:48:44.229229: -----------------------------------
Comment 1 tarunkhanna 2010-05-29 23:02:49 UTC 
Created attachment 162283 [details]
Debug Information for Empathy
Comment 2 tarunkhanna 2010-05-29 23:03:24 UTC 
Created attachment 162284 [details]
Debug Information for Gabble
Comment 3 tarunkhanna 2010-05-29 23:04:42 UTC 
I am running Empathy on 64 Bit Ubuntu Linux. Audio chats work perfectly fine with Skype, so the hardware drivers can't be at fault.
Comment 4 Guillaume Desmottes 2010-06-01 08:50:31 UTC 
Could you try upgrading to latest farsight2 please? You can find it on our PPA:
https://edge.launchpad.net/~telepathy/+archive/ppa
Comment 5 tarunkhanna 2010-06-01 13:28:00 UTC 
I'll try that tonight and let your know.

Thanks,
Tarun
Comment 6 Omer Akram 2010-06-02 13:44:42 UTC 
also reported at: https://bugs.launchpad.net/ubuntu/+source/empathy/+bug/585036
Comment 7 tarunkhanna 2010-06-02 13:55:47 UTC 
I was able to make audio call after adding the telepathy ppa found here https://edge.launchpad.net/~telepathy/+archive/ppa. I added the new ppa and did a simple upgrade of all installed packages.

I tested it on 64 bit Ubuntu and 32 Bit Ubuntu Netbook Remix.
Comment 8 Miro Hadzhiev (Хаджиев) 2010-06-02 14:10:48 UTC 
I've just tested it and now it works ok though the sound quality is not very good.