[Mar 6 03:48:51] Asterisk Ready. *CLI> core set verbose 4 Verbosity is at least 4 *CLI> sip set debug SIP Debugging enabled [Mar 6 03:49:31] <--- SIP read from 67.107.145.53:5060 ---> INVITE sip:14089830588@fr03.interatel.net SIP/2.0 Via: SIP/2.0/UDP 67.107.145.53:5060;branch=z9hG4bK0673880c From: "7027950101" ;tag=as6e02c279 To: Contact: Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Tue, 06 Mar 2007 03:49:31 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 240 v=0 o=root 9055 9055 IN IP4 67.107.145.53 s=session c=IN IP4 67.107.145.53 t=0 0 m=audio 16386 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:14089830588@fr03.interatel.net SIP/2.0 (49) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.53:5060;branch=z9hG4bK0673880c (58) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as6e02c279 (64) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: (40) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Contact: (39) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 (55) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: CSeq: 102 INVITE (16) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 9: Date: Tue, 06 Mar 2007 03:49:31 GMT (35) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 11: Supported: replaces (19) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 12: Content-Type: application/sdp (29) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 13: Content-Length: 240 (19) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 14: (0) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: o=root 9055 9055 IN IP4 67.107.145.53 (37) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: s=session (9) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: c=IN IP4 67.107.145.53 (22) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: m=audio 16386 RTP/AVP 0 101 (27) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=ptime:20 (10) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 6 03:49:31] --- (14 headers 12 lines) --- [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to Off [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4308 sip_alloc: Allocating new SIP dialog for 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 - INVITE (With RTP) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:14596 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:1678 parse_sip_options: Begin: parsing SIP "Supported: replaces" [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:1686 parse_sip_options: Found SIP option: -replaces- [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:1692 parse_sip_options: Matched SIP option: replaces [Mar 6 03:49:31] Sending to 67.107.145.53 : 5060 (no NAT) [Mar 6 03:49:31] Using INVITE request as basis request - 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 [Mar 6 03:49:31] DEBUG[16135]: res_config_mysql.c:651 mysql_reconnect: MySQL RealTime: Everything is fine. [Mar 6 03:49:31] DEBUG[16135]: res_config_mysql.c:139 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '7027950101' [Mar 6 03:49:31] Found peer 'fr02' [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to Off [Mar 6 03:49:31] Found RTP audio format 0 [Mar 6 03:49:31] Found RTP audio format 101 [Mar 6 03:49:31] Peer audio RTP is at port 67.107.145.53:16386 [Mar 6 03:49:31] Found description format PCMU for ID 0 [Mar 6 03:49:31] Found description format telephone-event for ID 101 [Mar 6 03:49:31] Got unsupported a:fmtp in SDP offer [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel [Mar 6 03:49:31] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Mar 6 03:49:31] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 6 03:49:31] Peer audio RTP is at port 67.107.145.53:16386 [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x4 (ulaw) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:13384 handle_request_invite: Checking SIP call limits for device [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:3001 update_call_counter: Updating call counter for incoming call [Mar 6 03:49:31] Looking for 14089830588 in deskphone (domain fr03.interatel.net) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:3803 sip_new: *** Our native formats are 0x4 (ulaw) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:3804 sip_new: *** Joint capabilities are 0x4 (ulaw) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:3805 sip_new: *** Our capabilities are 0x4 (ulaw) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:3806 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:3829 sip_new: This channel will not be able to handle video. [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:7970 build_route: build_route: Contact hop: [Mar 6 03:49:31] list_route: hop: [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:13459 handle_request_invite: SIP/67.107.145.53-08d06ed8: New call is still down.... Trying... [Mar 6 03:49:31] <--- Transmitting (no NAT) to 67.107.145.53:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 67.107.145.53:5060;branch=z9hG4bK0673880c;received=67.107.145.53 From: "7027950101" ;tag=as6e02c279 To: Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 6 03:49:31] DEBUG[16135]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/67.107.145.53-08d06ed8 [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'NoOp' [Mar 6 03:49:31] -- Executing [14089830588@deskphone:1] NoOp("SIP/67.107.145.53-08d06ed8", "Entering deskphone with callerid and exten 14089830588") in new stack [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'NoOp' [Mar 6 03:49:31] DEBUG[16104]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 67.107.145.53 [Mar 6 03:49:31] DEBUG[16104]: chan_sip.c:15207 sip_devicestate: Checking device state for peer 67.107.145.53 [Mar 6 03:49:31] -- Executing [14089830588@deskphone:2] NoOp("SIP/67.107.145.53-08d06ed8", "Inside oneplus") in new stack [Mar 6 03:49:31] DEBUG[16104]: res_config_mysql.c:651 mysql_reconnect: MySQL RealTime: Everything is fine. [Mar 6 03:49:31] DEBUG[16104]: res_config_mysql.c:139 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '67.107.145.53' [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'NoOp' [Mar 6 03:49:31] -- Executing [14089830588@deskphone:3] NoOp("SIP/67.107.145.53-08d06ed8", "Decide here... is it one of ours? If so| route locally") in new stack [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'Macro' [Mar 6 03:49:31] -- Executing [14089830588@deskphone:4] Macro("SIP/67.107.145.53-08d06ed8", "getdialstring|14089830588") in new stack [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'NoOp' [Mar 6 03:49:31] -- Executing [s@macro-getdialstring:1] NoOp("SIP/67.107.145.53-08d06ed8", "Entering macro getdialstring with 14089830588") in new stack [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'NoOp' [Mar 6 03:49:31] DEBUG[16104]: devicestate.c:287 do_state_change: Changing state for SIP/67.107.145.53 - state 2 (In use) [Mar 6 03:49:31] -- Executing [s@macro-getdialstring:2] NoOp("SIP/67.107.145.53-08d06ed8", "curlresult=CURL(http://fr03.interatel.net/lookups/ani.php?ani=14089830588)") in new stack [Mar 6 03:49:31] DEBUG[16407]: app_queue.c:546 changethread: Device 'SIP/67.107.145.53' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'notfound ' [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'Set' [Mar 6 03:49:31] -- Executing [s@macro-getdialstring:3] Set("SIP/67.107.145.53-08d06ed8", "curlresult=notfound ") in new stack [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1712 pbx_substitute_variables_helper_full: Expression result is '1' [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'GotoIf' [Mar 6 03:49:31] -- Executing [s@macro-getdialstring:4] GotoIf("SIP/67.107.145.53-08d06ed8", "1?notfound") in new stack [Mar 6 03:49:31] -- Goto (macro-getdialstring,s,30) [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'NoOp' [Mar 6 03:49:31] -- Executing [s@macro-getdialstring:30] NoOp("SIP/67.107.145.53-08d06ed8", "Not Found") in new stack [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'Set' [Mar 6 03:49:31] -- Executing [s@macro-getdialstring:31] Set("SIP/67.107.145.53-08d06ed8", "dialstring=notfound") in new stack [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'NoOp' [Mar 6 03:49:31] -- Executing [s@macro-getdialstring:32] NoOp("SIP/67.107.145.53-08d06ed8", "End") in new stack [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'NoOp' [Mar 6 03:49:31] -- Executing [s@macro-getdialstring:33] NoOp("SIP/67.107.145.53-08d06ed8", "dialstring was notfound") in new stack [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1712 pbx_substitute_variables_helper_full: Expression result is '0' [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'GotoIf' [Mar 6 03:49:31] -- Executing [14089830588@deskphone:5] GotoIf("SIP/67.107.145.53-08d06ed8", "0?onnet|14089830588|1") in new stack [Mar 6 03:49:31] DEBUG[16406]: pbx.c:5969 pbx_builtin_gotoif: Not taking any branch [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '7027950101' [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'Set' [Mar 6 03:49:31] -- Executing [14089830588@deskphone:6] Set("SIP/67.107.145.53-08d06ed8", "CALLERID(NUM)=7027950101") in new stack [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '7027950101' [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'Set' [Mar 6 03:49:31] -- Executing [14089830588@deskphone:7] Set("SIP/67.107.145.53-08d06ed8", "CALLERID(NUM)=+17027950101") in new stack [Mar 6 03:49:31] DEBUG[16406]: pbx.c:1791 pbx_extension_helper: Launching 'Dial' [Mar 6 03:49:31] -- Executing [14089830588@deskphone:8] Dial("SIP/67.107.145.53-08d06ed8", "SIP/level3/+14089830588|120") in new stack [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:15273 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4308 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to Off [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:3803 sip_new: *** Our native formats are 0x4 (ulaw) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:3804 sip_new: *** Joint capabilities are 0x0 (nothing) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:3805 sip_new: *** Our capabilities are 0x4 (ulaw) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:3806 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:3808 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:3829 sip_new: This channel will not be able to handle video. [Mar 6 03:49:31] DEBUG[16406]: rtp.c:1579 ast_rtp_make_compatible: Seeded SDP of 'SIP/level3-08d144c0' with that of 'SIP/67.107.145.53-08d06ed8' [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-deskphone-14089830588-8. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-deskphone-14089830588-7. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-deskphone-14089830588-6. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-deskphone-14089830588-5. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable MACRO_DEPTH. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-macro-getdialstring-s-33. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-macro-getdialstring-s-32. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable dialstring. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-macro-getdialstring-s-31. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-macro-getdialstring-s-30. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-macro-getdialstring-s-4. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable curlresult. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-macro-getdialstring-s-3. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-macro-getdialstring-s-2. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-macro-getdialstring-s-1. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-deskphone-14089830588-4. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-deskphone-14089830588-3. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-deskphone-14089830588-2. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-deskphone-14089830588-1. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Mar 6 03:49:31] DEBUG[16406]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPURI. [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:2828 sip_call: Outgoing Call for +14089830588 [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:3001 update_call_counter: Updating call counter for outgoing call [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:2843 sip_call: Our T38 capability (0), joint T38 capability (0) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:6182 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: False [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Mar 6 03:49:31] Audio is at 67.107.145.54 port 16944 [Mar 6 03:49:31] Adding codec 0x4 (ulaw) to SDP [Mar 6 03:49:31] Adding non-codec 0x1 (telephone-event) to SDP [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:6359 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:+14089830588@4.55.16.99 SIP/2.0 (42) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK1b64c40a;rport (64) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 3: To: (33) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 4: Contact: (41) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 6: CSeq: 102 INVITE (16) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 9: Remote-Party-ID: "7027950101" ;privacy=off;screen=no (84) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 10: Date: Tue, 06 Mar 2007 03:49:31 GMT (35) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 12: Supported: replaces (19) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 13: Content-Type: application/sdp (29) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 14: Content-Length: 242 (19) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 15: (0) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: o=root 16099 16099 IN IP4 67.107.145.54 (39) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: s=session (9) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: c=IN IP4 67.107.145.54 (22) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: m=audio 16944 RTP/AVP 0 101 (27) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=ptime:20 (10) [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 6 03:49:31] Reliably Transmitting (no NAT) to 4.55.16.99:5060: INVITE sip:+14089830588@4.55.16.99 SIP/2.0 Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK1b64c40a;rport From: "7027950101" ;tag=as1a7a2dfc To: Contact: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Remote-Party-ID: "7027950101" ;privacy=off;screen=no Date: Tue, 06 Mar 2007 03:49:31 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 242 v=0 o=root 16099 16099 IN IP4 67.107.145.54 s=session c=IN IP4 67.107.145.54 t=0 0 m=audio 16944 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #31 [Mar 6 03:49:31] -- Called level3/+14089830588 [Mar 6 03:49:31] <--- SIP read from 4.55.16.99:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK1b64c40a;rport=5060 From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 102 INVITE Content-Length: 0 <-------------> [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 100 Trying (18) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK1b64c40a;rport=5060 (69) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=gK029bd4e4 (48) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: Content-Length: 0 (17) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: (0) [Mar 6 03:49:31] --- (7 headers 0 lines) --- [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:2120 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #31 - INVITE (got response) [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:2129 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4c966af4386b16b84f0148e77fda502f@67.107.145.54' Request 102: Found [Mar 6 03:49:31] DEBUG[16135]: chan_sip.c:11627 handle_response_invite: SIP response 100 to standard invite [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:6414 transmit_response_with_sdp: Setting framing from config on incoming call [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:6182 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x0 (nothing) [Mar 6 03:49:31] Audio is at 67.107.145.54 port 16048 [Mar 6 03:49:31] Adding codec 0x4 (ulaw) to SDP [Mar 6 03:49:31] Adding non-codec 0x1 (telephone-event) to SDP [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 6 03:49:31] DEBUG[16406]: chan_sip.c:6359 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Mar 6 03:49:31] <--- Transmitting (no NAT) to 67.107.145.53:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 67.107.145.53:5060;branch=z9hG4bK0673880c;received=67.107.145.53 From: "7027950101" ;tag=as6e02c279 To: ;tag=as1d3882e6 Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 242 v=0 o=root 16099 16099 IN IP4 67.107.145.54 s=session c=IN IP4 67.107.145.54 t=0 0 m=audio 16048 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Mar 6 03:49:31] DEBUG[16406]: rtp.c:2670 ast_rtp_write: Ooh, format changed from unknown to ulaw [Mar 6 03:49:31] DEBUG[16406]: rtp.c:2687 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160 [Mar 6 03:49:33] <--- SIP read from 4.55.16.99:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK1b64c40a;rport=5060 From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 102 INVITE Contact: Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE,OPTIONS Content-Length: 231 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 8993 29249 IN IP4 4.55.16.99 s=SIP Media Capabilities c=IN IP4 4.55.16.66 t=0 0 m=audio 18408 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=maxptime:20 <-------------> [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK1b64c40a;rport=5060 (69) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=gK029bd4e4 (48) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: Contact: (43) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE,OPTIONS (49) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 8: Content-Length: 231 (20) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 9: Content-Disposition: session; handling=required (47) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 10: Content-Type: application/sdp (29) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 11: (0) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: o=Sonus_UAC 8993 29249 IN IP4 4.55.16.99 (40) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: s=SIP Media Capabilities (24) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: c=IN IP4 4.55.16.66 (19) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: m=audio 18408 RTP/AVP 0 101 (27) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=maxptime:20 (13) [Mar 6 03:49:33] --- (11 headers 11 lines) --- [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2129 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4c966af4386b16b84f0148e77fda502f@67.107.145.54' Request 102: Found [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11627 handle_response_invite: SIP response 183 to standard invite [Mar 6 03:49:33] Found RTP audio format 0 [Mar 6 03:49:33] Found RTP audio format 101 [Mar 6 03:49:33] Peer audio RTP is at port 4.55.16.66:18408 [Mar 6 03:49:33] Found description format PCMU for ID 0 [Mar 6 03:49:33] Found description format telephone-event for ID 101 [Mar 6 03:49:33] Got unsupported a:fmtp in SDP offer [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel SIP/level3-08d144c0 [Mar 6 03:49:33] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Mar 6 03:49:33] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 6 03:49:33] Peer audio RTP is at port 4.55.16.66:18408 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x4 (ulaw) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5210 process_sdp: We have an owner, now see if we need to change this call [Mar 6 03:49:33] -- Call on SIP/level3-08d144c0 left from hold [Mar 6 03:49:33] -- SIP/level3-08d144c0 is making progress passing it to SIP/67.107.145.53-08d06ed8 [Mar 6 03:49:33] DEBUG[16406]: rtp.c:1514 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/67.107.145.53-08d06ed8' with that of 'SIP/level3-08d144c0' [Mar 6 03:49:33] DEBUG[16406]: rtp.c:2670 ast_rtp_write: Ooh, format changed from unknown to ulaw [Mar 6 03:49:33] DEBUG[16406]: rtp.c:2687 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160 [Mar 6 03:49:33] <--- SIP read from 4.55.16.99:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK1b64c40a;rport=5060 From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 102 INVITE Contact: Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE,OPTIONS Content-Length: 231 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 8993 29249 IN IP4 4.55.16.99 s=SIP Media Capabilities c=IN IP4 4.55.16.66 t=0 0 m=audio 18408 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=maxptime:20 <-------------> [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK1b64c40a;rport=5060 (69) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=gK029bd4e4 (48) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: Contact: (43) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE,OPTIONS (49) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 8: Content-Length: 231 (20) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 9: Content-Disposition: session; handling=required (47) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 10: Content-Type: application/sdp (29) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 11: (0) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: o=Sonus_UAC 8993 29249 IN IP4 4.55.16.99 (40) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: s=SIP Media Capabilities (24) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: c=IN IP4 4.55.16.66 (19) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: m=audio 18408 RTP/AVP 0 101 (27) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=maxptime:20 (13) [Mar 6 03:49:33] --- (11 headers 11 lines) --- [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2129 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4c966af4386b16b84f0148e77fda502f@67.107.145.54' Request 102: Found [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11627 handle_response_invite: SIP response 180 to standard invite [Mar 6 03:49:33] DEBUG[16135]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/level3-08d144c0 [Mar 6 03:49:33] Found RTP audio format 0 [Mar 6 03:49:33] DEBUG[16104]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - level3 [Mar 6 03:49:33] DEBUG[16104]: chan_sip.c:15207 sip_devicestate: Checking device state for peer level3 [Mar 6 03:49:33] Found RTP audio format 101 [Mar 6 03:49:33] DEBUG[16104]: devicestate.c:287 do_state_change: Changing state for SIP/level3 - state 1 (Not in use) [Mar 6 03:49:33] Peer audio RTP is at port 4.55.16.66:18408 [Mar 6 03:49:33] DEBUG[16416]: app_queue.c:546 changethread: Device 'SIP/level3' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 6 03:49:33] Found description format PCMU for ID 0 [Mar 6 03:49:33] Found description format telephone-event for ID 101 [Mar 6 03:49:33] Got unsupported a:fmtp in SDP offer [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel SIP/level3-08d144c0 [Mar 6 03:49:33] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Mar 6 03:49:33] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 6 03:49:33] Peer audio RTP is at port 4.55.16.66:18408 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x4 (ulaw) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5210 process_sdp: We have an owner, now see if we need to change this call [Mar 6 03:49:33] -- SIP/level3-08d144c0 is ringing [Mar 6 03:49:33] <--- SIP read from 4.55.16.99:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK1b64c40a;rport=5060 From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 102 INVITE Contact: Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE,OPTIONS Content-Length: 231 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 8993 29249 IN IP4 4.55.16.99 s=SIP Media Capabilities c=IN IP4 4.55.16.66 t=0 0 m=audio 18408 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=maxptime:20 <-------------> [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK1b64c40a;rport=5060 (69) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=gK029bd4e4 (48) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: Contact: (43) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE,OPTIONS (49) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 8: Content-Length: 231 (20) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 9: Content-Disposition: session; handling=required (47) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 10: Content-Type: application/sdp (29) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 11: (0) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: o=Sonus_UAC 8993 29249 IN IP4 4.55.16.99 (40) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: s=SIP Media Capabilities (24) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: c=IN IP4 4.55.16.66 (19) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: m=audio 18408 RTP/AVP 0 101 (27) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=maxptime:20 (13) [Mar 6 03:49:33] --- (11 headers 11 lines) --- [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:14789 sipsock_read: Failed to grab owner channel lock, trying again. (SIP call 4c966af4386b16b84f0148e77fda502f@67.107.145.54) [Mar 6 03:49:33] DEBUG[16406]: rtp.c:1514 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/67.107.145.53-08d06ed8' with that of 'SIP/level3-08d144c0' [Mar 6 03:49:33] <--- Transmitting (no NAT) to 67.107.145.53:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 67.107.145.53:5060;branch=z9hG4bK0673880c;received=67.107.145.53 From: "7027950101" ;tag=as6e02c279 To: ;tag=as1d3882e6 Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 6 03:49:33] -- Call on SIP/level3-08d144c0 left from hold [Mar 6 03:49:33] -- SIP/level3-08d144c0 is making progress passing it to SIP/67.107.145.53-08d06ed8 [Mar 6 03:49:33] DEBUG[16406]: rtp.c:1514 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/67.107.145.53-08d06ed8' with that of 'SIP/level3-08d144c0' [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2129 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4c966af4386b16b84f0148e77fda502f@67.107.145.54' Request 102: Found [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11627 handle_response_invite: SIP response 183 to standard invite [Mar 6 03:49:33] Found RTP audio format 0 [Mar 6 03:49:33] Found RTP audio format 101 [Mar 6 03:49:33] Peer audio RTP is at port 4.55.16.66:18408 [Mar 6 03:49:33] Found description format PCMU for ID 0 [Mar 6 03:49:33] Found description format telephone-event for ID 101 [Mar 6 03:49:33] Got unsupported a:fmtp in SDP offer [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel SIP/level3-08d144c0 [Mar 6 03:49:33] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Mar 6 03:49:33] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 6 03:49:33] Peer audio RTP is at port 4.55.16.66:18408 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x4 (ulaw) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5210 process_sdp: We have an owner, now see if we need to change this call [Mar 6 03:49:33] -- Call on SIP/level3-08d144c0 left from hold [Mar 6 03:49:33] -- SIP/level3-08d144c0 is making progress passing it to SIP/67.107.145.53-08d06ed8 [Mar 6 03:49:33] DEBUG[16406]: rtp.c:1514 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/67.107.145.53-08d06ed8' with that of 'SIP/level3-08d144c0' [Mar 6 03:49:33] <--- SIP read from 4.55.16.99:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK1b64c40a;rport=5060 From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 102 INVITE Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay, multipart/mixed Contact: Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE,OPTIONS Content-Length: 231 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 8993 29249 IN IP4 4.55.16.99 s=SIP Media Capabilities c=IN IP4 4.55.16.66 t=0 0 m=audio 18408 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=maxptime:20 <-------------> [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK1b64c40a;rport=5060 (69) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=gK029bd4e4 (48) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay, multipart/mixed (101) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: Contact: (43) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 8: Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE,OPTIONS (49) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 9: Content-Length: 231 (20) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 10: Content-Disposition: session; handling=required (47) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 11: Content-Type: application/sdp (29) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 12: (0) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: o=Sonus_UAC 8993 29249 IN IP4 4.55.16.99 (40) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: s=SIP Media Capabilities (24) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: c=IN IP4 4.55.16.66 (19) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: m=audio 18408 RTP/AVP 0 101 (27) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=maxptime:20 (13) [Mar 6 03:49:33] --- (12 headers 11 lines) --- [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2069 __sip_ack: Acked pending invite 102 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '4c966af4386b16b84f0148e77fda502f@67.107.145.54' of Request 102: Match Not Found [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11627 handle_response_invite: SIP response 200 to standard invite [Mar 6 03:49:33] Found RTP audio format 0 [Mar 6 03:49:33] Found RTP audio format 101 [Mar 6 03:49:33] Peer audio RTP is at port 4.55.16.66:18408 [Mar 6 03:49:33] Found description format PCMU for ID 0 [Mar 6 03:49:33] Found description format telephone-event for ID 101 [Mar 6 03:49:33] Got unsupported a:fmtp in SDP offer [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel SIP/level3-08d144c0 [Mar 6 03:49:33] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Mar 6 03:49:33] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 6 03:49:33] Peer audio RTP is at port 4.55.16.66:18408 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x4 (ulaw) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5210 process_sdp: We have an owner, now see if we need to change this call [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:3001 update_call_counter: Updating call counter for outgoing call [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:7970 build_route: build_route: Contact hop: [Mar 6 03:49:33] list_route: hop: [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5637 reqprep: Strict routing enforced for session 4c966af4386b16b84f0148e77fda502f@67.107.145.54 [Mar 6 03:49:33] set_destination: Parsing for address/port to send to [Mar 6 03:49:33] set_destination: set destination to 4.55.16.99, port 5060 [Mar 6 03:49:33] Transmitting (no NAT) to 4.55.16.99:5060: ACK sip:+14089830588@4.55.16.99:5060 SIP/2.0 Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK15d9b032;rport From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Contact: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Remote-Party-ID: "7027950101" ;privacy=off;screen=no Content-Length: 0 --- [Mar 6 03:49:33] -- Call on SIP/level3-08d144c0 left from hold [Mar 6 03:49:33] DEBUG[16406]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/level3-08d144c0 [Mar 6 03:49:33] DEBUG[16104]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - level3 [Mar 6 03:49:33] -- SIP/level3-08d144c0 answered SIP/67.107.145.53-08d06ed8 [Mar 6 03:49:33] DEBUG[16104]: chan_sip.c:15207 sip_devicestate: Checking device state for peer level3 [Mar 6 03:49:33] DEBUG[16104]: devicestate.c:287 do_state_change: Changing state for SIP/level3 - state 1 (Not in use) [Mar 6 03:49:33] DEBUG[16406]: rtp.c:1514 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/67.107.145.53-08d06ed8' with that of 'SIP/level3-08d144c0' [Mar 6 03:49:33] DEBUG[16419]: app_queue.c:546 changethread: Device 'SIP/level3' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 6 03:49:33] DEBUG[16406]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/67.107.145.53-08d06ed8 [Mar 6 03:49:33] DEBUG[16104]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 67.107.145.53 [Mar 6 03:49:33] DEBUG[16104]: chan_sip.c:15207 sip_devicestate: Checking device state for peer 67.107.145.53 [Mar 6 03:49:33] DEBUG[16104]: res_config_mysql.c:651 mysql_reconnect: MySQL RealTime: Everything is fine. [Mar 6 03:49:33] DEBUG[16104]: res_config_mysql.c:139 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '67.107.145.53' [Mar 6 03:49:33] DEBUG[16104]: channel.c:1026 channel_find_locked: Avoiding initial deadlock for channel '0x8d05330' [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:3461 sip_answer: SIP answering channel: SIP/67.107.145.53-08d06ed8 [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:6414 transmit_response_with_sdp: Setting framing from config on incoming call [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:6182 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x0 (nothing) [Mar 6 03:49:33] Audio is at 67.107.145.54 port 16048 [Mar 6 03:49:33] Adding codec 0x4 (ulaw) to SDP [Mar 6 03:49:33] Adding non-codec 0x1 (telephone-event) to SDP [Mar 6 03:49:33] DEBUG[16104]: channel.c:1026 channel_find_locked: Avoiding initial deadlock for channel '0x8d05330' [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:6359 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Mar 6 03:49:33] <--- Reliably Transmitting (no NAT) to 67.107.145.53:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 67.107.145.53:5060;branch=z9hG4bK0673880c;received=67.107.145.53 From: "7027950101" ;tag=as6e02c279 To: ;tag=as1d3882e6 Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 242 v=0 o=root 16099 16100 IN IP4 67.107.145.54 s=session c=IN IP4 67.107.145.54 t=0 0 m=audio 16048 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #35 [Mar 6 03:49:33] -- Native bridging SIP/67.107.145.53-08d06ed8 and SIP/level3-08d144c0 [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:16871 sip_set_rtp_peer: Deferring reinvite on SIP '6abf4ca14f9a76322540fcd94ae40738@67.107.145.53' - It's audio will be redirected to IP 4.55.16.66 [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:16866 sip_set_rtp_peer: Sending reinvite on SIP '4c966af4386b16b84f0148e77fda502f@67.107.145.54' - It's audio soon redirected to IP 67.107.145.53 [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:5637 reqprep: Strict routing enforced for session 4c966af4386b16b84f0148e77fda502f@67.107.145.54 [Mar 6 03:49:33] set_destination: Parsing for address/port to send to [Mar 6 03:49:33] set_destination: set destination to 4.55.16.99, port 5060 [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:6182 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Mar 6 03:49:33] Audio is at 67.107.145.54 port 16944 [Mar 6 03:49:33] Adding codec 0x4 (ulaw) to SDP [Mar 6 03:49:33] Adding non-codec 0x1 (telephone-event) to SDP [Mar 6 03:49:33] <--- SIP read from 67.107.145.53:5060 ---> ACK sip:14089830588@67.107.145.54 SIP/2.0 Via: SIP/2.0/UDP 67.107.145.53:5060;branch=z9hG4bK5ecd20c1 From: "7027950101" ;tag=as6e02c279 To: ;tag=as1d3882e6 Contact: Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 <-------------> [Mar 6 03:49:33] DEBUG[16104]: channel.c:1026 channel_find_locked: Avoiding initial deadlock for channel '0x8d05330' [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:6359 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:1619 initialize_initreq: Initializing already initialized SIP dialog 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (presumably reinvite) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:+14089830588@4.55.16.99:5060 SIP/2.0 (47) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK5059b359;rport (64) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=gK029bd4e4 (48) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 4: Contact: (41) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 6: CSeq: 103 INVITE (16) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 9: Remote-Party-ID: "7027950101" ;privacy=off;screen=no (84) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 11: Supported: replaces (19) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 12: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 13: Content-Type: application/sdp (29) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 14: Content-Length: 242 (19) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 15: (0) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: o=root 16099 16100 IN IP4 67.107.145.53 (39) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: s=session (9) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: c=IN IP4 67.107.145.53 (22) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: m=audio 16386 RTP/AVP 0 101 (27) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=ptime:20 (10) [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 6 03:49:33] Reliably Transmitting (no NAT) to 4.55.16.99:5060: INVITE sip:+14089830588@4.55.16.99:5060 SIP/2.0 Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK5059b359;rport From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Contact: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 103 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Remote-Party-ID: "7027950101" ;privacy=off;screen=no Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 242 v=0 o=root 16099 16100 IN IP4 67.107.145.53 s=session c=IN IP4 67.107.145.53 t=0 0 m=audio 16386 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Mar 6 03:49:33] DEBUG[16406]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #36 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: ACK sip:14089830588@67.107.145.54 SIP/2.0 (41) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.53:5060;branch=z9hG4bK5ecd20c1 (58) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as6e02c279 (64) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=as1d3882e6 (55) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Contact: (39) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 (55) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: CSeq: 102 ACK (13) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 9: Content-Length: 0 (17) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 10: (0) [Mar 6 03:49:33] --- (10 headers 0 lines) --- [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:14596 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #35 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '6abf4ca14f9a76322540fcd94ae40738@67.107.145.53' of Response 102: Match Not Found [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11608 check_pendings: Sending pending reinvite on '6abf4ca14f9a76322540fcd94ae40738@67.107.145.53' [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5637 reqprep: Strict routing enforced for session 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 [Mar 6 03:49:33] set_destination: Parsing for address/port to send to [Mar 6 03:49:33] set_destination: set destination to 67.107.145.53, port 5060 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:6182 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x0 (nothing) [Mar 6 03:49:33] Audio is at 67.107.145.54 port 16048 [Mar 6 03:49:33] Adding codec 0x4 (ulaw) to SDP [Mar 6 03:49:33] Adding non-codec 0x1 (telephone-event) to SDP [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:6359 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:1619 initialize_initreq: Initializing already initialized SIP dialog 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 (presumably reinvite) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:7027950101@67.107.145.53 SIP/2.0 (43) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK29afc195;rport (64) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: ;tag=as1d3882e6 (57) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: "7027950101" ;tag=as6e02c279 (62) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Contact: (40) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 (55) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: CSeq: 102 INVITE (16) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 10: Supported: replaces (19) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 12: Content-Type: application/sdp (29) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 13: Content-Length: 236 (19) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 14: (0) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: o=root 16099 16101 IN IP4 4.55.16.66 (36) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: s=session (9) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: c=IN IP4 4.55.16.66 (19) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: m=audio 18408 RTP/AVP 0 101 (27) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=ptime:20 (10) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 6 03:49:33] Reliably Transmitting (no NAT) to 67.107.145.53:5060: INVITE sip:7027950101@67.107.145.53 SIP/2.0 Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK29afc195;rport From: ;tag=as1d3882e6 To: "7027950101" ;tag=as6e02c279 Contact: Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 236 v=0 o=root 16099 16101 IN IP4 4.55.16.66 s=session c=IN IP4 4.55.16.66 t=0 0 m=audio 18408 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #37 [Mar 6 03:49:33] DEBUG[16104]: devicestate.c:287 do_state_change: Changing state for SIP/67.107.145.53 - state 2 (In use) [Mar 6 03:49:33] DEBUG[16420]: app_queue.c:546 changethread: Device 'SIP/67.107.145.53' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 6 03:49:33] <--- SIP read from 67.107.145.53:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK29afc195;rport;received=67.107.145.54 From: ;tag=as1d3882e6 To: "7027950101" ;tag=as6e02c279 Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 240 v=0 o=root 9055 9056 IN IP4 67.107.145.53 s=session c=IN IP4 67.107.145.53 t=0 0 m=audio 16386 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK29afc195;rport;received=67.107.145.54 (87) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: ;tag=as1d3882e6 (57) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: "7027950101" ;tag=as6e02c279 (62) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 (55) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: CSeq: 102 INVITE (16) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: User-Agent: Asterisk PBX (24) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 8: Supported: replaces (19) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 9: Contact: (39) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 10: Content-Type: application/sdp (29) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 11: Content-Length: 240 (19) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 12: (0) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: o=root 9055 9056 IN IP4 67.107.145.53 (37) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: s=session (9) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: c=IN IP4 67.107.145.53 (22) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: m=audio 16386 RTP/AVP 0 101 (27) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=ptime:20 (10) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 6 03:49:33] --- (12 headers 12 lines) --- [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2069 __sip_ack: Acked pending invite 102 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #37 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '6abf4ca14f9a76322540fcd94ae40738@67.107.145.53' of Request 102: Match Not Found [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11625 handle_response_invite: SIP response 200 to RE-invite on outgoing call 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 [Mar 6 03:49:33] Found RTP audio format 0 [Mar 6 03:49:33] Found RTP audio format 101 [Mar 6 03:49:33] Peer audio RTP is at port 67.107.145.53:16386 [Mar 6 03:49:33] Found description format PCMU for ID 0 [Mar 6 03:49:33] Found description format telephone-event for ID 101 [Mar 6 03:49:33] Got unsupported a:fmtp in SDP offer [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel SIP/67.107.145.53-08d06ed8 [Mar 6 03:49:33] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Mar 6 03:49:33] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 6 03:49:33] Peer audio RTP is at port 67.107.145.53:16386 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x4 (ulaw) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5210 process_sdp: We have an owner, now see if we need to change this call [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:3001 update_call_counter: Updating call counter for incoming call [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:7970 build_route: build_route: Contact hop: [Mar 6 03:49:33] list_route: hop: [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11758 handle_response_invite: Strange... The other side of the bridge does not have a udptl struct [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11763 handle_response_invite: T38 state changed to 0 on channel SIP [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11766 handle_response_invite: T38 state changed to 0 on channel SIP/67.107.145.53-08d06ed8 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5637 reqprep: Strict routing enforced for session 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 [Mar 6 03:49:33] set_destination: Parsing for address/port to send to [Mar 6 03:49:33] set_destination: set destination to 67.107.145.53, port 5060 [Mar 6 03:49:33] Transmitting (no NAT) to 67.107.145.53:5060: ACK sip:7027950101@67.107.145.53 SIP/2.0 Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK51861400;rport From: ;tag=as1d3882e6 To: "7027950101" ;tag=as6e02c279 Contact: Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Mar 6 03:49:33] DEBUG[16406]: rtp.c:2687 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160 [Mar 6 03:49:33] <--- SIP read from 4.55.16.99:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK5059b359;rport=5060 From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 103 INVITE Content-Length: 0 <-------------> [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 100 Trying (18) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK5059b359;rport=5060 (69) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=gK029bd4e4 (48) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: CSeq: 103 INVITE (16) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: Content-Length: 0 (17) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: (0) [Mar 6 03:49:33] --- (7 headers 0 lines) --- [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2120 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #36 - INVITE (got response) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2129 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4c966af4386b16b84f0148e77fda502f@67.107.145.54' Request 103: Found [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11625 handle_response_invite: SIP response 100 to RE-invite on outgoing call 4c966af4386b16b84f0148e77fda502f@67.107.145.54 [Mar 6 03:49:33] <--- SIP read from 4.55.16.99:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK5059b359;rport=5060 From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 103 INVITE Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay, multipart/mixed Contact: Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE,OPTIONS Content-Length: 258 Content-Disposition: session; handling=required Content-Type: application/sdp v=0 o=Sonus_UAC 8993 29250 IN IP4 4.55.16.99 s=SIP Media Capabilities c=IN IP4 4.55.16.66 t=0 0 m=audio 18408 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=silenceSupp:off - - - - a=maxptime:20 <-------------> [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK5059b359;rport=5060 (69) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=gK029bd4e4 (48) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: CSeq: 103 INVITE (16) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay, multipart/mixed (101) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: Contact: (43) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 8: Allow: INVITE,ACK,CANCEL,BYE,PRACK,UPDATE,OPTIONS (49) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 9: Content-Length: 258 (20) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 10: Content-Disposition: session; handling=required (47) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 11: Content-Type: application/sdp (29) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 12: (0) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: o=Sonus_UAC 8993 29250 IN IP4 4.55.16.99 (40) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: s=SIP Media Capabilities (24) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: c=IN IP4 4.55.16.66 (19) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: m=audio 18408 RTP/AVP 0 101 (27) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-15 (15) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:4603 parse_request: Line: a=maxptime:20 (13) [Mar 6 03:49:33] --- (12 headers 12 lines) --- [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2069 __sip_ack: Acked pending invite 103 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '4c966af4386b16b84f0148e77fda502f@67.107.145.54' of Request 103: Match Not Found [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11625 handle_response_invite: SIP response 200 to RE-invite on outgoing call 4c966af4386b16b84f0148e77fda502f@67.107.145.54 [Mar 6 03:49:33] Found RTP audio format 0 [Mar 6 03:49:33] Found RTP audio format 101 [Mar 6 03:49:33] Peer audio RTP is at port 4.55.16.66:18408 [Mar 6 03:49:33] Found description format PCMU for ID 0 [Mar 6 03:49:33] Found description format telephone-event for ID 101 [Mar 6 03:49:33] Got unsupported a:fmtp in SDP offer [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel SIP/level3-08d144c0 [Mar 6 03:49:33] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Mar 6 03:49:33] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 6 03:49:33] Peer audio RTP is at port 4.55.16.66:18408 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0x4 (ulaw) [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5210 process_sdp: We have an owner, now see if we need to change this call [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:3001 update_call_counter: Updating call counter for outgoing call [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:7909 build_route: build_route: Retaining previous route: [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11758 handle_response_invite: Strange... The other side of the bridge does not have a udptl struct [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11763 handle_response_invite: T38 state changed to 0 on channel SIP [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:11766 handle_response_invite: T38 state changed to 0 on channel SIP/level3-08d144c0 [Mar 6 03:49:33] DEBUG[16135]: chan_sip.c:5637 reqprep: Strict routing enforced for session 4c966af4386b16b84f0148e77fda502f@67.107.145.54 [Mar 6 03:49:33] set_destination: Parsing for address/port to send to [Mar 6 03:49:33] set_destination: set destination to 4.55.16.99, port 5060 [Mar 6 03:49:33] Transmitting (no NAT) to 4.55.16.99:5060: ACK sip:+14089830588@4.55.16.99:5060 SIP/2.0 Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK257c6be5;rport From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Contact: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 103 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Remote-Party-ID: "7027950101" ;privacy=off;screen=no Content-Length: 0 --- *CLI> *CLI> *CLI> *CLI> *CLI> *CLI> *CLI> *CLI> *CLI> [Mar 6 03:49:41] <--- SIP read from 67.107.145.53:5060 ---> BYE sip:14089830588@67.107.145.54 SIP/2.0 Via: SIP/2.0/UDP 67.107.145.53:5060;branch=z9hG4bK655d9bbb From: "7027950101" ;tag=as6e02c279 To: ;tag=as1d3882e6 Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 <-------------> [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: BYE sip:14089830588@67.107.145.54 SIP/2.0 (41) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.53:5060;branch=z9hG4bK655d9bbb (58) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as6e02c279 (64) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=as1d3882e6 (55) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 (55) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: CSeq: 103 BYE (13) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: User-Agent: Asterisk PBX (24) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: Max-Forwards: 70 (16) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 8: Content-Length: 0 (17) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 9: (0) [Mar 6 03:49:41] --- (9 headers 0 lines) --- [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:14596 handle_request: **** Received BYE (8) - Command in SIP BYE [Mar 6 03:49:41] Sending to 67.107.145.53 : 5060 (no NAT) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:1631 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:14173 handle_request_bye: Received bye, issuing owner hangup [Mar 6 03:49:41] <--- Transmitting (no NAT) to 67.107.145.53:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 67.107.145.53:5060;branch=z9hG4bK655d9bbb;received=67.107.145.53 From: "7027950101" ;tag=as6e02c279 To: ;tag=as1d3882e6 Call-ID: 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53 CSeq: 103 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 6 03:49:41] DEBUG[16406]: rtp.c:2855 bridge_native_loop: Oooh, got a hangup [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:16866 sip_set_rtp_peer: Sending reinvite on SIP '4c966af4386b16b84f0148e77fda502f@67.107.145.54' - It's audio soon redirected to IP 67.107.145.54 [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:5637 reqprep: Strict routing enforced for session 4c966af4386b16b84f0148e77fda502f@67.107.145.54 [Mar 6 03:49:41] set_destination: Parsing for address/port to send to [Mar 6 03:49:41] set_destination: set destination to 4.55.16.99, port 5060 [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:6182 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Mar 6 03:49:41] Audio is at 67.107.145.54 port 16944 [Mar 6 03:49:41] Adding codec 0x4 (ulaw) to SDP [Mar 6 03:49:41] Adding non-codec 0x1 (telephone-event) to SDP [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:6359 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:1619 initialize_initreq: Initializing already initialized SIP dialog 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (presumably reinvite) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 0: INVITE sip:+14089830588@4.55.16.99:5060 SIP/2.0 (47) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK13f0efb9;rport (64) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=gK029bd4e4 (48) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 4: Contact: (41) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 5: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 6: CSeq: 104 INVITE (16) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 8: Max-Forwards: 70 (16) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 9: Remote-Party-ID: "7027950101" ;privacy=off;screen=no (84) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 11: Supported: replaces (19) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 12: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 13: Content-Type: application/sdp (29) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 14: Content-Length: 242 (19) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4571 parse_request: Header 15: (0) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: v=0 (3) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: o=root 16099 16101 IN IP4 67.107.145.54 (39) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: s=session (9) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: c=IN IP4 67.107.145.54 (22) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: t=0 0 (5) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: m=audio 16944 RTP/AVP 0 101 (27) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=fmtp:101 0-16 (15) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=silenceSupp:off - - - - (25) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=ptime:20 (10) [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:4603 parse_request: Line: a=sendrecv (10) [Mar 6 03:49:41] Reliably Transmitting (no NAT) to 4.55.16.99:5060: INVITE sip:+14089830588@4.55.16.99:5060 SIP/2.0 Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK13f0efb9;rport From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Contact: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 104 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Remote-Party-ID: "7027950101" ;privacy=off;screen=no Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 242 v=0 o=root 16099 16101 IN IP4 67.107.145.54 s=session c=IN IP4 67.107.145.54 t=0 0 m=audio 16944 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #38 [Mar 6 03:49:41] DEBUG[16406]: channel.c:4048 ast_channel_bridge: Returning from native bridge, channels: SIP/67.107.145.53-08d06ed8, SIP/level3-08d144c0 [Mar 6 03:49:41] DEBUG[16406]: channel.c:1693 ast_hangup: Hanging up channel 'SIP/level3-08d144c0' [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:3310 sip_hangup: Hangup call SIP/level3-08d144c0, SIP callid 4c966af4386b16b84f0148e77fda502f@67.107.145.54) [Mar 6 03:49:41] Scheduling destruction of SIP dialog '4c966af4386b16b84f0148e77fda502f@67.107.145.54' in 32000 ms (Method: INVITE) [Mar 6 03:49:41] DEBUG[16406]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/level3-08d144c0 [Mar 6 03:49:41] DEBUG[16406]: rtp.c:1474 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Mar 6 03:49:41] DEBUG[16406]: app_dial.c:1670 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Mar 6 03:49:41] DEBUG[16406]: pbx.c:2389 __ast_pbx_run: Spawn extension (deskphone,14089830588,8) exited non-zero on 'SIP/67.107.145.53-08d06ed8' [Mar 6 03:49:41] == Spawn extension (deskphone, 14089830588, 8) exited non-zero on 'SIP/67.107.145.53-08d06ed8' [Mar 6 03:49:41] DEBUG[16104]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - level3 [Mar 6 03:49:41] DEBUG[16104]: chan_sip.c:15207 sip_devicestate: Checking device state for peer level3 [Mar 6 03:49:41] DEBUG[16104]: devicestate.c:287 do_state_change: Changing state for SIP/level3 - state 1 (Not in use) [Mar 6 03:49:41] DEBUG[16482]: app_queue.c:546 changethread: Device 'SIP/level3' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 6 03:49:41] DEBUG[16406]: cdr_addon_mysql.c:210 mysql_log: cdr_mysql: inserting a CDR record. [Mar 6 03:49:41] DEBUG[16406]: cdr_addon_mysql.c:226 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2007-03-06 03:49:31','\"7027950101\" <7027950101>','7027950101','14089830588','deskphone', 'SIP/67.107.145.53-08d06ed8','SIP/level3-08d144c0','Dial','SIP/level3/+14089830588|120',10,8,'ANSWERED',3,'','1173152971.0') [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '"7027950101" <7027950101>' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '7027950101' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '14089830588' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'deskphone' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'SIP/67.107.145.53-08d06ed8' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'SIP/level3-08d144c0' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'Dial' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'SIP/level3/+14089830588|120' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2007-03-06 03:49:31' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2007-03-06 03:49:33' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2007-03-06 03:49:41' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '10' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '8' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '1173152971.0' [Mar 6 03:49:41] DEBUG[16406]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '' [Mar 6 03:49:41] DEBUG[16406]: channel.c:1693 ast_hangup: Hanging up channel 'SIP/67.107.145.53-08d06ed8' [Mar 6 03:49:41] DEBUG[16406]: chan_sip.c:3310 sip_hangup: Hangup call SIP/67.107.145.53-08d06ed8, SIP callid 6abf4ca14f9a76322540fcd94ae40738@67.107.145.53) [Mar 6 03:49:41] DEBUG[16406]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/67.107.145.53-08d06ed8 [Mar 6 03:49:41] DEBUG[16104]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 67.107.145.53 [Mar 6 03:49:41] DEBUG[16104]: chan_sip.c:15207 sip_devicestate: Checking device state for peer 67.107.145.53 [Mar 6 03:49:41] DEBUG[16104]: res_config_mysql.c:651 mysql_reconnect: MySQL RealTime: Everything is fine. [Mar 6 03:49:41] DEBUG[16104]: res_config_mysql.c:139 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '67.107.145.53' [Mar 6 03:49:41] DEBUG[16104]: devicestate.c:287 do_state_change: Changing state for SIP/67.107.145.53 - state 1 (Not in use) [Mar 6 03:49:41] DEBUG[16483]: app_queue.c:546 changethread: Device 'SIP/67.107.145.53' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 6 03:49:41] <--- SIP read from 4.55.16.99:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK13f0efb9;rport=5060 From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 104 INVITE Content-Length: 0 <-------------> [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 100 Trying (18) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK13f0efb9;rport=5060 (69) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=gK029bd4e4 (48) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: CSeq: 104 INVITE (16) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: Content-Length: 0 (17) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: (0) [Mar 6 03:49:41] --- (7 headers 0 lines) --- [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:2120 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #38 - INVITE (got response) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:2129 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4c966af4386b16b84f0148e77fda502f@67.107.145.54' Request 104: Found [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:11627 handle_response_invite: SIP response 100 to standard invite [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:5637 reqprep: Strict routing enforced for session 4c966af4386b16b84f0148e77fda502f@67.107.145.54 [Mar 6 03:49:41] set_destination: Parsing for address/port to send to [Mar 6 03:49:41] set_destination: set destination to 4.55.16.99, port 5060 [Mar 6 03:49:41] Reliably Transmitting (no NAT) to 4.55.16.99:5060: BYE sip:+14089830588@4.55.16.99:5060 SIP/2.0 Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK511cb7df;rport From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 105 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Remote-Party-ID: "7027950101" ;privacy=off;screen=no Content-Length: 0 --- [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:1973 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #40 [Mar 6 03:49:41] Scheduling destruction of SIP dialog '4c966af4386b16b84f0148e77fda502f@67.107.145.54' in 32000 ms (Method: INVITE) [Mar 6 03:49:41] Really destroying SIP dialog '6abf4ca14f9a76322540fcd94ae40738@67.107.145.53' Method: BYE [Mar 6 03:49:41] <--- SIP read from 4.55.16.99:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK511cb7df;rport=5060 From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 105 BYE Content-Length: 0 <-------------> [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK511cb7df;rport=5060 (69) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=gK029bd4e4 (48) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: CSeq: 105 BYE (13) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: Content-Length: 0 (17) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: (0) [Mar 6 03:49:41] --- (7 headers 0 lines) --- [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:2077 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #40 [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '4c966af4386b16b84f0148e77fda502f@67.107.145.54' of Request 105: Match Not Found [Mar 6 03:49:41] <--- SIP read from 4.55.16.99:5060 ---> SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK13f0efb9;rport=5060 From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 104 INVITE Content-Length: 0 <-------------> [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 0: SIP/2.0 487 Request Terminated (30) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 1: Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK13f0efb9;rport=5060 (69) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 2: From: "7027950101" ;tag=as1a7a2dfc (66) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 3: To: ;tag=gK029bd4e4 (48) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 4: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 (55) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 5: CSeq: 104 INVITE (16) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 6: Content-Length: 0 (17) [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:4571 parse_request: Header 7: (0) [Mar 6 03:49:41] --- (7 headers 0 lines) --- [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:2069 __sip_ack: Acked pending invite 104 [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '4c966af4386b16b84f0148e77fda502f@67.107.145.54' of Request 104: Match Not Found [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:11627 handle_response_invite: SIP response 487 to standard invite [Mar 6 03:49:41] DEBUG[16135]: chan_sip.c:5637 reqprep: Strict routing enforced for session 4c966af4386b16b84f0148e77fda502f@67.107.145.54 [Mar 6 03:49:41] set_destination: Parsing for address/port to send to [Mar 6 03:49:41] set_destination: set destination to 4.55.16.99, port 5060 [Mar 6 03:49:41] Transmitting (no NAT) to 4.55.16.99:5060: ACK sip:+14089830588@4.55.16.99:5060 SIP/2.0 Via: SIP/2.0/UDP 67.107.145.54:5060;branch=z9hG4bK511cb7df;rport From: "7027950101" ;tag=as1a7a2dfc To: ;tag=gK029bd4e4 Contact: Call-ID: 4c966af4386b16b84f0148e77fda502f@67.107.145.54 CSeq: 104 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Remote-Party-ID: "7027950101" ;privacy=off;screen=no Content-Length: 0 --- [Mar 6 03:49:41] Really destroying SIP dialog '4c966af4386b16b84f0148e77fda502f@67.107.145.54' Method: INVITE [Mar 6 03:49:42]