[Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 0 [ 50]: INVITE sip:43780004711@dev-sip.tele500.com SIP/2.0 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 1 [ 49]: Record-Route: [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 2 [ 59]: Via: SIP/2.0/UDP 78.105.1.128;branch=z9hG4bK127f.6e0b2541.0 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 3 [ 68]: Via: SIP/2.0/UDP 78.105.1.131:5061;rport=5061;branch=z9hG4bKpubfxigh [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 4 [ 16]: Max-Forwards: 69 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 5 [ 43]: To: [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 6 [ 55]: From: "10000" ;tag=jtnzd [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 7 [ 37]: Call-ID: ttekxbwhwiqqbfy@78.105.1.131 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 8 [ 16]: CSeq: 444 INVITE [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 9 [ 38]: Contact: [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 10 [ 29]: Content-Type: application/sdp [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 11 [ 78]: Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 12 [ 37]: Supported: replaces,norefersub,100rel [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 13 [ 23]: User-Agent: Twinkle/1.1 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 14 [ 19]: Content-Length: 251 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 15 [ 13]: X-auth: 10000 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Header 16 [ 0]: [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Body 0 [ 3]: v=0 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Body 1 [ 48]: o=10000 981038778 1042688338 IN IP4 78.105.1.131 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Body 2 [ 3]: s=- [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Body 3 [ 21]: c=IN IP4 78.105.1.131 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Body 4 [ 5]: t=0 0 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Body 5 [ 30]: m=audio 8002 RTP/AVP 8 0 3 101 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Body 10 [ 15]: a=fmtp:101 0-15 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Body 11 [ 10]: a=ptime:20 [Dec 10 22:18:37] DEBUG[25370] acl.c: Found IP address for this socket [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Setting NAT on RTP to Off [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Allocating new SIP dialog for ttekxbwhwiqqbfy@78.105.1.131 - INVITE (With RTP) [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Begin: parsing SIP "Supported: replaces,norefersub,100rel" [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Found SIP option: -replaces- [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Matched SIP option: replaces [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Found SIP option: -norefersub- [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Matched SIP option: norefersub [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Found SIP option: -100rel- [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Matched SIP option: 100rel [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Initializing initreq for method INVITE - callid ttekxbwhwiqqbfy@78.105.1.131 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Checking SIP call limits for device [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Updating call counter for incoming call [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: *** Our native formats are 0x8 (alaw) [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: *** Joint capabilities are 0xe (gsm|ulaw|alaw) [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: *** Our capabilities are 0x170f (g723|gsm|ulaw|alaw|g729|speex|ilbc|g722) [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: This channel will not be able to handle video. [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: build_route: Record-Route hop: [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Session timer started: 3 - ttekxbwhwiqqbfy@78.105.1.131 [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: SIP/dev-sip.tele500.com-08209b98: New call is still down.... Trying... [Dec 10 22:18:37] DEBUG[25370] chan_sip.c: Trying to put 'SIP/2.0 10' onto UDP socket destined for 78.105.1.128:5060 [Dec 10 22:18:37] DEBUG[25370] devicestate.c: device 'SIP/dev-sip.tele500.com' state '2' [Dec 10 22:18:37] DEBUG[25359] devicestate.c: Processing device state change for 'SIP/dev-sip.tele500.com' [Dec 10 22:18:37] DEBUG[25359] devicestate.c: Adding per-server state of 'In use' for 'SIP/dev-sip.tele500.com' [Dec 10 22:18:37] DEBUG[25359] devicestate.c: Aggregate devstate result is 2 [Dec 10 22:18:37] DEBUG[25359] devicestate.c: Aggregate state for device 'SIP/dev-sip.tele500.com' has changed to 'In use' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is '10000' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is '(null)' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is 'Twinkle/1.1' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is 'Twinkle/1.1' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is 'ttekxbwhwiqqbfy@78.105.1.131' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is 'ttekxbwhwiqqbfy@78.105.1.131' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is 'alaw' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is 'alaw' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is 'alaw' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is '10000' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is '0' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Expression result is '0' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'GotoIf' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is '10000' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Gosub' [Dec 10 22:18:37] DEBUG[25376] app_stack.c: Channel SIP/dev-sip.tele500.com-08209b98 has no datastore, so we're allocating one. [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'MYSQL' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'MYSQL' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'MYSQL' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'MYSQL' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'MYSQL' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is '43780004711' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is '11' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Expression result is '0' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'GotoIf' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Return' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is '(null)' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is '1' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Expression result is '1' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'GotoIf' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Goto' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Goto' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is '2' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is 'e164.arpa' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Expression result is '1' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'GotoIf' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is '1' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Function result is 'e164.org' [Dec 10 22:18:37] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:37] DEBUG[25376] enum.c: ast_get_enum(): n='43780004711', tech='sip', suffix='e164.arpa', options='2', record='1' [Dec 10 22:18:38] DEBUG[25376] enum.c: NAPTR input='+43780004711', flags='u', services='E2U+email:mailto', regexp='!^.*$!mailto:info@nemox.net!', repl='' [Dec 10 22:18:38] DEBUG[25376] enum.c: NAPTR input='+43780004711', flags='u', services='E2U+sip', regexp='!^.*$!sip:enum-test@sip.nemox.net!', repl='' [Dec 10 22:18:38] DEBUG[25376] enum.c: NAPTR input='+43780004711', flags='u', services='E2U+web:http', regexp='!^.*$!http://q.nemox.net/!', repl='' [Dec 10 22:18:38] DEBUG[25376] pbx.c: Function result is 'enum-test@sip.nemox.net' [Dec 10 22:18:38] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:38] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:38] DEBUG[25376] pbx.c: Expression result is '0' [Dec 10 22:18:38] DEBUG[25376] pbx.c: Launching 'GotoIf' [Dec 10 22:18:38] DEBUG[25376] pbx.c: Expression result is '0' [Dec 10 22:18:38] DEBUG[25376] pbx.c: Launching 'GotoIf' [Dec 10 22:18:38] DEBUG[25376] pbx.c: Launching 'Set' [Dec 10 22:18:38] DEBUG[25376] pbx.c: Launching 'Gosub' [Dec 10 22:18:38] DEBUG[25376] app_stack.c: Setting 'ARG1' to 'enum-test@sip.nemox.net' [Dec 10 22:18:38] DEBUG[25376] pbx.c: Launching 'NoOp' [Dec 10 22:18:38] DEBUG[25376] pbx.c: Launching 'Dial' [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Asked to create a SIP channel with formats: 0x8 (alaw) [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Allocating new SIP dialog for 26f371fe083772673157e20f3633fe72@78.105.1.129 - INVITE (With RTP) [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: OBPROXY: Applying global OBproxy to this call [Dec 10 22:18:38] DEBUG[25376] acl.c: Found IP address for this socket [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: *** Our native formats are 0x8 (alaw) [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: *** Our capabilities are 0x170f (g723|gsm|ulaw|alaw|g729|speex|ilbc|g722) [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: *** Our preferred formats from the incoming channel are 0x8 (alaw) [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: This channel will not be able to handle video. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable DIALEDTIME. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable ANSWEREDTIME. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable DIALEDPEERNAME. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable DIALEDPEERNUMBER. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable DIALSTATUS. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable ARG1. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable ENUM_URI. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable ENUM_SERVERS. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable ENUM_Total. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable ENUM_SERVER. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable GOSUB_RETVAL. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable MYSQL_STATUS. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable fetchid. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-monitor. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-customer_id. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-currency. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-cc. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-balance. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-fm_allowed. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-rec_allowed. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-ext. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-cli. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-partner_id. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-last_name. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-first_name. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable resultid. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable connid. [Dec 10 22:18:38] DEBUG[25376] channel.c: Copying hard-transferable variable X-USER_ID. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable SIPCALLID. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable SIPDOMAIN. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable SIPURI. [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Outgoing Call for enum-test [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Updating call counter for outgoing call [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Our T38 capability (0), joint T38 capability (0) [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: ** Our capability: 0x20e (gsm|ulaw|alaw|speex) Video flag: False Text flag: False [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: -- Done with adding codecs to SDP [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Done building SDP. Settling with this capability: 0x20e (gsm|ulaw|alaw|speex) [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Initializing initreq for method INVITE - callid 00dafd7f6b0239e9599aa6c70ce6eb70@78.105.1.129 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 0 [ 44]: INVITE sip:enum-test@sip.nemox.net:0 SIP/2.0 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 78.105.1.129:5060;branch=z9hG4bK73ed0fab;rport [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 3 [ 65]: From: "John Smith" ;tag=as1cb48e91 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 4 [ 35]: To: [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 5 [ 40]: Contact: [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 6 [ 54]: Call-ID: 00dafd7f6b0239e9599aa6c70ce6eb70@78.105.1.129 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 8 [ 49]: User-Agent: Asterisk PBX SVN-branch-1.6.1-r162896 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 9 [ 35]: Date: Wed, 10 Dec 2008 22:18:38 GMT [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 10 [ 21]: Session-Expires: 1800 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 11 [ 10]: Min-SE: 90 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 12 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 13 [ 26]: Supported: replaces, timer [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 15 [ 19]: Content-Length: 354 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Header 16 [ 0]: [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 0 [ 3]: v=0 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 1 [ 46]: o=root 832518865 832518865 IN IP4 78.105.1.129 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 2 [ 39]: s=Asterisk PBX SVN-branch-1.6.1-r162896 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 3 [ 21]: c=IN IP4 78.105.1.129 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 4 [ 5]: t=0 0 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 5 [ 35]: m=audio 18172 RTP/AVP 8 0 3 110 101 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 9 [ 23]: a=rtpmap:110 speex/8000 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 10 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 11 [ 15]: a=fmtp:101 0-16 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 12 [ 25]: a=silenceSupp:off - - - - [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 13 [ 10]: a=ptime:20 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Body 14 [ 10]: a=sendrecv [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #4 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Trying to put 'INVITE sip' onto UDP socket destined for 0.0.0.0:5060 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 0 [ 44]: INVITE sip:enum-test@sip.nemox.net:0 SIP/2.0 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 78.105.1.129:5060;branch=z9hG4bK73ed0fab;rport [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 3 [ 65]: From: "John Smith" ;tag=as1cb48e91 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 4 [ 35]: To: [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 5 [ 40]: Contact: [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 6 [ 54]: Call-ID: 00dafd7f6b0239e9599aa6c70ce6eb70@78.105.1.129 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 8 [ 49]: User-Agent: Asterisk PBX SVN-branch-1.6.1-r162896 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 9 [ 35]: Date: Wed, 10 Dec 2008 22:18:38 GMT [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 10 [ 21]: Session-Expires: 1800 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 11 [ 10]: Min-SE: 90 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 12 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 13 [ 26]: Supported: replaces, timer [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 15 [ 19]: Content-Length: 354 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 16 [ 0]: [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 0 [ 3]: v=0 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 1 [ 46]: o=root 832518865 832518865 IN IP4 78.105.1.129 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 2 [ 39]: s=Asterisk PBX SVN-branch-1.6.1-r162896 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 3 [ 21]: c=IN IP4 78.105.1.129 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 4 [ 5]: t=0 0 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 5 [ 35]: m=audio 18172 RTP/AVP 8 0 3 110 101 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 9 [ 23]: a=rtpmap:110 speex/8000 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 10 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 11 [ 15]: a=fmtp:101 0-16 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 12 [ 25]: a=silenceSupp:off - - - - [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 13 [ 10]: a=ptime:20 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Body 14 [ 10]: a=sendrecv [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Begin: parsing SIP "Supported: replaces, timer" [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Found SIP option: -replaces- [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Matched SIP option: replaces [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Found SIP option: -timer- [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Matched SIP option: timer [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Trying to put 'SIP/2.0 48' onto UDP socket destined for 0.0.0.0:5060 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 0 [ 25]: SIP/2.0 482 Loop Detected [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/UDP 78.105.1.129:5060;branch=z9hG4bK73ed0fab;received=78.105.1.129;rport=5060 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 2 [ 65]: From: "John Smith" ;tag=as1cb48e91 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 3 [ 50]: To: ;tag=as1cb48e91 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 4 [ 54]: Call-ID: 00dafd7f6b0239e9599aa6c70ce6eb70@78.105.1.129 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 6 [ 45]: Server: Asterisk PBX SVN-branch-1.6.1-r162896 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 10 [ 33]: X-Asterisk-HangupCause: User busy [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 11 [ 30]: X-Asterisk-HangupCauseCode: 17 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 12 [ 0]: [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Acked pending invite 102 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #4 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Stopping retransmission on '00dafd7f6b0239e9599aa6c70ce6eb70@78.105.1.129' of Request 102: Match Found [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Hairpin detected, setting up call forward for what it's worth [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Trying to put 'ACK sip:en' onto UDP socket destined for 0.0.0.0:5060 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Setting SIP_ALREADYGONE on dialog 00dafd7f6b0239e9599aa6c70ce6eb70@78.105.1.129 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 0 [ 41]: ACK sip:enum-test@sip.nemox.net:0 SIP/2.0 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 78.105.1.129:5060;branch=z9hG4bK73ed0fab;rport [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 3 [ 65]: From: "John Smith" ;tag=as1cb48e91 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 4 [ 50]: To: ;tag=as1cb48e91 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 5 [ 40]: Contact: [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 6 [ 54]: Call-ID: 00dafd7f6b0239e9599aa6c70ce6eb70@78.105.1.129 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 7 [ 13]: CSeq: 102 ACK [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 8 [ 49]: User-Agent: Asterisk PBX SVN-branch-1.6.1-r162896 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 10 [ 0]: [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable DIALEDTIME. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable ANSWEREDTIME. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable DIALEDPEERNAME. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable DIALEDPEERNUMBER. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable DIALSTATUS. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable ARG1. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable ENUM_URI. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable ENUM_SERVERS. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable ENUM_Total. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable ENUM_SERVER. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable GOSUB_RETVAL. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable MYSQL_STATUS. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable fetchid. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-monitor. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-customer_id. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-currency. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-cc. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-balance. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-fm_allowed. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-rec_allowed. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-ext. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-cli. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-partner_id. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-last_name. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable X-first_name. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable resultid. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable connid. [Dec 10 22:18:38] DEBUG[25376] channel.c: Copying hard-transferable variable X-USER_ID. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable SIPCALLID. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable SIPDOMAIN. [Dec 10 22:18:38] DEBUG[25376] channel.c: Not copying variable SIPURI. [Dec 10 22:18:38] DEBUG[25376] rtp.c: Channel 'Local/enum-test@common-848f;1' has no RTP, not doing anything [Dec 10 22:18:38] DEBUG[25376] channel.c: Hanging up channel 'SIP/sip.nemox.net-0820d4d0' [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Hangup call SIP/sip.nemox.net-0820d4d0, SIP callid 00dafd7f6b0239e9599aa6c70ce6eb70@78.105.1.129 [Dec 10 22:18:38] DEBUG[25376] devicestate.c: device 'SIP/sip.nemox.net' state '1' [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Processing device state change for 'SIP/sip.nemox.net' [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Adding per-server state of 'Not in use' for 'SIP/sip.nemox.net' [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Aggregate devstate result is 1 [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Aggregate state for device 'SIP/sip.nemox.net' has changed to 'Not in use' [Dec 10 22:18:38] DEBUG[25376] channel.c: Hanging up channel 'Local/enum-test@common-848f;1' [Dec 10 22:18:38] DEBUG[25376] channel.c: Hanging up channel 'Local/enum-test@common-848f;2' [Dec 10 22:18:38] DEBUG[25376] devicestate.c: device 'Local/enum-test@common' state '1' [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Processing device state change for 'Local/enum-test@common' [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Adding per-server state of 'Not in use' for 'Local/enum-test@common' [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Aggregate devstate result is 1 [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Aggregate state for device 'Local/enum-test@common' has changed to 'Not in use' [Dec 10 22:18:38] DEBUG[25376] devicestate.c: device 'Local/enum-test@common' state '1' [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Processing device state change for 'Local/enum-test@common' [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Adding per-server state of 'Not in use' for 'Local/enum-test@common' [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Aggregate devstate result is 1 [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Aggregate state for device 'Local/enum-test@common' has not changed from 'Not in use' [Dec 10 22:18:38] DEBUG[25376] rtp.c: Channel '' has no RTP, not doing anything [Dec 10 22:18:38] DEBUG[25376] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL. [Dec 10 22:18:38] DEBUG[25376] pbx.c: Launching 'Hangup' [Dec 10 22:18:38] DEBUG[25376] pbx.c: Spawn extension (dialSIP,43780004711,3) exited non-zero on 'SIP/dev-sip.tele500.com-08209b98' [Dec 10 22:18:38] DEBUG[25376] channel.c: Soft-Hanging up channel 'SIP/dev-sip.tele500.com-08209b98' [Dec 10 22:18:38] DEBUG[25376] channel.c: Hanging up channel 'SIP/dev-sip.tele500.com-08209b98' [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Hangup call SIP/dev-sip.tele500.com-08209b98, SIP callid ttekxbwhwiqqbfy@78.105.1.131 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Hanging up channel in state Ring (not UP) [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Session timer stopped: -1 - ttekxbwhwiqqbfy@78.105.1.131 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: AST hangup cause 16 (no match found in SIP) [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #8 [Dec 10 22:18:38] DEBUG[25376] chan_sip.c: Trying to put 'SIP/2.0 60' onto UDP socket destined for 78.105.1.128:5060 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 0 [ 47]: ACK sip:43780004711@dev-sip.tele500.com SIP/2.0 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 78.105.1.128;branch=z9hG4bK127f.6e0b2541.0 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 2 [ 55]: From: "10000" ;tag=jtnzd [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 3 [ 37]: Call-ID: ttekxbwhwiqqbfy@78.105.1.131 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 4 [ 58]: To: ;tag=as141d70f2 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 5 [ 13]: CSeq: 444 ACK [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 7 [ 47]: User-Agent: OpenSIPS (1.4.1-notls (i386/linux)) [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Header 9 [ 0]: [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #8 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Stopping retransmission on 'ttekxbwhwiqqbfy@78.105.1.131' of Response 444: Match Found [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: Destroying SIP dialog 00dafd7f6b0239e9599aa6c70ce6eb70@78.105.1.129 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: ---------- SIP HISTORY for '00dafd7f6b0239e9599aa6c70ce6eb70@78.105.1.129' [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: * SIP Call [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: 001. OBproxy Using global obproxy 78.105.1.128 [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: 002. Hangup Cause Interworking, unspecified [Dec 10 22:18:38] DEBUG[25370] chan_sip.c: ---------- END SIP HISTORY for '00dafd7f6b0239e9599aa6c70ce6eb70@78.105.1.129' [Dec 10 22:18:38] DEBUG[25376] devicestate.c: device 'SIP/dev-sip.tele500.com' state '1' [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Processing device state change for 'SIP/dev-sip.tele500.com' [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Adding per-server state of 'Not in use' for 'SIP/dev-sip.tele500.com' [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Aggregate devstate result is 1 [Dec 10 22:18:38] DEBUG[25359] devicestate.c: Aggregate state for device 'SIP/dev-sip.tele500.com' has changed to 'Not in use' [Dec 10 22:19:10] DEBUG[25370] chan_sip.c: Auto destroying SIP dialog 'ttekxbwhwiqqbfy@78.105.1.131' [Dec 10 22:19:10] DEBUG[25370] chan_sip.c: Destroying SIP dialog ttekxbwhwiqqbfy@78.105.1.131 [Dec 10 22:19:10] DEBUG[25370] chan_sip.c: ---------- SIP HISTORY for 'ttekxbwhwiqqbfy@78.105.1.131' [Dec 10 22:19:10] DEBUG[25370] chan_sip.c: * SIP Call [Dec 10 22:19:10] DEBUG[25370] chan_sip.c: 001. Cancel Cause Normal Clearing [Dec 10 22:19:10] DEBUG[25370] chan_sip.c: 002. AutoDestroy ttekxbwhwiqqbfy@78.105.1.131 [Dec 10 22:19:10] DEBUG[25370] chan_sip.c: ---------- END SIP HISTORY for 'ttekxbwhwiqqbfy@78.105.1.131'