Attachment 39844 Details for Bug 31166 – sofiasip debug output

sofiasip debug output

sofiasip.log (text/plain), 16.11 KB, created by Balint Menyhart on 2010-10-28 06:15:52 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Balint Menyhart

Created: 2010-10-28 06:15:52 UTC

Size: 16.11 KB

patch

obsolete

>tpsip/connection-DEBUG: 28/10/10 13:50:31.931184: conn_get_alias: handle 2 got alias user@domain.com
>tpsip/connection-DEBUG: 28/10/10 13:50:32.158951: conn_get_alias: handle 1 got alias user.laptop@domain.com
>tpsip/connection-DEBUG: 28/10/10 13:50:32.652940: new_media_channel: channel object path /org/freedesktop/Telepathy/Connection/sofiasip/sip/user_2elaptop_40domain/MediaChannel1
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.653074: tpsip_media_channel_constructed: registering object to dbus path=/org/freedesktop/Telepathy/Connection/sofiasip/sip/user_2elaptop_40domain/MediaChannel1
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.653928: priv_outbound_call: making outbound call - setting peer handle to 2
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.654005: priv_create_session: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.654078: priv_create_session: allocating session, peer=2
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.654195: priv_create_session: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.708585: tpsip_media_channel_request_streams: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.708646: priv_outbound_call: session already exists
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.708695: tpsip_media_session_request_streams: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.708745: tpsip_media_session_add_stream: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.708961: tpsip_media_session_add_stream: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.709031: tpsip_media_session_add_stream: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.709233: tpsip_media_session_add_stream: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.709302: priv_request_response_step: there are local streams not ready, postponed
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.709412: tpsip_media_channel_request_streams: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.711323: tpsip_media_channel_get_session_handlers: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.713756: tpsip_media_session_ready: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.818156: tpsip_media_stream_ready: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.818308: push_active_candidate_pair: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.903141: tpsip_media_stream_ready: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:32.903259: push_active_candidate_pair: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.457390: tpsip_media_stream_native_candidates_prepared: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.458095: priv_request_response_step: there are local streams not ready, postponed
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.458256: priv_stream_ready_cb: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.458400: priv_request_response_step: there are local streams not ready, postponed
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.458545: push_active_candidate_pair: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.459285: tpsip_media_stream_native_candidates_prepared: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.459743: priv_request_response_step: there are local streams not ready, postponed
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.459902: priv_stream_ready_cb: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.460082: priv_session_invite: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.460241: tpsip_media_stream_set_playing: set playing to TRUE
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.460443: tpsip_media_stream_set_playing: set playing to TRUE
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.460685: priv_session_state_changed_cb: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.467448: push_active_candidate_pair: enter
>tpsip/events-DEBUG: 28/10/10 13:50:35.471132: tpsip_connection_sofia_callback: event nua_i_state: 000 INVITE sent
>tpsip/events-DEBUG: 28/10/10 13:50:35.471407: tpsip_connection_sofia_callback: connection 0x8625848, refcount 2
>tpsip/events-DEBUG: 28/10/10 13:50:35.471647: tpsip_connection_sofia_callback: dispatching to target 0x8633d00 (handle 0x86393f0)
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.471893: priv_nua_i_state_cb: call with handle 0x86393f0 is calling
>tpsip/events-DEBUG: 28/10/10 13:50:35.472130: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 28/10/10 13:50:35.488985: tpsip_connection_sofia_callback: event nua_r_invite: 407 Proxy Authentication Required
>tpsip/events-DEBUG: 28/10/10 13:50:35.489078: tpsip_connection_sofia_callback: connection 0x8625848, refcount 2
>tpsip/events-DEBUG: 28/10/10 13:50:35.489130: tpsip_connection_sofia_callback: dispatching to target 0x8633d00 (handle 0x86393f0)
>tpsip/connection-DEBUG: 28/10/10 13:50:35.489187: priv_handle_auth: response presents an authentication challenge
>tpsip/connection-DEBUG: 28/10/10 13:50:35.489236: priv_handle_auth: using the primary auth credentials
>tpsip/connection-DEBUG: 28/10/10 13:50:35.489285: priv_handle_auth: proxy authenticating user='authuser' realm="realm"
>tpsip/events-DEBUG: 28/10/10 13:50:35.489341: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 28/10/10 13:50:35.489557: tpsip_connection_sofia_callback: event nua_i_state: 000 INVITE sent
>tpsip/events-DEBUG: 28/10/10 13:50:35.489614: tpsip_connection_sofia_callback: connection 0x8625848, refcount 2
>tpsip/events-DEBUG: 28/10/10 13:50:35.489665: tpsip_connection_sofia_callback: dispatching to target 0x8633d00 (handle 0x86393f0)
>tpsip/media-channel-DEBUG: 28/10/10 13:50:35.489731: priv_nua_i_state_cb: call with handle 0x86393f0 is calling
>tpsip/events-DEBUG: 28/10/10 13:50:35.489789: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 28/10/10 13:50:36.961822: tpsip_connection_sofia_callback: event nua_r_invite: 180 Ringing
>tpsip/events-DEBUG: 28/10/10 13:50:36.962055: tpsip_connection_sofia_callback: connection 0x8625848, refcount 2
>tpsip/events-DEBUG: 28/10/10 13:50:36.962207: tpsip_connection_sofia_callback: dispatching to target 0x8633d00 (handle 0x86393f0)
>tpsip/events-DEBUG: 28/10/10 13:50:36.962419: tpsip_connection_sofia_callback: event nua_r_invite for target 0x8633d00 was not consumed
>tpsip/events-DEBUG: 28/10/10 13:50:36.963335: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 28/10/10 13:50:36.963496: tpsip_connection_sofia_callback: event nua_i_state: 180 Ringing
>tpsip/events-DEBUG: 28/10/10 13:50:36.963648: tpsip_connection_sofia_callback: connection 0x8625848, refcount 2
>tpsip/events-DEBUG: 28/10/10 13:50:36.963840: tpsip_connection_sofia_callback: dispatching to target 0x8633d00 (handle 0x86393f0)
>tpsip/media-channel-DEBUG: 28/10/10 13:50:36.964009: priv_nua_i_state_cb: call with handle 0x86393f0 is proceeding
>tpsip/media-channel-DEBUG: 28/10/10 13:50:36.964159: tpsip_media_channel_change_call_state: setting call state 1 for peer 2
>tpsip/events-DEBUG: 28/10/10 13:50:36.964395: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 28/10/10 13:50:39.753062: tpsip_connection_sofia_callback: event nua_r_invite: 200 OK
>tpsip/events-DEBUG: 28/10/10 13:50:39.753288: tpsip_connection_sofia_callback: connection 0x8625848, refcount 2
>tpsip/events-DEBUG: 28/10/10 13:50:39.753441: tpsip_connection_sofia_callback: dispatching to target 0x8633d00 (handle 0x86393f0)
>tpsip/events-DEBUG: 28/10/10 13:50:39.753638: tpsip_connection_sofia_callback: event nua_r_invite for target 0x8633d00 was not consumed
>tpsip/events-DEBUG: 28/10/10 13:50:39.753787: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 28/10/10 13:50:39.753945: tpsip_connection_sofia_callback: event nua_i_state: 200 OK
>tpsip/events-DEBUG: 28/10/10 13:50:39.754091: tpsip_connection_sofia_callback: connection 0x8625848, refcount 2
>tpsip/events-DEBUG: 28/10/10 13:50:39.754240: tpsip_connection_sofia_callback: dispatching to target 0x8633d00 (handle 0x86393f0)
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.754400: tpsip_media_session_set_remote_media: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.754555: priv_session_state_changed_cb: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.754741: priv_update_remote_media: setting remote SDP for stream 0
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.754890: tpsip_media_stream_set_remote_media: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.755034: push_remote_candidates: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.755244: push_remote_candidates: remote RTP address=<10.0.0.1>, port=<50146>
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.755455: push_remote_candidates: remote RTCP address=<10.0.0.1>, port=<50147>
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.755682: push_remote_candidates: emitting SetRemoteCandidateList with L1
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.756251: push_remote_codecs: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.756968: push_active_candidate_pair: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.757117: push_active_candidate_pair: emitting SetActiveCandidatePair for L1-L1
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.757344: tpsip_media_stream_set_direction: set direction 3, pending send flags 0
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.763156: priv_update_remote_media: setting remote SDP for stream 1
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.763310: tpsip_media_stream_set_remote_media: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.763504: push_remote_candidates: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.763711: push_remote_candidates: remote RTP address=<10.0.0.1>, port=<50148>
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.769853: push_remote_candidates: remote RTCP address=<10.0.0.1>, port=<50149>
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.769938: push_remote_candidates: emitting SetRemoteCandidateList with L1
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.770142: push_remote_codecs: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.770405: push_active_candidate_pair: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.770456: push_active_candidate_pair: emitting SetActiveCandidatePair for L1-L1
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.770534: tpsip_media_stream_set_direction: set direction 3, pending send flags 0
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.770626: priv_update_remote_hold: the session is remotely unheld
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.770675: priv_update_remote_media: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.770726: priv_nua_i_state_cb: call with handle 0x86393f0 is ready
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.770776: tpsip_media_channel_change_call_state: setting call state 0 for peer 2
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.770854: tpsip_media_stream_apply_pending_direction: remote end ready to receive
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.770905: tpsip_media_stream_set_sending: set sending to TRUE
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.770973: tpsip_media_stream_apply_pending_direction: remote end ready to receive
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.771023: tpsip_media_stream_set_sending: set sending to TRUE
>tpsip/events-DEBUG: 28/10/10 13:50:39.771092: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 28/10/10 13:50:39.771147: tpsip_connection_sofia_callback: event nua_i_active: 200 Call active
>tpsip/events-DEBUG: 28/10/10 13:50:39.771197: tpsip_connection_sofia_callback: connection 0x8625848, refcount 2
>tpsip/events-DEBUG: 28/10/10 13:50:39.771245: tpsip_connection_sofia_callback: dispatching to target 0x8633d00 (handle 0x86393f0)
>tpsip/events-DEBUG: 28/10/10 13:50:39.771301: tpsip_connection_sofia_callback: event nua_i_active for target 0x8633d00 was not consumed
>tpsip/events-DEBUG: 28/10/10 13:50:39.771349: tpsip_connection_sofia_callback: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.771513: tpsip_media_stream_new_active_candidate_pair: stream engine reported new active candidate pair L1-L1
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.771604: tpsip_media_stream_stream_state: changing stream state from 0 to 2
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.771717: tpsip_media_stream_new_active_candidate_pair: stream engine reported new active candidate pair L1-L1
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.777487: tpsip_media_stream_supported_codecs: got codec intersection containing 3 codecs from stream-engine
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.786204: tpsip_media_stream_new_active_candidate_pair: stream engine reported new active candidate pair L1-L1
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.786309: tpsip_media_stream_stream_state: changing stream state from 0 to 2
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.786501: tpsip_media_stream_supported_codecs: got codec intersection containing 2 codecs from stream-engine
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.786559: tpsip_media_stream_apply_pending_direction: remote end ready to receive
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.786609: tpsip_media_stream_apply_pending_direction: remote end ready to receive
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.786663: priv_session_state_changed_cb: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:39.787015: tpsip_media_stream_new_active_candidate_pair: stream engine reported new active candidate pair L1-L1
>tpsip/events-DEBUG: 28/10/10 13:50:40.125647: tpsip_connection_sofia_callback: event nua_r_register: 100 Request Authorized by Cache
>tpsip/events-DEBUG: 28/10/10 13:50:40.125885: tpsip_connection_sofia_callback: connection 0x8625848, refcount 2
>tpsip/events-DEBUG: 28/10/10 13:50:40.126038: tpsip_connection_sofia_callback: dispatching to target 0x8625848 (handle 0x862b578)
>tpsip/events-DEBUG: 28/10/10 13:50:40.126202: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 28/10/10 13:50:40.145337: tpsip_connection_sofia_callback: event nua_r_register: 200 OK
>tpsip/events-DEBUG: 28/10/10 13:50:40.145560: tpsip_connection_sofia_callback: connection 0x8625848, refcount 2
>tpsip/events-DEBUG: 28/10/10 13:50:40.145735: tpsip_connection_sofia_callback: dispatching to target 0x8625848 (handle 0x862b578)
>tpsip/events-DEBUG: 28/10/10 13:50:40.145900: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 28/10/10 13:50:48.838696: tpsip_connection_sofia_callback: event nua_i_bye: 200 Session Terminated
>tpsip/events-DEBUG: 28/10/10 13:50:48.838933: tpsip_connection_sofia_callback: connection 0x8625848, refcount 2
>tpsip/events-DEBUG: 28/10/10 13:50:48.839085: tpsip_connection_sofia_callback: dispatching to target 0x8633d00 (handle 0x86393f0)
>tpsip/events-DEBUG: 28/10/10 13:50:48.839993: tpsip_connection_sofia_callback: exit
>tpsip/events-DEBUG: 28/10/10 13:50:48.840183: tpsip_connection_sofia_callback: event nua_i_state: 200 Session Terminated
>tpsip/events-DEBUG: 28/10/10 13:50:48.840334: tpsip_connection_sofia_callback: connection 0x8625848, refcount 2
>tpsip/events-DEBUG: 28/10/10 13:50:48.840481: tpsip_connection_sofia_callback: dispatching to target 0x8633d00 (handle 0x86393f0)
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.840646: priv_nua_i_state_cb: call with handle 0x86393f0 is terminated
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.840837: priv_stream_close_cb: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.841085: tpsip_media_stream_dispose: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.841303: tpsip_media_stream_finalize: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.841487: priv_stream_close_cb: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.848243: tpsip_media_stream_dispose: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.848318: tpsip_media_stream_finalize: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.848368: tpsip_media_session_change_state: destroying the NUA handle 0x86393f0
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.850949: priv_session_state_changed_cb: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.851059: priv_destroy_session: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.851113: priv_destroy_session: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.851162: tpsip_media_channel_close: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.851259: tpsip_media_session_dispose: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.851317: tpsip_media_session_dispose: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.851372: tpsip_media_session_finalize: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.851423: tpsip_media_channel_dispose: enter
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.851490: tpsip_media_channel_dispose: exit
>tpsip/media-channel-DEBUG: 28/10/10 13:50:48.851548: tpsip_media_channel_finalize: exit
>tpsip/events-DEBUG: 28/10/10 13:50:48.851598: tpsip_connection_sofia_callback: exit

Actions: View

Attachments on bug 31166: 39844

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.