<--- SIP read from 83.245.6.83:5060 ---> INVITE sip:448001180118@89.202.128.200 SIP/2.0 Max-Forwards: 11 Session-Expires: 3600;Refresher=uac Supported: timer To: From: ;tag=3373980756-449348 Remote-Party-Id: ;party=calling;screen=yes;privacy=off Call-ID: 1596574-3373980756-449309@msw8.mydomain.com CSeq: 1 INVITE Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bKd995bf4366c6aa6b3acb3311b6cefba0 Contact: sip:442074904605@83.245.6.83:5060 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 246 v=0 o=msw 3543 4063 IN IP4 83.245.6.83 s=sip call c=IN IP4 83.245.6.84 t=0 0 m=audio 20486 RTP/AVP 0 100 101 a=ptime:20 a=fmtp:101 0-16 a=rtpmap:101 telephone-event/8000 a=fmtp:100 192-194 a=rtpmap:100 X-NSE/8000 a=rtpmap:0 PCMU/8000 <-------------> [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 46]: INVITE sip:448001180118@89.202.128.200 SIP/2.0 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 16]: Max-Forwards: 11 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 35]: Session-Expires: 3600;Refresher=uac [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 16]: Supported: timer [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 42]: To: [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 58]: From: ;tag=3373980756-449348 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 84]: Remote-Party-Id: ;party=calling;screen=yes;privacy=off [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 52]: Call-ID: 1596574-3373980756-449309@msw8.mydomain.com [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 8 [ 14]: CSeq: 1 INVITE [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 9 [ 80]: Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bKd995bf4366c6aa6b3acb3311b6cefba0 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 10 [ 42]: Contact: sip:442074904605@83.245.6.83:5060 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 11 [ 29]: Allow-Events: telephone-event [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 12 [ 29]: Content-Type: application/sdp [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 13 [ 19]: Content-Length: 246 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 14 [ 0]: [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 0 [ 3]: v=0 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 1 [ 34]: o=msw 3543 4063 IN IP4 83.245.6.83 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 2 [ 10]: s=sip call [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 3 [ 20]: c=IN IP4 83.245.6.84 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 4 [ 5]: t=0 0 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 5 [ 31]: m=audio 20486 RTP/AVP 0 100 101 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 6 [ 10]: a=ptime:20 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 7 [ 15]: a=fmtp:101 0-16 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 9 [ 18]: a=fmtp:100 192-194 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 10 [ 23]: a=rtpmap:100 X-NSE/8000 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 11 [ 20]: a=rtpmap:0 PCMU/8000 [Dec 1 16:51:46] --- (14 headers 12 lines) --- [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:2671 do_setnat: Setting NAT on RTP to Off [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:2681 do_setnat: Setting NAT on UDPTL to Off [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4359 sip_alloc: Allocating new SIP dialog for 1596574-3373980756-449309@msw8.mydomain.com - INVITE (With RTP) [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:1707 parse_sip_options: Begin: parsing SIP "Supported: timer" [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:1715 parse_sip_options: Found SIP option: -timer- [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:1721 parse_sip_options: Matched SIP option: timer [Dec 1 16:51:46] Sending to 83.245.6.83 : 5060 (no NAT) [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:13334 handle_request_invite: Initializing initreq for method INVITE - callid 1596574-3373980756-449309@msw8.mydomain.com [Dec 1 16:51:46] Using INVITE request as basis request - 1596574-3373980756-449309@msw8.mydomain.com [Dec 1 16:51:46] No user '442074904605' in SIP users list [Dec 1 16:51:46] Found peer 'gamma-OUT' for '442074904605' from 83.245.6.83:5060 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:2671 do_setnat: Setting NAT on RTP to Off [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:2681 do_setnat: Setting NAT on UDPTL to Off [Dec 1 16:51:46] Found RTP audio format 0 [Dec 1 16:51:46] Found RTP audio format 100 [Dec 1 16:51:46] Found RTP audio format 101 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4924 process_sdp: Peer doesn't provide T.38 UDPTL [Dec 1 16:51:46] Peer audio RTP is at port 83.245.6.84:20486 [Dec 1 16:51:46] Got unsupported a:fmtp in SDP offer [Dec 1 16:51:46] Found description format telephone-event for ID 101 [Dec 1 16:51:46] Got unsupported a:fmtp in SDP offer [Dec 1 16:51:46] Found description format X-NSE for ID 100 [Dec 1 16:51:46] Found description format PCMU for ID 0 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:5154 process_sdp: T38 state changed to 0 on channel [Dec 1 16:51:46] Capabilities: us - 0x3f1fff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|jpeg|png|h261|h263|h263p|h264), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Dec 1 16:51:46] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 1 16:51:46] Peer audio RTP is at port 83.245.6.84:20486 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:5231 process_sdp: We're settling with these formats: 0x4 (ulaw) [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:13411 handle_request_invite: Checking SIP call limits for device [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:3092 update_call_counter: Updating call counter for incoming call [Dec 1 16:51:46] Looking for 448001180118 in from-gamma (domain 89.202.128.200) [Dec 1 16:51:46] DEBUG[26459]: frame.c:1137 ast_codec_choose: Could not find preferred codec - Going for the best codec [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:3868 sip_new: *** Our native formats are 0x4 (ulaw) [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:3869 sip_new: *** Joint capabilities are 0x4 (ulaw) [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:3870 sip_new: *** Our capabilities are 0x3f1fff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|jpeg|png|h261|h263|h263p|h264) [Dec 1 16:51:46] DEBUG[26459]: frame.c:1137 ast_codec_choose: Could not find preferred codec - Going for the best codec [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:3871 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:3894 sip_new: This channel will not be able to handle video. [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:7952 build_route: build_route: Contact hop: sip:442074904605@83.245.6.83:5060 [Dec 1 16:51:46] list_route: hop: [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:13484 handle_request_invite: SIP/83.245.6.83-082666f8: New call is still down.... Trying... [Dec 1 16:51:46] <--- Transmitting (no NAT) to 83.245.6.83:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bKd995bf4366c6aa6b3acb3311b6cefba0;received=83.245.6.83 From: ;tag=3373980756-449348 To: Call-ID: 1596574-3373980756-449309@msw8.mydomain.com CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 1 16:51:46] DEBUG[26459]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/83.245.6.83-082666f8 [Dec 1 16:51:46] DEBUG[26428]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 83.245.6.83 [Dec 1 16:51:46] DEBUG[26428]: chan_sip.c:15225 sip_devicestate: Checking device state for peer 83.245.6.83 [Dec 1 16:51:46] DEBUG[26428]: devicestate.c:287 do_state_change: Changing state for SIP/83.245.6.83 - state 2 (In use) [Dec 1 16:51:46] DEBUG[26503]: pbx.c:1685 pbx_extension_helper: Launching 'DeadAGI' [Dec 1 16:51:46] -- Executing [448001180118@from-gamma:1] DeadAGI("SIP/83.245.6.83-082666f8", "agi://127.0.0.1:4574/numbertrans?number_in=448001180118&context=gamma") in new stack [Dec 1 16:51:46] DEBUG[26503]: res_agi.c:228 launch_netscript: Wow, connected! [Dec 1 16:51:46] DEBUG[26504]: app_queue.c:568 changethread: Device 'SIP/83.245.6.83' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 1 16:51:46] -- AGI Script Executing Application: (Dial) Options: (Local/442070605610@gamma/n) [Dec 1 16:51:46] DEBUG[26503]: rtp.c:1548 ast_rtp_make_compatible: Channel 'Local/442070605610@gamma-0b52,1' has no RTP, not doing anything [Dec 1 16:51:46] DEBUG[26503]: channel.c:3186 ast_channel_inherit_variables: Copying hard-transferable variable CALLER-ID. [Dec 1 16:51:46] DEBUG[26503]: channel.c:3186 ast_channel_inherit_variables: Copying hard-transferable variable CALLER-PRES. [Dec 1 16:51:46] DEBUG[26503]: channel.c:3191 ast_channel_inherit_variables: Not copying variable STACK-from-gamma-448001180118-1. [Dec 1 16:51:46] DEBUG[26503]: channel.c:3191 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Dec 1 16:51:46] DEBUG[26503]: channel.c:3191 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Dec 1 16:51:46] DEBUG[26503]: channel.c:3191 ast_channel_inherit_variables: Not copying variable SIPURI. [Dec 1 16:51:46] -- Called 442070605610@gamma/n [Dec 1 16:51:46] DEBUG[26505]: pbx.c:1685 pbx_extension_helper: Launching 'Set' [Dec 1 16:51:46] -- Executing [442070605610@gamma:1] Set("Local/442070605610@gamma-0b52,2", "CALLERID(all)=442074904605") in new stack [Dec 1 16:51:46] DEBUG[26505]: pbx.c:1685 pbx_extension_helper: Launching 'Set' [Dec 1 16:51:46] -- Executing [442070605610@gamma:2] Set("Local/442070605610@gamma-0b52,2", "CALLERID(ANI)=123") in new stack [Dec 1 16:51:46] DEBUG[26505]: pbx.c:1685 pbx_extension_helper: Launching 'SetCallerPres' [Dec 1 16:51:46] -- Executing [442070605610@gamma:3] SetCallerPres("Local/442070605610@gamma-0b52,2", "allowed") in new stack [Dec 1 16:51:46] DEBUG[26505]: pbx.c:1685 pbx_extension_helper: Launching 'Dial' [Dec 1 16:51:46] -- Executing [442070605610@gamma:4] Dial("Local/442070605610@gamma-0b52,2", "SIP/gamma-OUT/442070605610") in new stack [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:15283 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4359 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:2717 create_addr_from_peer: Our T38 capability (3840) [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:2671 do_setnat: Setting NAT on RTP to Off [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:2681 do_setnat: Setting NAT on UDPTL to Off [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:3868 sip_new: *** Our native formats are 0x8 (alaw) [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:3869 sip_new: *** Joint capabilities are 0x0 (nothing) [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:3870 sip_new: *** Our capabilities are 0x3f1fff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|jpeg|png|h261|h263|h263p|h264) [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:3871 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:3873 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:3894 sip_new: This channel will not be able to handle video. [Dec 1 16:51:46] DEBUG[26505]: rtp.c:1555 ast_rtp_make_compatible: Channel 'Local/442070605610@gamma-0b52,2' has no RTP, not doing anything [Dec 1 16:51:46] DEBUG[26505]: channel.c:3191 ast_channel_inherit_variables: Not copying variable STACK-gamma-442070605610-4. [Dec 1 16:51:46] DEBUG[26505]: channel.c:3191 ast_channel_inherit_variables: Not copying variable STACK-gamma-442070605610-3. [Dec 1 16:51:46] DEBUG[26505]: channel.c:3191 ast_channel_inherit_variables: Not copying variable STACK-gamma-442070605610-2. [Dec 1 16:51:46] DEBUG[26505]: channel.c:3191 ast_channel_inherit_variables: Not copying variable STACK-gamma-442070605610-1. [Dec 1 16:51:46] DEBUG[26505]: channel.c:3191 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER. [Dec 1 16:51:46] DEBUG[26505]: channel.c:3186 ast_channel_inherit_variables: Copying hard-transferable variable CALLER-ID. [Dec 1 16:51:46] DEBUG[26505]: channel.c:3186 ast_channel_inherit_variables: Copying hard-transferable variable CALLER-PRES. [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:2918 sip_call: Outgoing Call for 442070605610 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:3092 update_call_counter: Updating call counter for outgoing call [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:2935 sip_call: Our T38 capability (3840), joint T38 capability (3840) [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:6228 add_sdp: ** Our capability: 0x3f0cfe (gsm|ulaw|alaw|g726|adpcm|slin|lpc10|ilbc|g726aal2|jpeg|png|h261|h263|h263p|h264) Video flag: False [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:6229 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:6246 add_sdp: This call needs video offers, but there's no video support enabled! [Dec 1 16:51:46] Audio is at 89.202.128.200 port 18754 [Dec 1 16:51:46] Adding codec 0x4 (ulaw) to SDP [Dec 1 16:51:46] Adding codec 0x8 (alaw) to SDP [Dec 1 16:51:46] Adding codec 0x2 (gsm) to SDP [Dec 1 16:51:46] Adding codec 0x10 (g726aal2) to SDP [Dec 1 16:51:46] Adding codec 0x20 (adpcm) to SDP [Dec 1 16:51:46] Adding codec 0x40 (slin) to SDP [Dec 1 16:51:46] Adding codec 0x80 (lpc10) to SDP [Dec 1 16:51:46] Adding codec 0x400 (ilbc) to SDP [Dec 1 16:51:46] Adding codec 0x800 (g726) to SDP [Dec 1 16:51:46] Adding non-codec 0x1 (telephone-event) to SDP [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:6354 add_sdp: -- Done with adding codecs to SDP [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:6398 add_sdp: Done building SDP. Settling with this capability: 0x3f0cfe (gsm|ulaw|alaw|g726|adpcm|slin|lpc10|ilbc|g726aal2|jpeg|png|h261|h263|h263p|h264) [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:1655 initialize_initreq: Initializing initreq for method INVITE - callid 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 0 [ 43]: INVITE sip:442070605610@83.245.6.83 SIP/2.0 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 89.202.128.200:5060;branch=z9hG4bK09988043;rport [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 2 [ 16]: Max-Forwards: 70 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 3 [ 69]: From: "442074904605" ;tag=as269e358f [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 4 [ 34]: To: [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 5 [ 42]: Contact: [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 6 [ 56]: Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 7 [ 16]: CSeq: 102 INVITE [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 8 [ 24]: User-Agent: Asterisk PBX [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 9 [ 88]: Remote-Party-ID: "442074904605" ;privacy=off;screen=yes [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 10 [ 35]: Date: Fri, 01 Dec 2006 16:51:46 GMT [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 11 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 12 [ 19]: Supported: replaces [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 13 [ 29]: Content-Type: application/sdp [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 14 [ 19]: Content-Length: 475 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Header 15 [ 0]: [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 0 [ 3]: v=0 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 1 [ 40]: o=root 26424 26424 IN IP4 89.202.128.200 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 2 [ 9]: s=session [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 3 [ 23]: c=IN IP4 89.202.128.200 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 4 [ 5]: t=0 0 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 5 [ 49]: m=audio 18754 RTP/AVP 0 8 3 112 5 10 7 97 111 101 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 9 [ 30]: a=rtpmap:112 AAL2-G726-32/8000 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 10 [ 20]: a=rtpmap:5 DVI4/8000 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 11 [ 20]: a=rtpmap:10 L16/8000 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 12 [ 19]: a=rtpmap:7 LPC/8000 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 13 [ 21]: a=rtpmap:97 iLBC/8000 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 14 [ 17]: a=fmtp:97 mode=30 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 15 [ 25]: a=rtpmap:111 G726-32/8000 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 16 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 17 [ 15]: a=fmtp:101 0-16 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 18 [ 25]: a=silenceSupp:off - - - - [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 19 [ 10]: a=ptime:20 [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:4637 parse_request: Body 20 [ 10]: a=sendrecv [Dec 1 16:51:46] Reliably Transmitting (no NAT) to 83.245.6.83:5060: INVITE sip:442070605610@83.245.6.83 SIP/2.0 Via: SIP/2.0/UDP 89.202.128.200:5060;branch=z9hG4bK09988043;rport Max-Forwards: 70 From: "442074904605" ;tag=as269e358f To: Contact: Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 CSeq: 102 INVITE User-Agent: Asterisk PBX Remote-Party-ID: "442074904605" ;privacy=off;screen=yes Date: Fri, 01 Dec 2006 16:51:46 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 475 v=0 o=root 26424 26424 IN IP4 89.202.128.200 s=session c=IN IP4 89.202.128.200 t=0 0 m=audio 18754 RTP/AVP 0 8 3 112 5 10 7 97 111 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:112 AAL2-G726-32/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:10 L16/8000 a=rtpmap:7 LPC/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:111 G726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Dec 1 16:51:46] DEBUG[26505]: chan_sip.c:1997 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #26 [Dec 1 16:51:46] -- Called gamma-OUT/442070605610 [Dec 1 16:51:46] DEBUG[26505]: channel.c:2735 set_format: Set channel SIP/gamma-OUT-0827a1b8 to read format ulaw [Dec 1 16:51:46] DEBUG[26505]: channel.c:2735 set_format: Set channel Local/442070605610@gamma-0b52,2 to read format alaw [Dec 1 16:51:46] <--- SIP read from 83.245.6.83:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 89.202.128.200:5060;branch=z9hG4bK09988043;rport From: "442074904605" ;tag=as269e358f To: Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 CSeq: 102 INVITE Content-Length: 0 <-------------> [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 18]: SIP/2.0 100 Trying [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 89.202.128.200:5060;branch=z9hG4bK09988043;rport [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 69]: From: "442074904605" ;tag=as269e358f [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 34]: To: [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 56]: Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 16]: CSeq: 102 INVITE [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 17]: Content-Length: 0 [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 0]: [Dec 1 16:51:46] --- (7 headers 0 lines) --- [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:2141 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #26 - INVITE (got response) [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:2150 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200' Request 102: Found [Dec 1 16:51:46] DEBUG[26459]: chan_sip.c:11708 handle_response_invite: SIP response 100 to standard invite [Dec 1 16:51:47] <--- SIP read from 208.51.25.114:5060 ---> OPTIONS sip:89.202.128.200:5060 SIP/2.0 Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goapf2068v1hh0l3180.1 Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 To: sip:ping@89.202.128.200 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f Max-Forwards: 70 CSeq: 17929 OPTIONS <-------------> [Dec 1 16:51:47] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 39]: OPTIONS sip:89.202.128.200:5060 SIP/2.0 [Dec 1 16:51:47] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 72]: Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goapf2068v1hh0l3180.1 [Dec 1 16:51:47] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 55]: Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 [Dec 1 16:51:47] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 27]: To: sip:ping@89.202.128.200 [Dec 1 16:51:47] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 65]: From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f [Dec 1 16:51:47] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 16]: Max-Forwards: 70 [Dec 1 16:51:47] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 19]: CSeq: 17929 OPTIONS [Dec 1 16:51:47] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 0]: [Dec 1 16:51:47] --- (7 headers 0 lines) --- [Dec 1 16:51:47] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Dec 1 16:51:47] Looking for s in default (domain 89.202.128.200) [Dec 1 16:51:47] <--- Transmitting (no NAT) to 208.51.25.114:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goapf2068v1hh0l3180.1;received=208.51.25.114 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f To: sip:ping@89.202.128.200;tag=as665950ab Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 CSeq: 17929 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <------------> [Dec 1 16:51:47] Scheduling destruction of SIP dialog '6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114' in 32000 ms (Method: OPTIONS) [Dec 1 16:51:48] <--- SIP read from 83.245.6.83:5060 ---> SIP/2.0 180 Ringing To: ;tag=3373980758-594199 From: "442074904605" ;tag=as269e358f Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 CSeq: 102 INVITE Contact: sip:442070605610@83.245.6.83:5060 Allow-Events: telephone-event Via: SIP/2.0/UDP 89.202.128.200:5060;branch=z9hG4bK09988043;rport Content-Length: 0 <-------------> [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 19]: SIP/2.0 180 Ringing [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 56]: To: ;tag=3373980758-594199 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 69]: From: "442074904605" ;tag=as269e358f [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 56]: Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 16]: CSeq: 102 INVITE [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 42]: Contact: sip:442070605610@83.245.6.83:5060 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 29]: Allow-Events: telephone-event [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 65]: Via: SIP/2.0/UDP 89.202.128.200:5060;branch=z9hG4bK09988043;rport [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 8 [ 17]: Content-Length: 0 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 9 [ 0]: [Dec 1 16:51:48] --- (9 headers 0 lines) --- [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:2150 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200' Request 102: Found [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:11708 handle_response_invite: SIP response 180 to standard invite [Dec 1 16:51:48] DEBUG[26459]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/gamma-OUT-0827a1b8 [Dec 1 16:51:48] -- SIP/gamma-OUT-0827a1b8 is ringing [Dec 1 16:51:48] DEBUG[26428]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - gamma-OUT [Dec 1 16:51:48] DEBUG[26428]: chan_sip.c:15225 sip_devicestate: Checking device state for peer gamma-OUT [Dec 1 16:51:48] DEBUG[26428]: devicestate.c:287 do_state_change: Changing state for SIP/gamma-OUT - state 1 (Not in use) [Dec 1 16:51:48] -- Local/442070605610@gamma-0b52,1 is ringing [Dec 1 16:51:48] <--- Transmitting (no NAT) to 83.245.6.83:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bKd995bf4366c6aa6b3acb3311b6cefba0;received=83.245.6.83 From: ;tag=3373980756-449348 To: ;tag=as08eef8ec Call-ID: 1596574-3373980756-449309@msw8.mydomain.com CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 1 16:51:48] DEBUG[26506]: app_queue.c:568 changethread: Device 'SIP/gamma-OUT' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 1 16:51:48] <--- SIP read from 83.245.6.83:5060 ---> SIP/2.0 200 OK To: ;tag=3373980758-594199 From: "442074904605" ;tag=as269e358f Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 CSeq: 102 INVITE Contact: sip:442070605610@83.245.6.83:5060 Allow-Events: telephone-event Content-Type: application/sdp Via: SIP/2.0/UDP 89.202.128.200:5060;branch=z9hG4bK09988043;rport Content-Length: 196 v=0 o=msw 8240 568 IN IP4 83.245.6.83 s=sip call c=IN IP4 83.245.6.84 t=0 0 m=audio 20494 RTP/AVP 0 101 a=ptime:20 a=fmtp:101 0-16 a=rtpmap:101 telephone-event/8000 a=rtpmap:0 PCMU/8000 <-------------> [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 14]: SIP/2.0 200 OK [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 56]: To: ;tag=3373980758-594199 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 69]: From: "442074904605" ;tag=as269e358f [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 56]: Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 16]: CSeq: 102 INVITE [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 42]: Contact: sip:442070605610@83.245.6.83:5060 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 29]: Allow-Events: telephone-event [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 29]: Content-Type: application/sdp [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 8 [ 65]: Via: SIP/2.0/UDP 89.202.128.200:5060;branch=z9hG4bK09988043;rport [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 9 [ 19]: Content-Length: 196 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 10 [ 0]: [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 0 [ 3]: v=0 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 1 [ 33]: o=msw 8240 568 IN IP4 83.245.6.83 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 2 [ 10]: s=sip call [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 3 [ 20]: c=IN IP4 83.245.6.84 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 4 [ 5]: t=0 0 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 5 [ 27]: m=audio 20494 RTP/AVP 0 101 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 6 [ 10]: a=ptime:20 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 7 [ 15]: a=fmtp:101 0-16 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 9 [ 20]: a=rtpmap:0 PCMU/8000 [Dec 1 16:51:48] --- (10 headers 10 lines) --- [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:2091 __sip_ack: Acked pending invite 102 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:2107 __sip_ack: Stopping retransmission on '6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200' of Request 102: Match Found [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:11708 handle_response_invite: SIP response 200 to standard invite [Dec 1 16:51:48] Found RTP audio format 0 [Dec 1 16:51:48] Found RTP audio format 101 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4924 process_sdp: Peer doesn't provide T.38 UDPTL [Dec 1 16:51:48] Peer audio RTP is at port 83.245.6.84:20494 [Dec 1 16:51:48] Got unsupported a:fmtp in SDP offer [Dec 1 16:51:48] Found description format telephone-event for ID 101 [Dec 1 16:51:48] Found description format PCMU for ID 0 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:5154 process_sdp: T38 state changed to 0 on channel SIP/gamma-OUT-0827a1b8 [Dec 1 16:51:48] Capabilities: us - 0x3f1fff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|jpeg|png|h261|h263|h263p|h264), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Dec 1 16:51:48] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 1 16:51:48] Peer audio RTP is at port 83.245.6.84:20494 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:5231 process_sdp: We're settling with these formats: 0x4 (ulaw) [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:5238 process_sdp: We have an owner, now see if we need to change this call [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:5243 process_sdp: Oooh, we need to change our audio formats since our peer supports only 0x4 (ulaw) and not 0x8 (alaw) [Dec 1 16:51:48] DEBUG[26459]: frame.c:1137 ast_codec_choose: Could not find preferred codec - Going for the best codec [Dec 1 16:51:48] DEBUG[26459]: channel.c:2735 set_format: Set channel SIP/gamma-OUT-0827a1b8 to read format ulaw [Dec 1 16:51:48] DEBUG[26459]: channel.c:2735 set_format: Set channel SIP/gamma-OUT-0827a1b8 to write format alaw [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:3092 update_call_counter: Updating call counter for outgoing call [Dec 1 16:51:48] --- set_address_from_contact host '83.245.6.83' [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:7952 build_route: build_route: Contact hop: sip:442070605610@83.245.6.83:5060 [Dec 1 16:51:48] list_route: hop: [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:5663 reqprep: Strict routing enforced for session 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:51:48] set_destination: Parsing for address/port to send to [Dec 1 16:51:48] set_destination: set destination to 83.245.6.83, port 5060 [Dec 1 16:51:48] Transmitting (no NAT) to 83.245.6.83:5060: ACK sip:442070605610@83.245.6.83:5060 SIP/2.0 Via: SIP/2.0/UDP 89.202.128.200:5060;branch=z9hG4bK704d1522;rport Max-Forwards: 70 From: "442074904605" ;tag=as269e358f To: ;tag=3373980758-594199 Contact: Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 CSeq: 102 ACK User-Agent: Asterisk PBX Remote-Party-ID: "442074904605" ;privacy=off;screen=yes Content-Length: 0 --- [Dec 1 16:51:48] DEBUG[26505]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/gamma-OUT-0827a1b8 [Dec 1 16:51:48] -- SIP/gamma-OUT-0827a1b8 answered Local/442070605610@gamma-0b52,2 [Dec 1 16:51:48] DEBUG[26505]: channel.c:2735 set_format: Set channel Local/442070605610@gamma-0b52,2 to read format ulaw [Dec 1 16:51:48] DEBUG[26505]: channel.c:2735 set_format: Set channel SIP/gamma-OUT-0827a1b8 to write format ulaw [Dec 1 16:51:48] DEBUG[26503]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/442070605610@gamma-0b52,1 [Dec 1 16:51:48] -- Local/442070605610@gamma-0b52,1 answered SIP/83.245.6.83-082666f8 [Dec 1 16:51:48] DEBUG[26503]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/83.245.6.83-082666f8 [Dec 1 16:51:48] DEBUG[26503]: chan_sip.c:3536 sip_answer: SIP answering channel: SIP/83.245.6.83-082666f8 [Dec 1 16:51:48] DEBUG[26503]: chan_sip.c:6453 transmit_response_with_sdp: Setting framing from config on incoming call [Dec 1 16:51:48] DEBUG[26503]: chan_sip.c:6228 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Dec 1 16:51:48] DEBUG[26503]: chan_sip.c:6229 add_sdp: ** Our prefcodec: 0x0 (nothing) [Dec 1 16:51:48] Audio is at 89.202.128.200 port 16188 [Dec 1 16:51:48] Adding codec 0x4 (ulaw) to SDP [Dec 1 16:51:48] Adding non-codec 0x1 (telephone-event) to SDP [Dec 1 16:51:48] DEBUG[26503]: chan_sip.c:6354 add_sdp: -- Done with adding codecs to SDP [Dec 1 16:51:48] DEBUG[26503]: chan_sip.c:6398 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Dec 1 16:51:48] <--- Reliably Transmitting (no NAT) to 83.245.6.83:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bKd995bf4366c6aa6b3acb3311b6cefba0;received=83.245.6.83 From: ;tag=3373980756-449348 To: ;tag=as08eef8ec Call-ID: 1596574-3373980756-449309@msw8.mydomain.com CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 244 v=0 o=root 26424 26424 IN IP4 89.202.128.200 s=session c=IN IP4 89.202.128.200 t=0 0 m=audio 16188 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 <------------> [Dec 1 16:51:48] DEBUG[26503]: chan_sip.c:1997 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #29 [Dec 1 16:51:48] DEBUG[26505]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/442070605610@gamma-0b52,2 [Dec 1 16:51:48] DEBUG[26428]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - gamma-OUT [Dec 1 16:51:48] DEBUG[26428]: chan_sip.c:15225 sip_devicestate: Checking device state for peer gamma-OUT [Dec 1 16:51:48] DEBUG[26428]: devicestate.c:287 do_state_change: Changing state for SIP/gamma-OUT - state 1 (Not in use) [Dec 1 16:51:48] DEBUG[26428]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 442070605610@gamma [Dec 1 16:51:48] DEBUG[26428]: chan_local.c:145 local_devicestate: Checking if extension 442070605610@gamma exists (devicestate) [Dec 1 16:51:48] DEBUG[26428]: devicestate.c:287 do_state_change: Changing state for Local/442070605610@gamma - state 2 (In use) [Dec 1 16:51:48] DEBUG[26428]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 83.245.6.83 [Dec 1 16:51:48] DEBUG[26428]: chan_sip.c:15225 sip_devicestate: Checking device state for peer 83.245.6.83 [Dec 1 16:51:48] DEBUG[26428]: devicestate.c:287 do_state_change: Changing state for SIP/83.245.6.83 - state 2 (In use) [Dec 1 16:51:48] DEBUG[26428]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 442070605610@gamma [Dec 1 16:51:48] DEBUG[26428]: chan_local.c:145 local_devicestate: Checking if extension 442070605610@gamma exists (devicestate) [Dec 1 16:51:48] DEBUG[26428]: devicestate.c:287 do_state_change: Changing state for Local/442070605610@gamma - state 2 (In use) [Dec 1 16:51:48] DEBUG[26507]: app_queue.c:568 changethread: Device 'SIP/gamma-OUT' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 1 16:51:48] DEBUG[26508]: app_queue.c:568 changethread: Device 'Local/442070605610@gamma' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 1 16:51:48] DEBUG[26509]: app_queue.c:568 changethread: Device 'SIP/83.245.6.83' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 1 16:51:48] DEBUG[26510]: app_queue.c:568 changethread: Device 'Local/442070605610@gamma' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 1 16:51:48] <--- SIP read from 83.245.6.83:5060 ---> ACK sip:448001180118@89.202.128.200 SIP/2.0 Max-Forwards: 11 To: ;tag=as08eef8ec From: ;tag=3373980756-449348 Call-ID: 1596574-3373980756-449309@msw8.mydomain.com CSeq: 1 ACK Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bK49ec7cded69706318a033909a0524fb5 Contact: sip:442074904605@83.245.6.83:5060 Content-Length: 0 <-------------> [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 43]: ACK sip:448001180118@89.202.128.200 SIP/2.0 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 16]: Max-Forwards: 11 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 57]: To: ;tag=as08eef8ec [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 58]: From: ;tag=3373980756-449348 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 52]: Call-ID: 1596574-3373980756-449309@msw8.mydomain.com [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 11]: CSeq: 1 ACK [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 80]: Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bK49ec7cded69706318a033909a0524fb5 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 42]: Contact: sip:442074904605@83.245.6.83:5060 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 8 [ 17]: Content-Length: 0 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 9 [ 0]: [Dec 1 16:51:48] --- (9 headers 0 lines) --- [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:2096 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #29 [Dec 1 16:51:48] DEBUG[26459]: chan_sip.c:2107 __sip_ack: Stopping retransmission on '1596574-3373980756-449309@msw8.mydomain.com' of Response 1: Match Found [Dec 1 16:51:48] DEBUG[26503]: rtp.c:2631 ast_rtp_write: Ooh, format changed from unknown to ulaw [Dec 1 16:51:48] DEBUG[26503]: rtp.c:2648 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160 [Dec 1 16:51:49] DEBUG[26505]: rtp.c:2631 ast_rtp_write: Ooh, format changed from unknown to ulaw [Dec 1 16:51:49] DEBUG[26505]: rtp.c:2648 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160 [Dec 1 16:51:50] DEBUG[26503]: rtp.c:858 ast_rtcp_read: Got RTCP report of 132 bytes [Dec 1 16:51:50] DEBUG[26505]: rtp.c:858 ast_rtcp_read: Got RTCP report of 112 bytes [Dec 1 16:51:52] DEBUG[26503]: rtp.c:858 ast_rtcp_read: Got RTCP report of 132 bytes [Dec 1 16:51:52] <--- SIP read from 83.245.6.83:5060 ---> INVITE sip:442074904605@89.202.128.200 SIP/2.0 Max-Forwards: 69 Session-Expires: 3600;Refresher=uac Supported: timer To: "442074904605" ;tag=as269e358f From: ;tag=3373980758-594199 Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 CSeq: 2 INVITE Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bK5b70f486c94e6e2f4e65dfb1772138cc Contact: sip:442070605610@83.245.6.83:5060 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 345 v=0 o=msw 8240 569 IN IP4 83.245.6.83 s=sip call c=IN IP4 83.245.6.84 t=0 0 m=image 20494 udptl t38 a=T38FaxUdpEC:t38UDPRedundancy a=T38FaxMaxDatagram:72 a=T38FaxMaxBuffer:200 a=T38FaxRateManagement:transferredTCF a=T38FaxTranscodingJBIG:0 a=T38FaxTranscodingMMR:0 a=T38FaxFillBitRemoval:0 a=T38MaxBitRate:14400 a=T38FaxVersion:0 <-------------> [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 46]: INVITE sip:442074904605@89.202.128.200 SIP/2.0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 16]: Max-Forwards: 69 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 35]: Session-Expires: 3600;Refresher=uac [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 16]: Supported: timer [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 67]: To: "442074904605" ;tag=as269e358f [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 58]: From: ;tag=3373980758-594199 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 56]: Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 14]: CSeq: 2 INVITE [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 8 [ 80]: Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bK5b70f486c94e6e2f4e65dfb1772138cc [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 9 [ 42]: Contact: sip:442070605610@83.245.6.83:5060 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 10 [ 29]: Allow-Events: telephone-event [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 11 [ 29]: Content-Type: application/sdp [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 12 [ 19]: Content-Length: 345 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 13 [ 0]: [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 0 [ 3]: v=0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 1 [ 33]: o=msw 8240 569 IN IP4 83.245.6.83 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 2 [ 10]: s=sip call [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 3 [ 20]: c=IN IP4 83.245.6.84 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 4 [ 5]: t=0 0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 5 [ 23]: m=image 20494 udptl t38 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 6 [ 30]: a=T38FaxUdpEC:t38UDPRedundancy [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 7 [ 22]: a=T38FaxMaxDatagram:72 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 8 [ 21]: a=T38FaxMaxBuffer:200 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 9 [ 37]: a=T38FaxRateManagement:transferredTCF [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 10 [ 25]: a=T38FaxTranscodingJBIG:0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 11 [ 24]: a=T38FaxTranscodingMMR:0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 12 [ 24]: a=T38FaxFillBitRemoval:0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 13 [ 21]: a=T38MaxBitRate:14400 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Body 14 [ 17]: a=T38FaxVersion:0 [Dec 1 16:51:52] --- (13 headers 15 lines) --- [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:1707 parse_sip_options: Begin: parsing SIP "Supported: timer" [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:1715 parse_sip_options: Found SIP option: -timer- [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:1721 parse_sip_options: Matched SIP option: timer [Dec 1 16:51:52] Sending to 83.245.6.83 : 5060 (no NAT) [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:13334 handle_request_invite: Initializing initreq for method INVITE - callid 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:51:52] Got T.38 offer in SDP in dialog 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4870 process_sdp: T38 state changed to 4 on channel SIP/gamma-OUT-0827a1b8 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4920 process_sdp: Peer T.38 UDPTL is at port 83.245.6.84:20494 [Dec 1 16:51:52] Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:5127 process_sdp: UDP EC: t38UDPRedundancy [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:5094 process_sdp: FaxMaxDatagram: 72 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:5058 process_sdp: MaxBufferSize:200 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:5119 process_sdp: RateMangement: transferredTCF [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:5113 process_sdp: Transcoding JBIG: 0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:5106 process_sdp: Transcoding MMR: 0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:5100 process_sdp: FillBitRemoval: 0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:5062 process_sdp: T38MaxBitRate: 14400 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:5086 process_sdp: FaxVersion: 0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:5147 process_sdp: Our T38 capability = (3840), peer T38 capability (16160), joint T38 capability (3872) [Dec 1 16:51:52] Capabilities: us - 0x3f1fff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|jpeg|png|h261|h263|h263p|h264), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) [Dec 1 16:51:52] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:5189 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:13462 handle_request_invite: Got a SIP re-invite for call 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:13557 handle_request_invite: SIP/gamma-OUT-0827a1b8: This call is UP.... [Dec 1 16:51:52] <--- Reliably Transmitting (no NAT) to 83.245.6.83:5060 ---> SIP/2.0 488 Not acceptable here Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bK5b70f486c94e6e2f4e65dfb1772138cc;received=83.245.6.83 From: ;tag=3373980758-594199 To: "442074904605" ;tag=as269e358f Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 <------------> [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:1997 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #32 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:13600 handle_request_invite: T38 state changed to 0 on channel SIP/gamma-OUT-0827a1b8 [Dec 1 16:51:52] <--- SIP read from 83.245.6.83:5060 ---> ACK sip:442074904605@89.202.128.200 SIP/2.0 Max-Forwards: 69 From: ;tag=3373980758-594199 To: "442074904605" ;tag=as269e358f Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 CSeq: 2 ACK Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bK5b70f486c94e6e2f4e65dfb1772138cc Content-Length: 0 <-------------> [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 43]: ACK sip:442074904605@89.202.128.200 SIP/2.0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 16]: Max-Forwards: 69 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 58]: From: ;tag=3373980758-594199 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 67]: To: "442074904605" ;tag=as269e358f [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 56]: Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 11]: CSeq: 2 ACK [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 80]: Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bK5b70f486c94e6e2f4e65dfb1772138cc [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 17]: Content-Length: 0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 8 [ 0]: [Dec 1 16:51:52] --- (8 headers 0 lines) --- [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:2096 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #32 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:2107 __sip_ack: Stopping retransmission on '6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200' of Response 2: Match Found [Dec 1 16:51:52] <--- SIP read from 208.51.25.114:5060 ---> OPTIONS sip:89.202.128.200:5060 SIP/2.0 Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goa9i2068v11i0035s0.1 Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 To: sip:ping@89.202.128.200 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f Max-Forwards: 70 CSeq: 17930 OPTIONS <-------------> [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 39]: OPTIONS sip:89.202.128.200:5060 SIP/2.0 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 72]: Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goa9i2068v11i0035s0.1 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 55]: Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 27]: To: sip:ping@89.202.128.200 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 65]: From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 16]: Max-Forwards: 70 [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 19]: CSeq: 17930 OPTIONS [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 0]: [Dec 1 16:51:52] --- (7 headers 0 lines) --- [Dec 1 16:51:52] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Dec 1 16:51:52] Looking for s in default (domain 89.202.128.200) [Dec 1 16:51:52] <--- Transmitting (no NAT) to 208.51.25.114:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goa9i2068v11i0035s0.1;received=208.51.25.114 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f To: sip:ping@89.202.128.200;tag=as665950ab Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 CSeq: 17930 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <------------> [Dec 1 16:51:52] Scheduling destruction of SIP dialog '6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114' in 32000 ms (Method: OPTIONS) [Dec 1 16:51:57] <--- SIP read from 208.51.25.114:5060 ---> OPTIONS sip:89.202.128.200:5060 SIP/2.0 Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goapk207030rhgvr7s1.1 Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 To: sip:ping@89.202.128.200 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f Max-Forwards: 70 CSeq: 17931 OPTIONS <-------------> [Dec 1 16:51:57] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 39]: OPTIONS sip:89.202.128.200:5060 SIP/2.0 [Dec 1 16:51:57] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 72]: Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goapk207030rhgvr7s1.1 [Dec 1 16:51:57] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 55]: Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 [Dec 1 16:51:57] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 27]: To: sip:ping@89.202.128.200 [Dec 1 16:51:58] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 65]: From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f [Dec 1 16:51:58] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 16]: Max-Forwards: 70 [Dec 1 16:51:58] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 19]: CSeq: 17931 OPTIONS [Dec 1 16:51:58] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 0]: [Dec 1 16:51:58] --- (7 headers 0 lines) --- [Dec 1 16:51:58] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Dec 1 16:51:58] Looking for s in default (domain 89.202.128.200) [Dec 1 16:51:58] <--- Transmitting (no NAT) to 208.51.25.114:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goapk207030rhgvr7s1.1;received=208.51.25.114 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f To: sip:ping@89.202.128.200;tag=as665950ab Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 CSeq: 17931 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <------------> [Dec 1 16:51:58] Scheduling destruction of SIP dialog '6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114' in 32000 ms (Method: OPTIONS) [Dec 1 16:51:58] DEBUG[26503]: rtp.c:858 ast_rtcp_read: Got RTCP report of 132 bytes [Dec 1 16:52:02] <--- SIP read from 208.51.25.114:5060 ---> OPTIONS sip:89.202.128.200:5060 SIP/2.0 Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goa9n20702gshssj3g0.1 Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 To: sip:ping@89.202.128.200 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f Max-Forwards: 70 CSeq: 17932 OPTIONS <-------------> [Dec 1 16:52:02] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 39]: OPTIONS sip:89.202.128.200:5060 SIP/2.0 [Dec 1 16:52:02] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 72]: Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goa9n20702gshssj3g0.1 [Dec 1 16:52:02] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 55]: Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 [Dec 1 16:52:02] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 27]: To: sip:ping@89.202.128.200 [Dec 1 16:52:02] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 65]: From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f [Dec 1 16:52:02] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 16]: Max-Forwards: 70 [Dec 1 16:52:02] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 19]: CSeq: 17932 OPTIONS [Dec 1 16:52:02] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 0]: [Dec 1 16:52:02] --- (7 headers 0 lines) --- [Dec 1 16:52:02] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Dec 1 16:52:02] Looking for s in default (domain 89.202.128.200) [Dec 1 16:52:02] <--- Transmitting (no NAT) to 208.51.25.114:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goa9n20702gshssj3g0.1;received=208.51.25.114 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f To: sip:ping@89.202.128.200;tag=as665950ab Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 CSeq: 17932 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <------------> [Dec 1 16:52:02] Scheduling destruction of SIP dialog '6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114' in 32000 ms (Method: OPTIONS) [Dec 1 16:52:05] DEBUG[26503]: rtp.c:858 ast_rtcp_read: Got RTCP report of 108 bytes [Dec 1 16:52:07] <--- SIP read from 208.51.25.114:5060 ---> OPTIONS sip:89.202.128.200:5060 SIP/2.0 Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goapp20702gshcih3o1.1 Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 To: sip:ping@89.202.128.200 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f Max-Forwards: 70 CSeq: 17933 OPTIONS <-------------> [Dec 1 16:52:07] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 39]: OPTIONS sip:89.202.128.200:5060 SIP/2.0 [Dec 1 16:52:07] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 72]: Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goapp20702gshcih3o1.1 [Dec 1 16:52:07] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 55]: Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 [Dec 1 16:52:07] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 27]: To: sip:ping@89.202.128.200 [Dec 1 16:52:07] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 65]: From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f [Dec 1 16:52:07] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 16]: Max-Forwards: 70 [Dec 1 16:52:07] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 19]: CSeq: 17933 OPTIONS [Dec 1 16:52:07] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 0]: [Dec 1 16:52:07] --- (7 headers 0 lines) --- [Dec 1 16:52:07] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Dec 1 16:52:07] Looking for s in default (domain 89.202.128.200) [Dec 1 16:52:07] <--- Transmitting (no NAT) to 208.51.25.114:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goapp20702gshcih3o1.1;received=208.51.25.114 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f To: sip:ping@89.202.128.200;tag=as665950ab Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 CSeq: 17933 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <------------> [Dec 1 16:52:07] Scheduling destruction of SIP dialog '6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114' in 32000 ms (Method: OPTIONS) [Dec 1 16:52:10] <--- SIP read from 83.245.6.83:5060 ---> BYE sip:448001180118@89.202.128.200 SIP/2.0 Max-Forwards: 11 To: ;tag=as08eef8ec From: ;tag=3373980756-449348 Call-ID: 1596574-3373980756-449309@msw8.mydomain.com CSeq: 2 BYE Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bKe898612fc4f0e711667f2995b26e9476 Contact: sip:442074904605@83.245.6.83:5060 Content-Length: 0 <-------------> [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 43]: BYE sip:448001180118@89.202.128.200 SIP/2.0 [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 16]: Max-Forwards: 11 [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 57]: To: ;tag=as08eef8ec [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 58]: From: ;tag=3373980756-449348 [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 52]: Call-ID: 1596574-3373980756-449309@msw8.mydomain.com [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 11]: CSeq: 2 BYE [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 80]: Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bKe898612fc4f0e711667f2995b26e9476 [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 42]: Contact: sip:442074904605@83.245.6.83:5060 [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 8 [ 17]: Content-Length: 0 [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 9 [ 0]: [Dec 1 16:52:10] --- (9 headers 0 lines) --- [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received BYE (8) - Command in SIP BYE [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:14156 handle_request_bye: Initializing initreq for method BYE - callid 1596574-3373980756-449309@msw8.mydomain.com [Dec 1 16:52:10] Sending to 83.245.6.83 : 5060 (no NAT) [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:14206 handle_request_bye: Received bye, issuing owner hangup .[Dec 1 16:52:10] <--- Transmitting (no NAT) to 83.245.6.83:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 83.245.6.83:5060;branch=z9hG4bKe898612fc4f0e711667f2995b26e9476;received=83.245.6.83 From: ;tag=3373980756-449348 To: ;tag=as08eef8ec Call-ID: 1596574-3373980756-449309@msw8.mydomain.com CSeq: 2 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 1 16:52:10] DEBUG[26503]: channel.c:3693 ast_generic_bridge: Didn't get a frame from channel: SIP/83.245.6.83-082666f8 [Dec 1 16:52:10] DEBUG[26503]: channel.c:4017 ast_channel_bridge: Bridge stops bridging channels SIP/83.245.6.83-082666f8 and Local/442070605610@gamma-0b52,1 [Dec 1 16:52:10] DEBUG[26503]: channel.c:1603 ast_hangup: Hanging up channel 'Local/442070605610@gamma-0b52,1' [Dec 1 16:52:10] DEBUG[26503]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/442070605610@gamma-0b52,1 [Dec 1 16:52:10] DEBUG[26503]: rtp.c:1485 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Dec 1 16:52:10] DEBUG[26503]: app_dial.c:1668 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Dec 1 16:52:10] DEBUG[26505]: channel.c:3693 ast_generic_bridge: Didn't get a frame from channel: Local/442070605610@gamma-0b52,2 [Dec 1 16:52:10] DEBUG[26505]: channel.c:4017 ast_channel_bridge: Bridge stops bridging channels Local/442070605610@gamma-0b52,2 and SIP/gamma-OUT-0827a1b8 [Dec 1 16:52:10] DEBUG[26505]: channel.c:1603 ast_hangup: Hanging up channel 'SIP/gamma-OUT-0827a1b8' [Dec 1 16:52:10] DEBUG[26505]: chan_sip.c:3390 sip_hangup: Hangup call SIP/gamma-OUT-0827a1b8, SIP callid 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200) [Dec 1 16:52:10] DEBUG[26505]: chan_sip.c:3398 sip_hangup: update_call_counter(442070605610) - decrement call limit counter on hangup [Dec 1 16:52:10] DEBUG[26505]: chan_sip.c:3092 update_call_counter: Updating call counter for incoming call [Dec 1 16:52:10] Scheduling destruction of SIP dialog '6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200' in 32000 ms (Method: ACK) [Dec 1 16:52:10] DEBUG[26505]: chan_sip.c:5663 reqprep: Strict routing enforced for session 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:52:10] set_destination: Parsing for address/port to send to [Dec 1 16:52:10] set_destination: set destination to 83.245.6.83, port 5060 [Dec 1 16:52:10] Reliably Transmitting (no NAT) to 83.245.6.83:5060: BYE sip:442070605610@83.245.6.83:5060 SIP/2.0 Via: SIP/2.0/UDP 89.202.128.200:5060;branch=z9hG4bK41244105;rport Max-Forwards: 70 From: "442074904605" ;tag=as269e358f To: ;tag=3373980758-594199 Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 CSeq: 103 BYE User-Agent: Asterisk PBX Remote-Party-ID: "442074904605" ;privacy=off;screen=yes Content-Length: 0 --- [Dec 1 16:52:10] DEBUG[26505]: chan_sip.c:1997 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #38 [Dec 1 16:52:10] DEBUG[26505]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/gamma-OUT-0827a1b8 [Dec 1 16:52:10] DEBUG[26505]: app_dial.c:1668 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Dec 1 16:52:10] DEBUG[26505]: pbx.c:2281 __ast_pbx_run: Spawn extension (gamma,442070605610,4) exited non-zero on 'Local/442070605610@gamma-0b52,2' [Dec 1 16:52:10] == Spawn extension (gamma, 442070605610, 4) exited non-zero on 'Local/442070605610@gamma-0b52,2' [Dec 1 16:52:10] DEBUG[26505]: cdr.c:896 ast_cdr_detach: Dropping CDR ! [Dec 1 16:52:10] DEBUG[26505]: channel.c:1603 ast_hangup: Hanging up channel 'Local/442070605610@gamma-0b52,2' [Dec 1 16:52:10] DEBUG[26505]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/442070605610@gamma-0b52,2 [Dec 1 16:52:10] DEBUG[26428]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 442070605610@gamma [Dec 1 16:52:10] DEBUG[26428]: chan_local.c:145 local_devicestate: Checking if extension 442070605610@gamma exists (devicestate) [Dec 1 16:52:10] DEBUG[26428]: devicestate.c:287 do_state_change: Changing state for Local/442070605610@gamma - state 1 (Not in use) [Dec 1 16:52:10] DEBUG[26428]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - gamma-OUT [Dec 1 16:52:10] DEBUG[26428]: chan_sip.c:15225 sip_devicestate: Checking device state for peer gamma-OUT [Dec 1 16:52:10] DEBUG[26428]: devicestate.c:287 do_state_change: Changing state for SIP/gamma-OUT - state 1 (Not in use) [Dec 1 16:52:10] DEBUG[26428]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 442070605610@gamma [Dec 1 16:52:10] DEBUG[26428]: chan_local.c:145 local_devicestate: Checking if extension 442070605610@gamma exists (devicestate) [Dec 1 16:52:10] DEBUG[26428]: devicestate.c:287 do_state_change: Changing state for Local/442070605610@gamma - state 1 (Not in use) [Dec 1 16:52:10] DEBUG[26517]: app_queue.c:568 changethread: Device 'Local/442070605610@gamma' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 1 16:52:10] DEBUG[26518]: app_queue.c:568 changethread: Device 'SIP/gamma-OUT' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 1 16:52:10] DEBUG[26519]: app_queue.c:568 changethread: Device 'Local/442070605610@gamma' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 1 16:52:10] -- AGI Script agi://127.0.0.1:4574/numbertrans?number_in=448001180118&context=gamma completed, returning 0 [Dec 1 16:52:10] DEBUG[26503]: pbx.c:2302 __ast_pbx_run: Extension 448001180118, priority 1 returned normally even though call was hung up [Dec 1 16:52:10] DEBUG[26503]: cdr.c:896 ast_cdr_detach: Dropping CDR ! [Dec 1 16:52:10] DEBUG[26503]: channel.c:1603 ast_hangup: Hanging up channel 'SIP/83.245.6.83-082666f8' [Dec 1 16:52:10] DEBUG[26503]: chan_sip.c:3390 sip_hangup: Hangup call SIP/83.245.6.83-082666f8, SIP callid 1596574-3373980756-449309@msw8.mydomain.com) [Dec 1 16:52:10] DEBUG[26503]: chan_sip.c:3398 sip_hangup: update_call_counter() - decrement call limit counter on hangup [Dec 1 16:52:10] DEBUG[26503]: chan_sip.c:3092 update_call_counter: Updating call counter for incoming call [Dec 1 16:52:10] DEBUG[26503]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/83.245.6.83-082666f8 [Dec 1 16:52:10] DEBUG[26428]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 83.245.6.83 [Dec 1 16:52:10] DEBUG[26428]: chan_sip.c:15225 sip_devicestate: Checking device state for peer 83.245.6.83 [Dec 1 16:52:10] DEBUG[26428]: devicestate.c:287 do_state_change: Changing state for SIP/83.245.6.83 - state 1 (Not in use) [Dec 1 16:52:10] DEBUG[26520]: app_queue.c:568 changethread: Device 'SIP/83.245.6.83' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 1 16:52:10] <--- SIP read from 83.245.6.83:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 89.202.128.200:5060;branch=z9hG4bK41244105;rport From: "442074904605" ;tag=as269e358f To: ;tag=3373980758-594199 Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 CSeq: 103 BYE Content-Length: 0 <-------------> [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 14]: SIP/2.0 200 OK [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 89.202.128.200:5060;branch=z9hG4bK41244105;rport [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 69]: From: "442074904605" ;tag=as269e358f [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 56]: To: ;tag=3373980758-594199 [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 56]: Call-ID: 6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200 [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 13]: CSeq: 103 BYE [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 17]: Content-Length: 0 [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 0]: [Dec 1 16:52:10] --- (7 headers 0 lines) --- [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:2096 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #38 [Dec 1 16:52:10] DEBUG[26459]: chan_sip.c:2107 __sip_ack: Stopping retransmission on '6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200' of Request 103: Match Found [Dec 1 16:52:10] SIP Response message for INCOMING dialog BYE arrived [Dec 1 16:52:10] Really destroying SIP dialog '6ba591bd42f120f25f97c37b4cd5528c@89.202.128.200' Method: ACK [Dec 1 16:52:10] Really destroying SIP dialog '1596574-3373980756-449309@msw8.mydomain.com' Method: BYE [Dec 1 16:52:12] <--- SIP read from 208.51.25.114:5060 ---> OPTIONS sip:89.202.128.200:5060 SIP/2.0 Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goa9s20702gshsk43o0.1 Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 To: sip:ping@89.202.128.200 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f Max-Forwards: 70 CSeq: 17934 OPTIONS <-------------> [Dec 1 16:52:12] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 39]: OPTIONS sip:89.202.128.200:5060 SIP/2.0 [Dec 1 16:52:12] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 72]: Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goa9s20702gshsk43o0.1 [Dec 1 16:52:12] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 55]: Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 [Dec 1 16:52:12] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 27]: To: sip:ping@89.202.128.200 [Dec 1 16:52:12] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 65]: From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f [Dec 1 16:52:12] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 16]: Max-Forwards: 70 [Dec 1 16:52:12] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 19]: CSeq: 17934 OPTIONS [Dec 1 16:52:12] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 0]: [Dec 1 16:52:12] --- (7 headers 0 lines) --- [Dec 1 16:52:12] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Dec 1 16:52:12] Looking for s in default (domain 89.202.128.200) [Dec 1 16:52:12] <--- Transmitting (no NAT) to 208.51.25.114:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goa9s20702gshsk43o0.1;received=208.51.25.114 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f To: sip:ping@89.202.128.200;tag=as665950ab Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 CSeq: 17934 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <------------> [Dec 1 16:52:12] Scheduling destruction of SIP dialog '6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114' in 32000 ms (Method: OPTIONS) [Dec 1 16:52:17] <--- SIP read from 208.51.25.114:5060 ---> OPTIONS sip:89.202.128.200:5060 SIP/2.0 Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goapu20702gsh8ve0s1.1 Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 To: sip:ping@89.202.128.200 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f Max-Forwards: 70 CSeq: 17935 OPTIONS <-------------> [Dec 1 16:52:17] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 39]: OPTIONS sip:89.202.128.200:5060 SIP/2.0 [Dec 1 16:52:17] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 72]: Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goapu20702gsh8ve0s1.1 [Dec 1 16:52:17] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 55]: Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 [Dec 1 16:52:17] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 27]: To: sip:ping@89.202.128.200 [Dec 1 16:52:17] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 65]: From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f [Dec 1 16:52:17] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 16]: Max-Forwards: 70 [Dec 1 16:52:17] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 19]: CSeq: 17935 OPTIONS [Dec 1 16:52:17] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 0]: [Dec 1 16:52:17] --- (7 headers 0 lines) --- [Dec 1 16:52:17] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Dec 1 16:52:17] Looking for s in default (domain 89.202.128.200) [Dec 1 16:52:17] <--- Transmitting (no NAT) to 208.51.25.114:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goapu20702gsh8ve0s1.1;received=208.51.25.114 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f To: sip:ping@89.202.128.200;tag=as665950ab Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 CSeq: 17935 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <------------> [Dec 1 16:52:17] Scheduling destruction of SIP dialog '6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114' in 32000 ms (Method: OPTIONS) [Dec 1 16:52:22] <--- SIP read from 208.51.25.114:5060 ---> OPTIONS sip:89.202.128.200:5060 SIP/2.0 Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goa9130702gshchj200.1 Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 To: sip:ping@89.202.128.200 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f Max-Forwards: 70 CSeq: 17936 OPTIONS <-------------> [Dec 1 16:52:22] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 39]: OPTIONS sip:89.202.128.200:5060 SIP/2.0 [Dec 1 16:52:22] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 72]: Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goa9130702gshchj200.1 [Dec 1 16:52:22] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 55]: Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 [Dec 1 16:52:22] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 27]: To: sip:ping@89.202.128.200 [Dec 1 16:52:22] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 65]: From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f [Dec 1 16:52:22] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 16]: Max-Forwards: 70 [Dec 1 16:52:22] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 19]: CSeq: 17936 OPTIONS [Dec 1 16:52:22] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 0]: [Dec 1 16:52:22] --- (7 headers 0 lines) --- [Dec 1 16:52:22] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Dec 1 16:52:22] Looking for s in default (domain 89.202.128.200) [Dec 1 16:52:22] <--- Transmitting (no NAT) to 208.51.25.114:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goa9130702gshchj200.1;received=208.51.25.114 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f To: sip:ping@89.202.128.200;tag=as665950ab Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 CSeq: 17936 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <------------> [Dec 1 16:52:22] Scheduling destruction of SIP dialog '6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114' in 32000 ms (Method: OPTIONS) [Dec 1 16:52:27] <--- SIP read from 208.51.25.114:5060 ---> OPTIONS sip:89.202.128.200:5060 SIP/2.0 Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goap330702gshgum1g0.1 Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 To: sip:ping@89.202.128.200 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f Max-Forwards: 70 CSeq: 17937 OPTIONS <-------------> [Dec 1 16:52:27] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 0 [ 39]: OPTIONS sip:89.202.128.200:5060 SIP/2.0 [Dec 1 16:52:27] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 1 [ 72]: Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goap330702gshgum1g0.1 [Dec 1 16:52:27] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 2 [ 55]: Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 [Dec 1 16:52:27] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 3 [ 27]: To: sip:ping@89.202.128.200 [Dec 1 16:52:27] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 4 [ 65]: From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f [Dec 1 16:52:27] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 5 [ 16]: Max-Forwards: 70 [Dec 1 16:52:27] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 6 [ 19]: CSeq: 17937 OPTIONS [Dec 1 16:52:27] DEBUG[26459]: chan_sip.c:4637 parse_request: Header 7 [ 0]: [Dec 1 16:52:27] --- (7 headers 0 lines) --- [Dec 1 16:52:27] DEBUG[26459]: chan_sip.c:14627 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Dec 1 16:52:27] Looking for s in default (domain 89.202.128.200) [Dec 1 16:52:27] <--- Transmitting (no NAT) to 208.51.25.114:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.51.25.114:5060;branch=z9hG4bK0goap330702gshgum1g0.1;received=208.51.25.114 From: sip:ping@208.51.25.114;tag=108352804eb67c3de2e195c22418591f To: sip:ping@89.202.128.200;tag=as665950ab Call-ID: 6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114 CSeq: 17937 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <------------> [Dec 1 16:52:27] Scheduling destruction of SIP dialog '6e8f7eb39ab9b7d471747d5dd4a76662@208.51.25.114' in 32000 ms (Method: OPTIONS)