Attachment 38597 Details for Bug 29785 – Sofiasip debug output from caller

Sofiasip debug output from caller

caller.debug.txt (text/plain), 15.55 KB, created by Chris Vine on 2010-09-10 02:35:35 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Chris Vine

Created: 2010-09-10 02:35:35 UTC

Size: 15.55 KB

patch

obsolete

>tpsip/connection-DEBUG: 10/09/10 10:18:59.481316: conn_get_alias: handle 2 got alias vine.chris@sip.antisip.com
>tpsip/connection-DEBUG: 10/09/10 10:19:00.160294: conn_get_alias: handle 1 got alias cvine@sip.antisip.com
>tpsip/connection-DEBUG: 10/09/10 10:19:01.320349: new_media_channel: channel object path /org/freedesktop/Telepathy/Connection/sofiasip/sip/cvine_40sip_2eantisip_2ecom/MediaChannel1
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.320899: tpsip_media_channel_constructed: registering object to dbus path=/org/freedesktop/Telepathy/Connection/sofiasip/sip/cvine_40sip_2eantisip_2ecom/MediaChannel1
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.342957: priv_outbound_call: making outbound call - setting peer handle to 2
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.343245: priv_create_session: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.355875: priv_create_session: allocating session, peer=2
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.356472: priv_create_session: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.648871: tpsip_media_channel_request_streams: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.649127: priv_outbound_call: session already exists
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.649296: tpsip_media_session_request_streams: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.649458: tpsip_media_session_add_stream: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.650353: tpsip_media_session_add_stream: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.650604: tpsip_media_session_add_stream: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.651379: tpsip_media_session_add_stream: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.662538: priv_request_response_step: there are local streams not ready, postponed
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.662995: tpsip_media_channel_request_streams: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.673974: tpsip_media_channel_get_session_handlers: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.698450: tpsip_media_session_ready: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.911988: tpsip_media_stream_ready: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:01.912542: push_active_candidate_pair: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.188970: tpsip_media_stream_ready: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.189450: push_active_candidate_pair: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.221699: tpsip_media_stream_native_candidates_prepared: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.222748: priv_request_response_step: there are local streams not ready, postponed
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.222955: priv_stream_ready_cb: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.223115: priv_request_response_step: there are local streams not ready, postponed
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.223272: push_active_candidate_pair: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.242958: tpsip_media_stream_native_candidates_prepared: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.244960: priv_request_response_step: there are local streams not ready, postponed
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.245233: priv_stream_ready_cb: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.245589: priv_session_invite: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.245887: tpsip_media_stream_set_playing: set playing to TRUE
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.246159: tpsip_media_stream_set_playing: set playing to TRUE
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.246444: priv_session_state_changed_cb: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.259021: push_active_candidate_pair: enter
>tpsip/events-DEBUG: 10/09/10 10:19:02.265168: tpsip_connection_sofia_callback: event nua_i_state: 000 INVITE sent
>tpsip/events-DEBUG: 10/09/10 10:19:02.265460: tpsip_connection_sofia_callback: connection 0x8099930, refcount 2
>tpsip/events-DEBUG: 10/09/10 10:19:02.265630: tpsip_connection_sofia_callback: dispatching to target 0x80aa168 (handle 0x80b3130)
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.265917: priv_nua_i_state_cb: call with handle 0x80b3130 is calling
>tpsip/events-DEBUG: 10/09/10 10:19:02.266114: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 10/09/10 10:19:02.345340: tpsip_connection_sofia_callback: event nua_r_invite: 407 Proxy Authentication Required
>tpsip/events-DEBUG: 10/09/10 10:19:02.350553: tpsip_connection_sofia_callback: connection 0x8099930, refcount 2
>tpsip/events-DEBUG: 10/09/10 10:19:02.350846: tpsip_connection_sofia_callback: dispatching to target 0x80aa168 (handle 0x80b3130)
>tpsip/connection-DEBUG: 10/09/10 10:19:02.351046: priv_handle_auth: response presents an authentication challenge
>tpsip/connection-DEBUG: 10/09/10 10:19:02.351402: priv_handle_auth: using the primary auth credentials
>tpsip/connection-DEBUG: 10/09/10 10:19:02.355977: priv_handle_auth: proxy authenticating user='cvine' realm="sip.antisip.com"
>tpsip/events-DEBUG: 10/09/10 10:19:02.356237: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 10/09/10 10:19:02.357450: tpsip_connection_sofia_callback: event nua_i_state: 000 INVITE sent
>tpsip/events-DEBUG: 10/09/10 10:19:02.357880: tpsip_connection_sofia_callback: connection 0x8099930, refcount 2
>tpsip/events-DEBUG: 10/09/10 10:19:02.358100: tpsip_connection_sofia_callback: dispatching to target 0x80aa168 (handle 0x80b3130)
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.358314: priv_nua_i_state_cb: call with handle 0x80b3130 is calling
>tpsip/events-DEBUG: 10/09/10 10:19:02.358508: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 10/09/10 10:19:02.867968: tpsip_connection_sofia_callback: event nua_r_invite: 180 Ringing
>tpsip/events-DEBUG: 10/09/10 10:19:02.868273: tpsip_connection_sofia_callback: connection 0x8099930, refcount 2
>tpsip/events-DEBUG: 10/09/10 10:19:02.868453: tpsip_connection_sofia_callback: dispatching to target 0x80aa168 (handle 0x80b3130)
>tpsip/events-DEBUG: 10/09/10 10:19:02.868649: tpsip_connection_sofia_callback: event nua_r_invite for target 0x80aa168 was not consumed
>tpsip/events-DEBUG: 10/09/10 10:19:02.868992: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 10/09/10 10:19:02.869230: tpsip_connection_sofia_callback: event nua_i_state: 180 Ringing
>tpsip/events-DEBUG: 10/09/10 10:19:02.869402: tpsip_connection_sofia_callback: connection 0x8099930, refcount 2
>tpsip/events-DEBUG: 10/09/10 10:19:02.869560: tpsip_connection_sofia_callback: dispatching to target 0x80aa168 (handle 0x80b3130)
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.869757: priv_nua_i_state_cb: call with handle 0x80b3130 is proceeding
>tpsip/media-channel-DEBUG: 10/09/10 10:19:02.870028: tpsip_media_channel_change_call_state: setting call state 1 for peer 2
>tpsip/events-DEBUG: 10/09/10 10:19:02.870313: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 10/09/10 10:19:22.490597: tpsip_connection_sofia_callback: event nua_r_invite: 200 OK
>tpsip/events-DEBUG: 10/09/10 10:19:22.494012: tpsip_connection_sofia_callback: connection 0x8099930, refcount 2
>tpsip/events-DEBUG: 10/09/10 10:19:22.495707: tpsip_connection_sofia_callback: dispatching to target 0x80aa168 (handle 0x80b3130)
>tpsip/events-DEBUG: 10/09/10 10:19:22.496006: tpsip_connection_sofia_callback: event nua_r_invite for target 0x80aa168 was not consumed
>tpsip/events-DEBUG: 10/09/10 10:19:22.496181: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 10/09/10 10:19:22.496373: tpsip_connection_sofia_callback: event nua_i_state: 200 OK
>tpsip/events-DEBUG: 10/09/10 10:19:22.496546: tpsip_connection_sofia_callback: connection 0x8099930, refcount 2
>tpsip/events-DEBUG: 10/09/10 10:19:22.496712: tpsip_connection_sofia_callback: dispatching to target 0x80aa168 (handle 0x80b3130)
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.496908: tpsip_media_session_set_remote_media: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.517843: priv_session_state_changed_cb: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.518121: priv_update_remote_media: setting remote SDP for stream 0
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.518315: tpsip_media_stream_set_remote_media: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.518486: push_remote_candidates: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.518743: push_remote_candidates: remote RTP address=<91.121.81.212>, port=<45370>
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.519001: push_remote_candidates: remote RTCP address=<91.121.81.212>, port=<45371>
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.519287: push_remote_candidates: emitting SetRemoteCandidateList with L1
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.520059: push_remote_codecs: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.548011: push_active_candidate_pair: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.548212: push_active_candidate_pair: emitting SetActiveCandidatePair for L1-L1
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.548480: priv_update_remote_media: setting remote SDP for stream 1
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.548646: tpsip_media_stream_set_remote_media: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.548810: push_remote_candidates: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.567166: push_remote_candidates: remote RTP address=<91.121.81.212>, port=<45372>
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.567558: push_remote_candidates: remote RTCP address=<91.121.81.212>, port=<45373>
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.567862: push_remote_candidates: emitting SetRemoteCandidateList with L1
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.568521: push_remote_codecs: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.587137: push_active_candidate_pair: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.587343: push_active_candidate_pair: emitting SetActiveCandidatePair for L1-L1
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.587613: priv_update_remote_hold: the session is remotely unheld
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.587778: priv_update_remote_media: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.587946: priv_nua_i_state_cb: call with handle 0x80b3130 is ready
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.588113: tpsip_media_channel_change_call_state: setting call state 0 for peer 2
>tpsip/events-DEBUG: 10/09/10 10:19:22.588387: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 10/09/10 10:19:22.588572: tpsip_connection_sofia_callback: event nua_i_active: 200 Call active
>tpsip/events-DEBUG: 10/09/10 10:19:22.588737: tpsip_connection_sofia_callback: connection 0x8099930, refcount 2
>tpsip/events-DEBUG: 10/09/10 10:19:22.588900: tpsip_connection_sofia_callback: dispatching to target 0x80aa168 (handle 0x80b3130)
>tpsip/events-DEBUG: 10/09/10 10:19:22.613076: tpsip_connection_sofia_callback: event nua_i_active for target 0x80aa168 was not consumed
>tpsip/events-DEBUG: 10/09/10 10:19:22.613642: tpsip_connection_sofia_callback: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.614223: tpsip_media_stream_new_active_candidate_pair: stream engine reported new active candidate pair L1-L1
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.614623: tpsip_media_stream_stream_state: changing stream state from 0 to 2
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.615078: tpsip_media_stream_new_active_candidate_pair: stream engine reported new active candidate pair L1-L1
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.616035: tpsip_media_stream_supported_codecs: got codec intersection containing 7 codecs from stream-engine
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.651273: tpsip_media_stream_new_active_candidate_pair: stream engine reported new active candidate pair L1-L1
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.652249: tpsip_media_stream_stream_state: changing stream state from 0 to 2
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.792654: tpsip_media_stream_supported_codecs: got codec intersection containing 4 codecs from stream-engine
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.793128: priv_session_state_changed_cb: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.794987: priv_session_invite: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.795290: priv_session_state_changed_cb: enter
>tpsip/events-DEBUG: 10/09/10 10:19:22.821763: tpsip_connection_sofia_callback: event nua_i_state: 000 INVITE sent
>tpsip/events-DEBUG: 10/09/10 10:19:22.822267: tpsip_connection_sofia_callback: connection 0x8099930, refcount 2
>tpsip/events-DEBUG: 10/09/10 10:19:22.822448: tpsip_connection_sofia_callback: dispatching to target 0x80aa168 (handle 0x80b3130)
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.822655: priv_nua_i_state_cb: call with handle 0x80b3130 is calling
>tpsip/events-DEBUG: 10/09/10 10:19:22.822825: tpsip_connection_sofia_callback: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.823173: tpsip_media_stream_new_active_candidate_pair: stream engine reported new active candidate pair L1-L1
>tpsip/events-DEBUG: 10/09/10 10:19:22.966525: tpsip_connection_sofia_callback: event nua_r_invite: 513 Message too big
>tpsip/events-DEBUG: 10/09/10 10:19:22.968290: tpsip_connection_sofia_callback: connection 0x8099930, refcount 2
>tpsip/events-DEBUG: 10/09/10 10:19:22.968556: tpsip_connection_sofia_callback: dispatching to target 0x80aa168 (handle 0x80b3130)
>tpsip/events-DEBUG: 10/09/10 10:19:22.968761: tpsip_connection_sofia_callback: event nua_r_invite for target 0x80aa168 was not consumed
>tpsip/events-DEBUG: 10/09/10 10:19:22.968929: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 10/09/10 10:19:22.972192: tpsip_connection_sofia_callback: event nua_i_state: 513 Message too big
>tpsip/events-DEBUG: 10/09/10 10:19:22.972492: tpsip_connection_sofia_callback: connection 0x8099930, refcount 2
>tpsip/events-DEBUG: 10/09/10 10:19:22.972666: tpsip_connection_sofia_callback: dispatching to target 0x80aa168 (handle 0x80b3130)
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.972872: priv_nua_i_state_cb: call with handle 0x80b3130 is ready
>tpsip/media-channel-MESSAGE: 10/09/10 10:19:22.973119: priv_nua_i_state_cb: can't handle non-fatal response 513 Message too big
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.977488: tpsip_media_session_terminate: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.977751: priv_stream_close_cb: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.978055: tpsip_media_stream_dispose: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.978326: tpsip_media_stream_finalize: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.978544: priv_stream_close_cb: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.978837: tpsip_media_stream_dispose: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.979070: tpsip_media_stream_finalize: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.979243: tpsip_media_session_terminate: sending BYE
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.979490: tpsip_media_session_change_state: destroying the NUA handle 0x80b3130
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.979718: priv_session_state_changed_cb: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.980667: priv_destroy_session: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.980854: priv_destroy_session: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:22.981014: tpsip_media_channel_close: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:23.22077: tpsip_media_session_dispose: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:23.22300: tpsip_media_session_dispose: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:23.22490: tpsip_media_session_finalize: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:23.22663: tpsip_media_channel_dispose: enter
>tpsip/media-channel-DEBUG: 10/09/10 10:19:23.22907: tpsip_media_channel_dispose: exit
>tpsip/media-channel-DEBUG: 10/09/10 10:19:23.23133: tpsip_media_channel_finalize: exit
>tpsip/events-DEBUG: 10/09/10 10:19:23.23313: tpsip_connection_sofia_callback: exit
>tpsip/sofia-DEBUG: 10/09/10 10:19:30.106141: nta_agent: tport: Bad message

Actions: View

Attachments on bug 29785: 38128 | 38129 | 38597 | 38598

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.