Jun 29 15:06:57 VERBOSE[2849] logger.c: <-- SIP read from 212.248.181.59:5060: INVITE sip:07870699479@212.248.181.59 SIP/2.0 Record-Route: Via: SIP/2.0/UDP 212.248.181.59;branch=z9hG4bKb1e4.1799cc37.0 Via: SIP/2.0/UDP 62.3.241.21:38126;branch=z9hG4bK29978af7;rport=5060 From: "Alistair Cunningham" ;tag=as77c811bb To: Contact: Call-ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 CSeq: 103 INVITE User-Agent: Integrics Enswitch Max-Forwards: 16 Date: Thu, 29 Jun 2006 14:25:28 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 255 v=0 o=root 6905 6906 IN IP4 172.31.0.2 s=session c=IN IP4 62.3.241.21 t=0 0 m=audio 16604 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=direction:active Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 0: INVITE sip:07870699479@212.248.181.59 SIP/2.0 (45) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 1: Record-Route: (56) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 2: Via: SIP/2.0/UDP 212.248.181.59;branch=z9hG4bKb1e4.1799cc37.0 (61) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 3: Via: SIP/2.0/UDP 62.3.241.21:38126;branch=z9hG4bK29978af7;rport=5060 (68) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 4: From: "Alistair Cunningham" ;tag=as77c811bb (68) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 5: To: (36) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 6: Contact: (36) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 7: Call-ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 (56) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 8: CSeq: 103 INVITE (16) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 9: User-Agent: Integrics Enswitch (30) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 10: Max-Forwards: 16 (16) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 11: Date: Thu, 29 Jun 2006 14:25:28 GMT (35) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 12: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 13: Content-Type: application/sdp (29) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 14: Content-Length: 255 (19) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 15: (0) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: v=0 (3) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: o=root 6905 6906 IN IP4 172.31.0.2 (34) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: s=session (9) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: c=IN IP4 62.3.241.21 (20) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: t=0 0 (5) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: m=audio 16604 RTP/AVP 0 8 101 (29) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=direction:active (18) Jun 29 15:06:57 VERBOSE[2849] logger.c: --- (15 headers 12 lines)Jun 29 15:06:57 VERBOSE[2849] logger.c: --- (15 headers 12 lines)--- Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Allocating new SIP dialog for 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 - INVITE (With RTP) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jun 29 15:06:57 VERBOSE[2849] logger.c: Using INVITE request as basis request - 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 Jun 29 15:06:57 VERBOSE[2849] logger.c: Sending to 212.248.181.59 : 5060 (NAT) Jun 29 15:06:57 VERBOSE[2849] logger.c: Found peer 'local-ser' Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Setting NAT on RTP to 524288 Jun 29 15:06:57 VERBOSE[2849] logger.c: Found RTP audio format 0 Jun 29 15:06:57 VERBOSE[2849] logger.c: Found RTP audio format 8 Jun 29 15:06:57 VERBOSE[2849] logger.c: Found RTP audio format 101 Jun 29 15:06:57 VERBOSE[2849] logger.c: Peer audio RTP is at port 62.3.241.21:16604 Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Peer audio RTP is at port 62.3.241.21:16604 Jun 29 15:06:57 VERBOSE[2849] logger.c: Found description format PCMU Jun 29 15:06:57 VERBOSE[2849] logger.c: Found description format PCMA Jun 29 15:06:57 VERBOSE[2849] logger.c: Found description format telephone-event Jun 29 15:06:57 VERBOSE[2849] logger.c: Capabilities: us - 0x1f07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|png|h261|h263|h263p), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) Jun 29 15:06:57 VERBOSE[2849] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Checking SIP call limits for device Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Updating call counter for incoming call Jun 29 15:06:57 VERBOSE[2849] logger.c: Looking for 07870699479 in from-internal (domain 212.248.181.59) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: build_route: Record-Route hop: Jun 29 15:06:57 VERBOSE[2849] logger.c: list_route: hop: Jun 29 15:06:57 VERBOSE[2849] logger.c: Transmitting (NAT) to 212.248.181.59:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 212.248.181.59;branch=z9hG4bKb1e4.1799cc37.0;received=212.248.181.59 Via: SIP/2.0/UDP 62.3.241.21:38126;branch=z9hG4bK29978af7;rport=5060 From: "Alistair Cunningham" ;tag=as77c811bb To: Call-ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 CSeq: 103 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jun 29 15:06:57 DEBUG[10396] pbx.c: Launching 'AGI' Jun 29 15:06:57 VERBOSE[10396] logger.c: -- Executing AGI("SIP/212.248.181.59-0864bfc0", "agi://127.0.0.1/start?stype=phone&snumber=4968&ctype=external&cnumber=07870699479&scustomer=") in new stack Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_network_script: start?stype=phone&snumber=4968&ctype=external&cnumber=07870699479&scustomer= Jun 29 15:06:57 DEBUG[10396] res_agi.c: Wow, connected! Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_request: agi://127.0.0.1/start?stype=phone&snumber=4968&ctype=external&cnumber=07870699479&scustomer= Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_channel: SIP/212.248.181.59-0864bfc0 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_language: en Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_type: SIP Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_uniqueid: 1151590017.1767 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_callerid: 4968 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_calleridname: Alistair Cunningham Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_callingpres: 0 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_callingani2: 0 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_callington: 0 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_callingtns: 0 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_dnid: 07870699479 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_rdnis: unknown Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_context: from-internal Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_extension: 07870699479 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_priority: 1 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_enhanced: 0.0 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> agi_accountcode: Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> Jun 29 15:06:57 DEBUG[2835] chan_sip.c: Checking device state for peer 212.248.181.59 Jun 29 15:06:57 DEBUG[2835] devicestate.c: Changing state for SIP/212.248.181.59 - state 2 (In use) Jun 29 15:06:57 DEBUG[10397] app_queue.c: Device 'SIP/212.248.181.59' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << GET VARIABLE SIP_HEADER(X-Enswitch-External) Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=0 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << SET VARIABLE __DYNAMIC_FEATURES "park_caller#park_called" Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=1 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << SET VARIABLE TIMEOUT(absolute) 86400 Jun 29 15:06:57 VERBOSE[10396] logger.c: -- Channel will hangup at 2006-06-30 14:06:57 UTC. Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=1 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << VERBOSE "Resolving type 'external', number '07870699479'." 5 Jun 29 15:06:57 VERBOSE[10396] logger.c: agi://127.0.0.1/start?stype=phone&snumber=4968&ctype=external&cnumber=07870699479&scustomer=: Resolving type 'external', number '07870699479'. Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=1 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << SET CONTEXT nta Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=0 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << VERBOSE "Customer 2 has 86400 outbound seconds available." 9 Jun 29 15:06:57 VERBOSE[10396] logger.c: agi://127.0.0.1/start?stype=phone&snumber=4968&ctype=external&cnumber=07870699479&scustomer=: Customer 2 has 86400 outbound seconds available. Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=1 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << SET VARIABLE CALLERID(number) "" Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=1 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << EXEC SetCallerPres prohib Jun 29 15:06:57 VERBOSE[10396] logger.c: -- AGI Script Executing Application: (SetCallerPres) Options: (prohib) Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=0 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << SET EXTENSION 07870699479 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=0 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << SET PRIORITY 1 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=0 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << SET VARIABLE ENSWITCH-DCUSTOMER "2" Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=1 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << SET VARIABLE ENSWITCH-DTYPE "external" Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=1 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << SET VARIABLE ENSWITCH-DNUMBER "07870699479" Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=1 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << SET VARIABLE ENSWITCH-CUTOFF "L(86400000:60000:30000)" Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=1 Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Rx << SET VARIABLE TIMEOUT(absolute) "86401" Jun 29 15:06:57 VERBOSE[10396] logger.c: -- Channel will hangup at 2006-06-30 14:06:58 UTC. Jun 29 15:06:57 VERBOSE[10396] logger.c: AGI Tx >> 200 result=1 Jun 29 15:06:57 VERBOSE[10396] logger.c: -- AGI Script agi://127.0.0.1/start?stype=phone&snumber=4968&ctype=external&cnumber=07870699479&scustomer= completed, returning 0 Jun 29 15:06:57 DEBUG[10396] pbx.c: Launching 'Set' Jun 29 15:06:57 VERBOSE[10396] logger.c: -- Executing Set("SIP/212.248.181.59-0864bfc0", "CALLERID(number)=23452345") in new stack Jun 29 15:06:57 DEBUG[10396] pbx.c: Launching 'Dial' Jun 29 15:06:57 VERBOSE[10396] logger.c: -- Executing Dial("SIP/212.248.181.59-0864bfc0", "SIP/07870699479@nta||L(86400000:60000:30000)") in new stack Jun 29 15:06:57 VERBOSE[10396] logger.c: -- Limit Data for this call: Jun 29 15:06:57 VERBOSE[10396] logger.c: -- - timelimit = 86400000 Jun 29 15:06:57 VERBOSE[10396] logger.c: -- - play_warning = 60000 Jun 29 15:06:57 VERBOSE[10396] logger.c: -- - play_to_caller= yes Jun 29 15:06:57 VERBOSE[10396] logger.c: -- - play_to_callee= no Jun 29 15:06:57 VERBOSE[10396] logger.c: -- - warning_freq = 30000 Jun 29 15:06:57 VERBOSE[10396] logger.c: -- - start_sound = UNDEF Jun 29 15:06:57 VERBOSE[10396] logger.c: -- - warning_sound = timeleft Jun 29 15:06:57 VERBOSE[10396] logger.c: -- - end_sound = UNDEF Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Setting NAT on RTP to 0 Jun 29 15:06:57 DEBUG[10396] channel.c: Not copying variable STACK-nta-07870699479-2. Jun 29 15:06:57 DEBUG[10396] channel.c: Not copying variable STACK-nta-07870699479-1. Jun 29 15:06:57 DEBUG[10396] channel.c: Not copying variable ENSWITCH-CUTOFF. Jun 29 15:06:57 DEBUG[10396] channel.c: Not copying variable ENSWITCH-DNUMBER. Jun 29 15:06:57 DEBUG[10396] channel.c: Not copying variable ENSWITCH-DTYPE. Jun 29 15:06:57 DEBUG[10396] channel.c: Not copying variable ENSWITCH-DCUSTOMER. Jun 29 15:06:57 DEBUG[10396] channel.c: Copying hard-transferable variable DYNAMIC_FEATURES. Jun 29 15:06:57 DEBUG[10396] channel.c: Not copying variable STACK-from-internal-07870699479-1. Jun 29 15:06:57 DEBUG[10396] channel.c: Not copying variable SIPCALLID. Jun 29 15:06:57 DEBUG[10396] channel.c: Not copying variable SIPUSERAGENT. Jun 29 15:06:57 DEBUG[10396] channel.c: Not copying variable SIPDOMAIN. Jun 29 15:06:57 DEBUG[10396] channel.c: Not copying variable SIPURI. Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Outgoing Call for 07870699479 Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Updating call counter for outgoing call Jun 29 15:06:57 VERBOSE[10396] logger.c: We're at 212.248.181.59 port 11050 Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x4 (ulaw) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x1 (g723) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x2 (gsm) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x8 (alaw) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x10 (g726) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x20 (adpcm) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x40 (slin) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x80 (lpc10) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x100 (g729) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x200 (speex) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x400 (ilbc) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 0: INVITE sip:07870699479@212.187.189.12 SIP/2.0 (45) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 1: Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK43cf4f18;rport (65) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 2: From: "Unknown" ;tag=as23241974 (60) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 3: To: (36) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 4: Contact: (43) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 5: Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 (56) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 7: User-Agent: Asterisk (20) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 9: Date: Thu, 29 Jun 2006 14:06:57 GMT (35) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 11: Content-Type: application/sdp (29) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 12: Content-Length: 494 (19) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Header 13: (0) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: v=0 (3) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: o=root 2812 2812 IN IP4 212.248.181.59 (38) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: s=session (9) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: c=IN IP4 212.248.181.59 (23) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: t=0 0 (5) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: m=audio 11050 RTP/AVP 0 4 3 8 111 5 10 7 18 110 97 101 (54) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=rtpmap:4 G723/8000 (20) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=rtpmap:111 G726-32/8000 (25) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=rtpmap:5 DVI4/8000 (20) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=rtpmap:10 L16/8000 (20) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=rtpmap:7 LPC/8000 (19) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=rtpmap:110 speex/8000 (23) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=rtpmap:97 iLBC/8000 (21) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Jun 29 15:06:57 VERBOSE[10396] logger.c: 13 headers, 21 lines Jun 29 15:06:57 VERBOSE[10396] logger.c: Reliably Transmitting (no NAT) to 212.187.189.12:5060: INVITE sip:07870699479@212.187.189.12 SIP/2.0 Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK43cf4f18;rport From: "Unknown" ;tag=as23241974 To: Contact: Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 CSeq: 102 INVITE User-Agent: Asterisk Max-Forwards: 70 Date: Thu, 29 Jun 2006 14:06:57 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 494 v=0 o=root 2812 2812 IN IP4 212.248.181.59 s=session c=IN IP4 212.248.181.59 t=0 0 m=audio 11050 RTP/AVP 0 4 3 8 111 5 10 7 18 110 97 101 a=rtpmap:0 PCMU/8000 a=rtpmap:4 G723/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:10 L16/8000 a=rtpmap:7 LPC/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:110 speex/8000 a=rtpmap:97 iLBC/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jun 29 15:06:57 DEBUG[10396] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #120104 Jun 29 15:06:57 VERBOSE[10396] logger.c: -- Called 07870699479@nta Jun 29 15:06:57 DEBUG[10396] channel.c: Set channel SIP/nta-eb7d to read format ulaw Jun 29 15:06:57 DEBUG[10396] channel.c: Set channel SIP/212.248.181.59-0864bfc0 to write format ulaw Jun 29 15:06:57 DEBUG[10396] channel.c: Set channel SIP/212.248.181.59-0864bfc0 to read format ulaw Jun 29 15:06:57 DEBUG[10396] channel.c: Set channel SIP/nta-eb7d to write format ulaw Jun 29 15:06:57 VERBOSE[2849] logger.c: <-- SIP read from 212.187.189.12:5060: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK43cf4f18;rport=5070 From: "Unknown" ;tag=as23241974 To: ;tag=6608bbc84a56ce479a8fbaec695833b9.970d Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 CSeq: 102 INVITE Proxy-Authenticate: Digest realm="212.187.189.12", nonce="44a3e404f89df3781f9f89a9745c5f13da70e15f" Server: Sip EXpress router (0.9.3 (i386/linux)) Content-Length: 0 Warning: 392 212.187.189.12:5060 "Noisy feedback tells: pid=11504 req_src_ip=212.248.181.59 req_src_port=5070 in_uri=sip:07870699479@212.187.189.12 out_uri=sip:07870699479@212.187.189.12 via_cnt==1" Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 0: SIP/2.0 407 Proxy Authentication Required (41) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 1: Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK43cf4f18;rport=5070 (70) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 2: From: "Unknown" ;tag=as23241974 (60) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 3: To: ;tag=6608bbc84a56ce479a8fbaec695833b9.970d (78) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 4: Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 (56) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 6: Proxy-Authenticate: Digest realm="212.187.189.12", nonce="44a3e404f89df3781f9f89a9745c5f13da70e15f" (99) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 7: Server: Sip EXpress router (0.9.3 (i386/linux)) (47) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 8: Content-Length: 0 (17) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 9: Warning: 392 212.187.189.12:5060 "Noisy feedback tells: pid=11504 req_src_ip=212.248.181.59 req_src_port=5070 in_uri=sip:07870699479@212.187.189.12 out_uri=sip:07870699479@212.187.189.12 via_cnt==1" (199) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 10: (0) Jun 29 15:06:57 VERBOSE[2849] logger.c: --- (10 headers 0 lines)Jun 29 15:06:57 VERBOSE[2849] logger.c: --- (10 headers 0 lines)--- Jun 29 15:06:57 DEBUG[2849] chan_sip.c: = Found Their Call ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 Their Tag Our tag: as23241974 Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Acked pending invite 102 Jun 29 15:06:57 DEBUG[2849] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #120104 Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Stopping retransmission on '2ca3b3a276757c0d511f62d032155805@212.187.189.12' of Request 102: Match Found Jun 29 15:06:57 DEBUG[2849] chan_sip.c: SIP response 407 to standard invite Jun 29 15:06:57 VERBOSE[2849] logger.c: Transmitting (no NAT) to 212.187.189.12:5060: ACK sip:07870699479@212.187.189.12 SIP/2.0 Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK43cf4f18;rport From: "Unknown" ;tag=as23241974 To: ;tag=6608bbc84a56ce479a8fbaec695833b9.970d Contact: Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 CSeq: 102 ACK User-Agent: Asterisk Max-Forwards: 70 Content-Length: 0 --- Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Auth attempt 1 on INVITE Jun 29 15:06:57 VERBOSE[2849] logger.c: We're at 212.248.181.59 port 11050 Jun 29 15:06:57 VERBOSE[2849] logger.c: Adding codec 0x4 (ulaw) to SDP Jun 29 15:06:57 VERBOSE[2849] logger.c: Adding codec 0x1 (g723) to SDP Jun 29 15:06:57 VERBOSE[2849] logger.c: Adding codec 0x2 (gsm) to SDP Jun 29 15:06:57 VERBOSE[2849] logger.c: Adding codec 0x8 (alaw) to SDP Jun 29 15:06:57 VERBOSE[2849] logger.c: Adding codec 0x10 (g726) to SDP Jun 29 15:06:57 VERBOSE[2849] logger.c: Adding codec 0x20 (adpcm) to SDP Jun 29 15:06:57 VERBOSE[2849] logger.c: Adding codec 0x40 (slin) to SDP Jun 29 15:06:57 VERBOSE[2849] logger.c: Adding codec 0x80 (lpc10) to SDP Jun 29 15:06:57 VERBOSE[2849] logger.c: Adding codec 0x100 (g729) to SDP Jun 29 15:06:57 VERBOSE[2849] logger.c: Adding codec 0x200 (speex) to SDP Jun 29 15:06:57 VERBOSE[2849] logger.c: Adding codec 0x400 (ilbc) to SDP Jun 29 15:06:57 VERBOSE[2849] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jun 29 15:06:57 VERBOSE[2849] logger.c: Reliably Transmitting (no NAT) to 212.187.189.12:5060: INVITE sip:07870699479@212.187.189.12 SIP/2.0 Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK2bf4a313;rport From: "Unknown" ;tag=as23241974 To: Contact: Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 CSeq: 103 INVITE User-Agent: Asterisk Max-Forwards: 70 Proxy-Authorization: Digest username="23452345", realm="212.187.189.12", algorithm=MD5, uri="sip:07870699479@212.187.189.12", nonce="44a3e404f89df3781f9f81a9745c8f13da70e15f", response="f58817361a815d56f3ad6a58c1ba35c7", opaque="" Date: Thu, 29 Jun 2006 14:06:57 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 494 v=0 o=root 2812 2813 IN IP4 212.248.181.59 s=session c=IN IP4 212.248.181.59 t=0 0 m=audio 11050 RTP/AVP 0 4 3 8 111 5 10 7 18 110 97 101 a=rtpmap:0 PCMU/8000 a=rtpmap:4 G723/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:10 L16/8000 a=rtpmap:7 LPC/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:110 speex/8000 a=rtpmap:97 iLBC/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jun 29 15:06:57 DEBUG[2849] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #120105 Jun 29 15:06:57 VERBOSE[2849] logger.c: <-- SIP read from 212.187.189.12:5060: SIP/2.0 100 trying -- your call is important to us Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK2bf4a313;rport=5070 From: "Unknown" ;tag=as23241974 To: Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 CSeq: 103 INVITE Server: Sip EXpress router (0.9.3 (i386/linux)) Content-Length: 0 Warning: 392 212.187.189.12:5060 "Noisy feedback tells: pid=11505 req_src_ip=212.248.181.59 req_src_port=5070 in_uri=sip:07870699479@212.187.189.12 out_uri=sip:07870699479@212.187.189.12 via_cnt==1" Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 0: SIP/2.0 100 trying -- your call is important to us (50) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 1: Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK2bf4a313;rport=5070 (70) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 2: From: "Unknown" ;tag=as23241974 (60) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 3: To: (36) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 4: Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 (56) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 5: CSeq: 103 INVITE (16) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 6: Server: Sip EXpress router (0.9.3 (i386/linux)) (47) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 7: Content-Length: 0 (17) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 8: Warning: 392 212.187.189.12:5060 "Noisy feedback tells: pid=11505 req_src_ip=212.248.181.59 req_src_port=5070 in_uri=sip:07870699479@212.187.189.12 out_uri=sip:07870699479@212.187.189.12 via_cnt==1" (199) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 9: (0) Jun 29 15:06:57 VERBOSE[2849] logger.c: --- (9 headers 0 lines)Jun 29 15:06:57 VERBOSE[2849] logger.c: --- (9 headers 0 lines)--- Jun 29 15:06:57 DEBUG[2849] chan_sip.c: = Found Their Call ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 Their Tag Our tag: as23241974 Jun 29 15:06:57 DEBUG[2849] chan_sip.c: *** SIP TIMER: Cancelling retransmission #120105 - INVITE (got response) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '2ca3b3a276757c0d511f62d032155805@212.187.189.12' Request 103: Found Jun 29 15:06:57 DEBUG[2849] chan_sip.c: SIP response 100 to standard invite Jun 29 15:06:57 VERBOSE[2849] logger.c: <-- SIP read from 212.187.189.12:5060: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK2bf4a313;rport=5070 From: "Unknown" ;tag=as23241974 To: ;tag=as5474f287 Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 CSeq: 103 INVITE User-Agent: Integrics Enswitch Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 332 v=0 o=root 4985 4985 IN IP4 212.187.189.14 s=session c=IN IP4 212.187.189.14 t=0 0 m=audio 10150 RTP/AVP 18 3 0 8 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=direction:active Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 0: SIP/2.0 183 Session Progress (28) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 1: Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK2bf4a313;rport=5070 (70) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 2: From: "Unknown" ;tag=as23241974 (60) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 3: To: ;tag=as5474f287 (51) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 4: Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 (56) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 5: CSeq: 103 INVITE (16) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 6: User-Agent: Integrics Enswitch (30) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 8: Contact: (46) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 9: Content-Type: application/sdp (29) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 10: Content-Length: 332 (19) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Header 11: (0) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: v=0 (3) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: o=root 4985 4985 IN IP4 212.187.189.14 (38) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: s=session (9) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: c=IN IP4 212.187.189.14 (23) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: t=0 0 (5) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: m=audio 10150 RTP/AVP 18 3 0 8 101 (34) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Line: a=direction:active (18) Jun 29 15:06:57 VERBOSE[2849] logger.c: --- (11 headers 15 lines)Jun 29 15:06:57 VERBOSE[2849] logger.c: --- (11 headers 15 lines)--- Jun 29 15:06:57 DEBUG[2849] chan_sip.c: = Found Their Call ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 Their Tag Our tag: as23241974 Jun 29 15:06:57 DEBUG[2849] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '2ca3b3a276757c0d511f62d032155805@212.187.189.12' Request 103: Found Jun 29 15:06:57 DEBUG[2849] chan_sip.c: SIP response 183 to standard invite Jun 29 15:06:57 VERBOSE[2849] logger.c: Found RTP audio format 18 Jun 29 15:06:57 VERBOSE[2849] logger.c: Found RTP audio format 3 Jun 29 15:06:57 VERBOSE[2849] logger.c: Found RTP audio format 0 Jun 29 15:06:57 VERBOSE[2849] logger.c: Found RTP audio format 8 Jun 29 15:06:57 VERBOSE[2849] logger.c: Found RTP audio format 101 Jun 29 15:06:57 VERBOSE[2849] logger.c: Peer audio RTP is at port 212.187.189.14:10150 Jun 29 15:06:57 DEBUG[2849] chan_sip.c: Peer audio RTP is at port 212.187.189.14:10150 Jun 29 15:06:57 VERBOSE[2849] logger.c: Found description format G729 Jun 29 15:06:57 VERBOSE[2849] logger.c: Found description format GSM Jun 29 15:06:57 VERBOSE[2849] logger.c: Found description format PCMU Jun 29 15:06:57 VERBOSE[2849] logger.c: Found description format PCMA Jun 29 15:06:57 VERBOSE[2849] logger.c: Found description format telephone-event Jun 29 15:06:57 VERBOSE[2849] logger.c: Capabilities: us - 0x1f07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|png|h261|h263|h263p), peer - audio=0x10e (gsm|ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x10e (gsm|ulaw|alaw|g729) Jun 29 15:06:57 VERBOSE[2849] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jun 29 15:06:57 VERBOSE[10396] logger.c: -- SIP/nta-eb7d is making progress passing it to SIP/212.248.181.59-0864bfc0 Jun 29 15:06:57 VERBOSE[10396] logger.c: We're at 212.248.181.59 port 11630 Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x4 (ulaw) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding codec 0x8 (alaw) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jun 29 15:06:57 VERBOSE[10396] logger.c: Transmitting (NAT) to 212.248.181.59:5060: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 212.248.181.59;branch=z9hG4bKb1e4.1799cc37.0;received=212.248.181.59 Via: SIP/2.0/UDP 62.3.241.21:38126;branch=z9hG4bK29978af7;rport=5060 From: "Alistair Cunningham" ;tag=as77c811bb To: ;tag=as56b39e90 Call-ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 CSeq: 103 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 242 v=0 o=root 2812 2812 IN IP4 212.248.181.59 s=session c=IN IP4 212.248.181.59 t=0 0 m=audio 11630 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jun 29 15:06:57 DEBUG[10396] chan_sip.c: Oooh, format changed to 256 Jun 29 15:06:57 DEBUG[10396] channel.c: Set channel SIP/nta-eb7d to read format ulaw Jun 29 15:06:57 DEBUG[10396] channel.c: Set channel SIP/nta-eb7d to write format ulaw Jun 29 15:06:57 DEBUG[10396] rtp.c: Ooh, format changed from unknown to ulaw Jun 29 15:06:58 DEBUG[10396] rtp.c: Ooh, format changed from unknown to g729 Jun 29 15:07:05 VERBOSE[2849] logger.c: <-- SIP read from 212.187.189.12:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK2bf4a313;rport=5070 Record-Route: From: "Unknown" ;tag=as23241974 To: ;tag=as5474f287 Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 CSeq: 103 INVITE User-Agent: Integrics Enswitch Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 332 v=0 o=root 4985 4986 IN IP4 212.187.189.14 s=session c=IN IP4 212.187.189.14 t=0 0 m=audio 10150 RTP/AVP 18 3 0 8 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=direction:active Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 1: Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK2bf4a313;rport=5070 (70) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 2: Record-Route: (56) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 3: From: "Unknown" ;tag=as23241974 (60) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 4: To: ;tag=as5474f287 (51) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 5: Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 (56) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 6: CSeq: 103 INVITE (16) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 7: User-Agent: Integrics Enswitch (30) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 9: Contact: (46) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 10: Content-Type: application/sdp (29) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 11: Content-Length: 332 (19) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 12: (0) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: v=0 (3) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: o=root 4985 4986 IN IP4 212.187.189.14 (38) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: s=session (9) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: c=IN IP4 212.187.189.14 (23) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: t=0 0 (5) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: m=audio 10150 RTP/AVP 18 3 0 8 101 (34) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: a=fmtp:101 0-16 (15) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Line: a=direction:active (18) Jun 29 15:07:05 VERBOSE[2849] logger.c: --- (12 headers 15 lines)Jun 29 15:07:05 VERBOSE[2849] logger.c: --- (12 headers 15 lines)--- Jun 29 15:07:05 DEBUG[2849] chan_sip.c: = Found Their Call ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 Their Tag as5474f287 Our tag: as23241974 Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Acked pending invite 103 Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Stopping retransmission on '2ca3b3a276757c0d511f62d032155805@212.187.189.12' of Request 103: Match Found Jun 29 15:07:05 DEBUG[2849] chan_sip.c: SIP response 200 to standard invite Jun 29 15:07:05 VERBOSE[2849] logger.c: Found RTP audio format 18 Jun 29 15:07:05 VERBOSE[2849] logger.c: Found RTP audio format 3 Jun 29 15:07:05 VERBOSE[2849] logger.c: Found RTP audio format 0 Jun 29 15:07:05 VERBOSE[2849] logger.c: Found RTP audio format 8 Jun 29 15:07:05 VERBOSE[2849] logger.c: Found RTP audio format 101 Jun 29 15:07:05 VERBOSE[2849] logger.c: Peer audio RTP is at port 212.187.189.14:10150 Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Peer audio RTP is at port 212.187.189.14:10150 Jun 29 15:07:05 VERBOSE[2849] logger.c: Found description format G729 Jun 29 15:07:05 VERBOSE[2849] logger.c: Found description format GSM Jun 29 15:07:05 VERBOSE[2849] logger.c: Found description format PCMU Jun 29 15:07:05 VERBOSE[2849] logger.c: Found description format PCMA Jun 29 15:07:05 VERBOSE[2849] logger.c: Found description format telephone-event Jun 29 15:07:05 VERBOSE[2849] logger.c: Capabilities: us - 0x1f07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|png|h261|h263|h263p), peer - audio=0x10e (gsm|ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x10e (gsm|ulaw|alaw|g729) Jun 29 15:07:05 VERBOSE[2849] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: build_route: Record-Route hop: Jun 29 15:07:05 VERBOSE[2849] logger.c: list_route: hop: Jun 29 15:07:05 VERBOSE[2849] logger.c: set_destination: Parsing for address/port to send to Jun 29 15:07:05 VERBOSE[2849] logger.c: set_destination: set destination to 212.187.189.12, port 5060 Jun 29 15:07:05 VERBOSE[2849] logger.c: Transmitting (no NAT) to 212.187.189.12:5060: ACK sip:07870699479@212.187.189.14:5060 SIP/2.0 Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK02ae01a1;rport Route: From: "Unknown" ;tag=as23241974 To: ;tag=as5474f287 Contact: Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 CSeq: 103 ACK User-Agent: Asterisk Max-Forwards: 70 Content-Length: 0 --- Jun 29 15:07:05 VERBOSE[10396] logger.c: -- SIP/nta-eb7d answered SIP/212.248.181.59-0864bfc0 Jun 29 15:07:05 DEBUG[10396] channel.c: Set channel SIP/212.248.181.59-0864bfc0 to read format slin Jun 29 15:07:05 DEBUG[10396] channel.c: Set channel SIP/nta-eb7d to write format slin Jun 29 15:07:05 DEBUG[10396] channel.c: Set channel SIP/nta-eb7d to read format slin Jun 29 15:07:05 DEBUG[10396] channel.c: Set channel SIP/212.248.181.59-0864bfc0 to write format slin Jun 29 15:07:05 DEBUG[10396] chan_sip.c: sip_answer(SIP/212.248.181.59-0864bfc0) Jun 29 15:07:05 VERBOSE[10396] logger.c: We're at 212.248.181.59 port 11630 Jun 29 15:07:05 VERBOSE[10396] logger.c: Adding codec 0x4 (ulaw) to SDP Jun 29 15:07:05 VERBOSE[10396] logger.c: Adding codec 0x8 (alaw) to SDP Jun 29 15:07:05 VERBOSE[10396] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jun 29 15:07:05 VERBOSE[10396] logger.c: Reliably Transmitting (NAT) to 212.248.181.59:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 212.248.181.59;branch=z9hG4bKb1e4.1799cc37.0;received=212.248.181.59 Via: SIP/2.0/UDP 62.3.241.21:38126;branch=z9hG4bK29978af7;rport=5060 Record-Route: From: "Alistair Cunningham" ;tag=as77c811bb To: ;tag=as56b39e90 Call-ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 CSeq: 103 INVITE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 242 v=0 o=root 2812 2813 IN IP4 212.248.181.59 s=session c=IN IP4 212.248.181.59 t=0 0 m=audio 11630 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jun 29 15:07:05 DEBUG[10396] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #120106 Jun 29 15:07:05 DEBUG[2835] chan_sip.c: Checking device state for peer nta Jun 29 15:07:05 DEBUG[2835] devicestate.c: Changing state for SIP/nta - state 2 (In use) Jun 29 15:07:05 DEBUG[10408] app_queue.c: Device 'SIP/nta' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 29 15:07:05 DEBUG[2835] chan_sip.c: Checking device state for peer 212.248.181.59 Jun 29 15:07:05 DEBUG[2835] devicestate.c: Changing state for SIP/212.248.181.59 - state 2 (In use) Jun 29 15:07:05 DEBUG[10409] app_queue.c: Device 'SIP/212.248.181.59' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 29 15:07:05 VERBOSE[2849] logger.c: <-- SIP read from 212.248.181.59:5060: ACK sip:07870699479@212.248.181.59:5070 SIP/2.0 Record-Route: Via: SIP/2.0/UDP 212.248.181.59;branch=0 Via: SIP/2.0/UDP 62.3.241.21:38126;branch=z9hG4bK0fdb8c76;rport=5060 From: "Alistair Cunningham" ;tag=as77c811bb To: ;tag=as56b39e90 Contact: Call-ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 CSeq: 103 ACK User-Agent: Integrics Enswitch Max-Forwards: 16 Content-Length: 0 Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 0: ACK sip:07870699479@212.248.181.59:5070 SIP/2.0 (47) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 1: Record-Route: (56) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 2: Via: SIP/2.0/UDP 212.248.181.59;branch=0 (40) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 3: Via: SIP/2.0/UDP 62.3.241.21:38126;branch=z9hG4bK0fdb8c76;rport=5060 (68) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 4: From: "Alistair Cunningham" ;tag=as77c811bb (68) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 5: To: ;tag=as56b39e90 (51) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 6: Contact: (36) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 7: Call-ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 (56) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 8: CSeq: 103 ACK (13) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 9: User-Agent: Integrics Enswitch (30) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 10: Max-Forwards: 16 (16) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 11: Content-Length: 0 (17) Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Header 12: (0) Jun 29 15:07:05 VERBOSE[2849] logger.c: --- (12 headers 0 lines)Jun 29 15:07:05 VERBOSE[2849] logger.c: --- (12 headers 0 lines)--- Jun 29 15:07:05 DEBUG[2849] chan_sip.c: = No match Their Call ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 Their Tag as5474f287 Our tag: as23241974 Jun 29 15:07:05 DEBUG[2849] chan_sip.c: = Found Their Call ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 Their Tag as77c811bb Our tag: as56b39e90 Jun 29 15:07:05 DEBUG[2849] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jun 29 15:07:05 DEBUG[2849] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #120106 Jun 29 15:07:05 DEBUG[2849] chan_sip.c: Stopping retransmission on '3e943e5d279852c0173c57b0618a97a0@212.248.181.59' of Response 103: Match Found Jun 29 15:07:07 DEBUG[10396] rtp.c: Sending dtmf: 42 (*), at 62.3.241.21 Jun 29 15:07:07 DEBUG[10396] channel.c: Got DTMF on channel (SIP/212.248.181.59-0864bfc0) Jun 29 15:07:07 DEBUG[10396] channel.c: Bridge stops bridging channels SIP/212.248.181.59-0864bfc0 and SIP/nta-eb7d Jun 29 15:07:07 DEBUG[10396] res_features.c: Feature interpret: chan=SIP/212.248.181.59-0864bfc0, peer=SIP/nta-eb7d, sense=1, features=1 Jun 29 15:07:07 DEBUG[10396] res_features.c: Set time limit to 500 Jun 29 15:07:07 DEBUG[10396] rtp.c: Sending dtmf: 42 (*), at 62.3.241.21 Jun 29 15:07:07 DEBUG[10396] channel.c: Got DTMF on channel (SIP/212.248.181.59-0864bfc0) Jun 29 15:07:07 DEBUG[10396] channel.c: Bridge stops bridging channels SIP/212.248.181.59-0864bfc0 and SIP/nta-eb7d Jun 29 15:07:07 DEBUG[10396] res_features.c: Feature interpret: chan=SIP/212.248.181.59-0864bfc0, peer=SIP/nta-eb7d, sense=1, features=0 Jun 29 15:07:07 VERBOSE[10396] logger.c: -- Feature Found: park_caller exten: park_caller Jun 29 15:07:08 VERBOSE[10396] logger.c: == Parked SIP/212.248.181.59-0864bfc0 on 701. Will timeout back to extension [nta] s, 1 in 45 seconds Jun 29 15:07:08 DEBUG[10396] pbx.c: Added extension '701' priority 1 to parkedcalls Jun 29 15:07:08 DEBUG[10396] channel.c: Set channel SIP/212.248.181.59-0864bfc0 to write format gsm Jun 29 15:07:08 DEBUG[10396] rtp.c: Difference is 8288, ms is 1056 Jun 29 15:07:08 DEBUG[10396] channel.c: Scheduling timer at 160 sample intervals Jun 29 15:07:08 VERBOSE[10396] logger.c: -- Playing 'digits/7' (language 'en') Jun 29 15:07:09 DEBUG[10396] channel.c: Scheduling timer at 0 sample intervals Jun 29 15:07:09 DEBUG[10396] channel.c: Scheduling timer at 0 sample intervals Jun 29 15:07:09 DEBUG[10396] channel.c: Set channel SIP/212.248.181.59-0864bfc0 to write format slin Jun 29 15:07:09 DEBUG[10396] channel.c: Set channel SIP/212.248.181.59-0864bfc0 to write format gsm Jun 29 15:07:09 DEBUG[10396] channel.c: Scheduling timer at 160 sample intervals Jun 29 15:07:09 VERBOSE[10396] logger.c: -- Playing 'digits/0' (language 'en') Jun 29 15:07:10 DEBUG[10396] channel.c: Scheduling timer at 0 sample intervals Jun 29 15:07:10 DEBUG[10396] channel.c: Scheduling timer at 0 sample intervals Jun 29 15:07:10 DEBUG[10396] channel.c: Set channel SIP/212.248.181.59-0864bfc0 to write format slin Jun 29 15:07:10 DEBUG[10396] channel.c: Set channel SIP/212.248.181.59-0864bfc0 to write format gsm Jun 29 15:07:10 DEBUG[10396] channel.c: Scheduling timer at 160 sample intervals Jun 29 15:07:10 VERBOSE[10396] logger.c: -- Playing 'digits/1' (language 'en') Jun 29 15:07:10 DEBUG[10396] channel.c: Scheduling timer at 0 sample intervals Jun 29 15:07:10 DEBUG[10396] channel.c: Scheduling timer at 0 sample intervals Jun 29 15:07:10 DEBUG[10396] channel.c: Set channel SIP/212.248.181.59-0864bfc0 to write format slin Jun 29 15:07:10 DEBUG[10396] channel.c: Set channel SIP/212.248.181.59-0864bfc0 to write format slin Jun 29 15:07:10 VERBOSE[10396] logger.c: -- Started music on hold, class 'default', on channel 'SIP/212.248.181.59-0864bfc0' Jun 29 15:07:10 DEBUG[10396] channel.c: Scheduling timer at 160 sample intervals Jun 29 15:07:10 DEBUG[10396] channel.c: Hanging up channel 'SIP/nta-eb7d' Jun 29 15:07:10 DEBUG[10396] chan_sip.c: Hangup call SIP/nta-eb7d, SIP callid 2ca3b3a276757c0d511f62d032155805@212.187.189.12) Jun 29 15:07:10 DEBUG[10396] chan_sip.c: update_call_counter(07870699479) - decrement call limit counter Jun 29 15:07:10 DEBUG[10396] chan_sip.c: Updating call counter for outgoing call Jun 29 15:07:10 VERBOSE[10396] logger.c: set_destination: Parsing for address/port to send to Jun 29 15:07:10 VERBOSE[10396] logger.c: set_destination: set destination to 212.187.189.12, port 5060 Jun 29 15:07:10 VERBOSE[10396] logger.c: Reliably Transmitting (no NAT) to 212.187.189.12:5060: BYE sip:07870699479@212.187.189.14:5060 SIP/2.0 Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK1ba77d4a;rport Route: From: "Unknown" ;tag=as23241974 To: ;tag=as5474f287 Contact: Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 CSeq: 104 BYE User-Agent: Asterisk Max-Forwards: 70 Proxy-Authorization: Digest username="23452345", realm="212.187.189.12", algorithm=MD5, uri="sip:07870699479@212.187.189.14:5060", nonce="44a3e404f29df3781f9f89a9785c5f13da71e15f", response="f58817361a815d56f3ad6a58c1ba35c7", opaque="" Content-Length: 0 --- Jun 29 15:07:10 DEBUG[10396] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #120107 Jun 29 15:07:10 DEBUG[10396] app_dial.c: Exiting with DIALSTATUS=ANSWER. Jun 29 15:07:10 DEBUG[10396] pbx.c: Spawn extension (nta,s,1) exited KEEPALIVE on 'SIP/212.248.181.59-0864bfc0' Jun 29 15:07:10 DEBUG[2835] chan_sip.c: Checking device state for peer nta Jun 29 15:07:10 DEBUG[2835] devicestate.c: Changing state for SIP/nta - state 1 (Not in use) Jun 29 15:07:10 DEBUG[10410] app_queue.c: Device 'SIP/nta' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 29 15:07:10 DEBUG[2840] channel.c: Generator got voice, switching to phase locked mode Jun 29 15:07:10 DEBUG[2840] channel.c: Scheduling timer at 0 sample intervals Jun 29 15:07:11 VERBOSE[2849] logger.c: <-- SIP read from 212.187.189.12:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK1ba77d4a;rport=5070 Record-Route: From: "Unknown" ;tag=as23241974 To: ;tag=as5474f287 Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 CSeq: 104 BYE User-Agent: Integrics Enswitch Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 1: Via: SIP/2.0/UDP 212.248.181.59:5070;branch=z9hG4bK1ba77d4a;rport=5070 (70) Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 2: Record-Route: (56) Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 3: From: "Unknown" ;tag=as23241974 (60) Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 4: To: ;tag=as5474f287 (51) Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 5: Call-ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 (56) Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 6: CSeq: 104 BYE (13) Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 7: User-Agent: Integrics Enswitch (30) Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 9: Contact: (46) Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 10: Content-Length: 0 (17) Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 11: X-Asterisk-HangupCause: Normal Clearing (39) Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Header 12: (0) Jun 29 15:07:11 VERBOSE[2849] logger.c: --- (12 headers 0 lines)Jun 29 15:07:11 VERBOSE[2849] logger.c: --- (12 headers 0 lines)--- Jun 29 15:07:11 DEBUG[2849] chan_sip.c: = Found Their Call ID: 2ca3b3a276757c0d511f62d032155805@212.187.189.12 Their Tag as5474f287 Our tag: as23241974 Jun 29 15:07:11 DEBUG[2849] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #120107 Jun 29 15:07:11 DEBUG[2849] chan_sip.c: Stopping retransmission on '2ca3b3a276757c0d511f62d032155805@212.187.189.12' of Request 104: Match Found Jun 29 15:07:11 VERBOSE[2849] logger.c: Destroying call '2ca3b3a276757c0d511f62d032155805@212.187.189.12' Jun 29 15:07:23 DEBUG[2836] res_musiconhold.c: Only wrote -1 of 640 bytes to pipe Jun 29 15:07:23 DEBUG[2836] res_musiconhold.c: Only wrote -1 of 640 bytes to pipe Jun 29 15:07:24 VERBOSE[2849] logger.c: <-- SIP read from 212.248.181.59:5060: SUBSCRIBE sip:1010@212.248.181.59;user=phone SIP/2.0 Record-Route: Via: SIP/2.0/UDP 212.248.181.59;branch=z9hG4bK275.997c7176.0 Via: SIP/2.0/UDP 212.248.181.36:2051;branch=z9hG4bK-xp8vodc1ej25;rport=2051 From: ;tag=qzwh2r4utq To: Call-ID: 3c990971186a-xyogukqdmmwc@snom320 CSeq: 552 SUBSCRIBE Max-Forwards: 16 Contact: Event: dialog Accept: application/dialog-info+xml Expires: 3600 Content-Length: 0 Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 0: SUBSCRIBE sip:1010@212.248.181.59;user=phone SIP/2.0 (52) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 1: Record-Route: (56) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 2: Via: SIP/2.0/UDP 212.248.181.59;branch=z9hG4bK275.997c7176.0 (60) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 3: Via: SIP/2.0/UDP 212.248.181.36:2051;branch=z9hG4bK-xp8vodc1ej25;rport=2051 (75) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 4: From: ;tag=qzwh2r4utq (46) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 5: To: (40) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 6: Call-ID: 3c990971186a-xyogukqdmmwc@snom320 (42) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 7: CSeq: 552 SUBSCRIBE (19) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 8: Max-Forwards: 16 (16) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 9: Contact: (53) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 10: Event: dialog (13) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 11: Accept: application/dialog-info+xml (35) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 12: Expires: 3600 (13) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 13: Content-Length: 0 (17) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Header 14: (0) Jun 29 15:07:24 VERBOSE[2849] logger.c: --- (14 headers 0 lines)Jun 29 15:07:24 VERBOSE[2849] logger.c: --- (14 headers 0 lines)--- Jun 29 15:07:24 DEBUG[2849] chan_sip.c: = No match Their Call ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 Their Tag as77c811bb Our tag: as56b39e90 Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Allocating new SIP dialog for 3c990971186a-xyogukqdmmwc@snom320 - SUBSCRIBE (No RTP) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE Jun 29 15:07:24 VERBOSE[2849] logger.c: Using latest SUBSCRIBE request as basis request Jun 29 15:07:24 VERBOSE[2849] logger.c: Sending to 212.248.181.59 : 5060 (NAT) Jun 29 15:07:24 VERBOSE[2849] logger.c: Found no matching peer or user for '212.248.181.59:5060' Jun 29 15:07:24 VERBOSE[2849] logger.c: Looking for 1010 in from-external (domain 212.248.181.59) Jun 29 15:07:24 DEBUG[2849] chan_sip.c: Adding subscription for extension 1010 context from-external for peer Jun 29 15:07:24 VERBOSE[2849] logger.c: Scheduling destruction of call '3c990971186a-xyogukqdmmwc@snom320' in 3610000 ms Jun 29 15:07:24 ERROR[2849] chan_sip.c: Got SUBSCRIBE for extensions without hint. Please add hint to 1010 in context from-external Jun 29 15:07:24 VERBOSE[2849] logger.c: Transmitting (NAT) to 212.248.181.59:5060: SIP/2.0 404 Not found Via: SIP/2.0/UDP 212.248.181.59;branch=z9hG4bK275.997c7176.0;received=212.248.181.59 Via: SIP/2.0/UDP 212.248.181.36:2051;branch=z9hG4bK-xp8vodc1ej25;rport=2051 From: ;tag=qzwh2r4utq To: ;tag=as08b42bc0 Call-ID: 3c990971186a-xyogukqdmmwc@snom320 CSeq: 552 SUBSCRIBE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jun 29 15:07:24 VERBOSE[2849] logger.c: Destroying call '3c990971186a-xyogukqdmmwc@snom320' Jun 29 15:07:25 DEBUG[2836] res_musiconhold.c: Only wrote -1 of 640 bytes to pipe Jun 29 15:07:26 DEBUG[2836] res_musiconhold.c: Only wrote -1 of 640 bytes to pipe Jun 29 15:07:27 DEBUG[2836] res_musiconhold.c: Only wrote -1 of 640 bytes to pipe Jun 29 15:07:27 DEBUG[2836] res_musiconhold.c: Only wrote -1 of 640 bytes to pipe Jun 29 15:07:27 VERBOSE[2849] logger.c: <-- SIP read from 212.248.181.59:5060: BYE sip:07870699479@212.248.181.59:5070 SIP/2.0 Record-Route: Via: SIP/2.0/UDP 212.248.181.59;branch=z9hG4bK81e4.c9f1f134.0 Via: SIP/2.0/UDP 62.3.241.21:38126;branch=z9hG4bK0fdf4edd;rport=5060 From: "Alistair Cunningham" ;tag=as77c811bb To: ;tag=as56b39e90 Contact: Call-ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 CSeq: 104 BYE User-Agent: Integrics Enswitch Max-Forwards: 16 Proxy-Authorization: Digest username="4968", realm="212.248.181.59", algorithm=MD5, uri="sip:07870699479@212.248.181.59:5070", nonce="f58817361a815d56f3ad6a58c1ba35c7", response="92d47d5125fce04a325d1dfbbb930f8f", opaque="" Content-Length: 0 Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 0: BYE sip:07870699479@212.248.181.59:5070 SIP/2.0 (47) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 1: Record-Route: (56) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 2: Via: SIP/2.0/UDP 212.248.181.59;branch=z9hG4bK81e4.c9f1f134.0 (61) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 3: Via: SIP/2.0/UDP 62.3.241.21:38126;branch=z9hG4bK0fdf4edd;rport=5060 (68) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 4: From: "Alistair Cunningham" ;tag=as77c811bb (68) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 5: To: ;tag=as56b39e90 (51) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 6: Contact: (36) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 7: Call-ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 (56) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 8: CSeq: 104 BYE (13) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 9: User-Agent: Integrics Enswitch (30) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 10: Max-Forwards: 16 (16) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 11: Proxy-Authorization: Digest username="4968", realm="212.248.181.59", algorithm=MD5, uri="sip:07870699479@212.248.181.59:5070", nonce="44a3dfadc31354c4af59a534992c31c34e2b47f7", response="f58817361a815d56f3ad6a58c1ba35c7", opaque="" (231) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 12: Content-Length: 0 (17) Jun 29 15:07:27 DEBUG[2849] chan_sip.c: Header 13: (0) Jun 29 15:07:27 VERBOSE[2849] logger.c: --- (13 headers 0 lines)Jun 29 15:07:27 VERBOSE[2849] logger.c: --- (13 headers 0 lines)--- Jun 29 15:07:27 DEBUG[2849] chan_sip.c: = Found Their Call ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 Their Tag as77c811bb Our tag: as56b39e90 Jun 29 15:07:27 DEBUG[2849] chan_sip.c: **** Received BYE (8) - Command in SIP BYE Jun 29 15:07:27 VERBOSE[2849] logger.c: Sending to 212.248.181.59 : 5060 (NAT) Jun 29 15:07:27 VERBOSE[2849] logger.c: Transmitting (NAT) to 212.248.181.59:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 212.248.181.59;branch=z9hG4bK81e4.c9f1f134.0;received=212.248.181.59 Via: SIP/2.0/UDP 62.3.241.21:38126;branch=z9hG4bK0fdf4edd;rport=5060 Record-Route: From: "Alistair Cunningham" ;tag=as77c811bb To: ;tag=as56b39e90 Call-ID: 3e943e5d279852c0173c57b0618a97a0@212.248.181.59 CSeq: 104 BYE User-Agent: Asterisk Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- Jun 29 15:07:27 DEBUG[2840] channel.c: Set channel SIP/212.248.181.59-0864bfc0 to write format slin Jun 29 15:07:27 VERBOSE[2840] logger.c: -- Stopped music on hold on SIP/212.248.181.59-0864bfc0 Jun 29 15:07:27 DEBUG[2840] channel.c: Scheduling timer at 0 sample intervals Jun 29 15:07:27 VERBOSE[2840] logger.c: == SIP/212.248.181.59-0864bfc0 got tired of being parked Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is '"Alistair Cunningham" <23452345>' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is '23452345' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is '07870699479' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is 'from-internal' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is 'SIP/212.248.181.59-0864bfc0' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is 'SIP/nta-eb7d' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is 'Park' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is '(null)' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is '2006-06-29 15:06:57' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is '2006-06-29 15:07:05' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is '2006-06-29 15:07:27' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is '30' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is '22' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is 'ANSWERED' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is 'DOCUMENTATION' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is '(null)' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is '1151590017.1767' Jun 29 15:07:27 DEBUG[2840] pbx.c: Function result is '(null)' Jun 29 15:07:27 DEBUG[2840] channel.c: Hanging up channel 'SIP/212.248.181.59-0864bfc0' Jun 29 15:07:27 DEBUG[2840] chan_sip.c: Hangup call SIP/212.248.181.59-0864bfc0, SIP callid 3e943e5d279852c0173c57b0618a97a0@212.248.181.59) Jun 29 15:07:27 DEBUG[2840] chan_sip.c: update_call_counter() - decrement call limit counter Jun 29 15:07:27 DEBUG[2840] chan_sip.c: Updating call counter for incoming call Jun 29 15:07:27 DEBUG[2835] chan_sip.c: Checking device state for peer 212.248.181.59 Jun 29 15:07:27 DEBUG[2835] devicestate.c: Changing state for SIP/212.248.181.59 - state 1 (Not in use) Jun 29 15:07:27 DEBUG[10411] app_queue.c: Device 'SIP/212.248.181.59' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 29 15:07:28 VERBOSE[2849] logger.c: Destroying call '3e943e5d279852c0173c57b0618a97a0@212.248.181.59'