=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2008.01.14 10:55:05 =~=~=~=~=~=~=~=~=~=~=~= root root@10.0.0.138's password: Last login: Mon Jan 14 10:47:25 2008 from 192.168.30.190 ]0;root@lab:~[root@lab ~]# asterisk -vvvvvvvvvvvvvvvvvvvvr Asterisk 1.4.17, Copyright (C) 1999 - 2007 Digium, Inc. and others. Created by Mark Spencer Asterisk comes with ABSOLUTELY NO WARRANTY; type 'core show warranty' for details. This is free software, with components licensed under the GNU General Public License version 2 and other licenses; you are welcome to redistribute it under certain conditions. Type 'core show license' for details. ========================================================================= == Parsing '/etc/asterisk/asterisk.conf': Found Connected to Asterisk 1.4.17 currently running on lab (pid = 8834) lab*CLI> Verbosity was 19 and is now 20 lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> Reliably Transmitting (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK561e638e;rport From: "asterisk" ;tag=as281ecdba To: Contact: Call-ID: 474c41774bc026d65c824463643cfad2@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:24 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> Retransmitting #1 (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK561e638e;rport From: "asterisk" ;tag=as281ecdba To: Contact: Call-ID: 474c41774bc026d65c824463643cfad2@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:24 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> INVITE sip:2221@192.168.30.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-q58njmewozkv;rport From: "Reception 6000" ;tag=azns9srzgc To: Call-ID: 3c26704eb838-ckqqjy9ahvbg CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/7.1.30 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 475 v=0 o=root 74452599 74452599 IN IP4 192.168.30.162 s=call c=IN IP4 192.168.30.162 t=0 0 m=audio 16302 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:vEyhyjlTGlhV57V8sRbq2jBOUWj2R1JZ8Sz8Asf3 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv <-------------> --- (18 headers 19 lines) --- [Jan 14 10:55:26] WARNING[8924]: rtp.c:1987 ast_rtp_settos: Unable to set TOS to 184 Sending to 192.168.30.162 : 2084 (NAT) Using INVITE request as basis request - 3c26704eb838-ckqqjy9ahvbg <--- Reliably Transmitting (no NAT) to 192.168.30.162:2084 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-q58njmewozkv;received=192.168.30.162;rport=2084 From: "Reception 6000" ;tag=azns9srzgc To: ;tag=as4fef7451 Call-ID: 3c26704eb838-ckqqjy9ahvbg CSeq: 1 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="fireworx", nonce="755eea96" Content-Length: 0 <------------> Scheduling destruction of SIP dialog '3c26704eb838-ckqqjy9ahvbg' in 32000 ms (Method: INVITE) Found user '6000' lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> ACK sip:2221@192.168.30.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-q58njmewozkv;rport From: "Reception 6000" ;tag=azns9srzgc To: ;tag=as4fef7451 Call-ID: 3c26704eb838-ckqqjy9ahvbg CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 <-------------> --- (9 headers 0 lines) --- lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> INVITE sip:2221@192.168.30.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-3kov4jizthjt;rport From: "Reception 6000" ;tag=azns9srzgc To: Call-ID: 3c26704eb838-ckqqjy9ahvbg CSeq: 2 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/7.1.30 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Proxy-Authorization: Digest username="6000",realm="fireworx",nonce="755eea96",uri="sip:2221@192.168.30.254",response="1f71d68ada51bf4c8ba1d139f994fb87",algorithm=MD5 Content-Type: application/sdp Content-Length: 475 v=0 o=root 74452599 74452599 IN IP4 192.168.30.162 s=call c=IN IP4 192.168.30.162 t=0 0 m=audio 16302 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:vEyhyjlTGlhV57V8sRbq2jBOUWj2R1JZ8Sz8Asf3 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv <-------------> lab*CLI> --- (19 headers 19 lines) --- Sending to 192.168.30.162 : 2084 (NAT) Using INVITE request as basis request - 3c26704eb838-ckqqjy9ahvbg Found user '6000' Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 9 Found RTP audio format 2 Found RTP audio format 3 lab*CLI> Found RTP audio format 18 Found RTP audio format 4 Found RTP audio format 101 Peer audio RTP is at port 192.168.30.162:16302 Found audio description format pcmu for ID 0 Found audio description format pcma for ID 8 Found audio description format g722 for ID 9 Found audio description format g726-32 for ID 2 Found audio description format gsm for ID 3 Found audio description format g729 for ID 18 Found audio description format g723 for ID 4 Found audio description format telephone-event for ID 101 lab*CLI> Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x190f (g723|gsm|ulaw|alaw|g726|g729|g722)/video=0x0 (nothing), combined - 0x104 (ulaw|g729) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 192.168.30.162:16302 [Jan 14 10:55:26] DEBUG[8924]: chan_sip.c:3250 update_call_counter: Call from peer '6000' is 1 out of 4 Looking for 2221 in default-super (domain 192.168.30.254) list_route: hop: lab*CLI> <--- Transmitting (no NAT) to 192.168.30.162:2084 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-3kov4jizthjt;received=192.168.30.162;rport=2084 From: "Reception 6000" ;tag=azns9srzgc To: Call-ID: 3c26704eb838-ckqqjy9ahvbg CSeq: 2 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> Reliably Transmitting (no NAT) to 192.168.30.162:2084: NOTIFY sip:6000@192.168.30.162:2084;line=7m5w9ycs SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK08070bb5;rport From: ;tag=as5624c84b To: ;tag=tjss8drb6l Contact: Call-ID: 3c2670156a44-imyvvf79f9oc CSeq: 104 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 206 confirmed --- lab*CLI> Extension Changed 6000 new state InUse for Notify User 6000 Reliably Transmitting (no NAT) to 192.168.30.193:5060: NOTIFY sip:6001@192.168.30.193:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK261c779d;rport From: ;tag=as1bd164c1 To: Reception 6001 ;tag=75fba40d63 Contact: Call-ID: 97f0e33a014c2888 CSeq: 131 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212 confirmed --- Extension Changed 6000 new state InUse for Notify User 6001 Reliably Transmitting (no NAT) to 192.168.30.199:1046: NOTIFY sip:6003@192.168.30.199:1046;line=guwdxbyt SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK0ea8e788;rport From: ;tag=as314e8d8e To: ;tag=rg47iqt9w3 Contact: Call-ID: 3c2670203b58-j6r2fngncv40 CSeq: 133 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 207 confirmed --- Extension Changed 6000 new state InUse for Notify User 6003 Reliably Transmitting (no NAT) to 192.168.30.200:5060: NOTIFY sip:6002@192.168.30.200:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK54493784;rport From: ;tag=as61cb867a To: "Reception 6002" ;tag=F570E265-895599D2 Contact: Call-ID: 64cdadc6-2aa2a9cf-4372cd4@192.168.30.200 CSeq: 136 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: presence Content-Type: application/xpidf+xml Subscription-State: active Content-Length: 353
--- Extension Changed 6000 new state InUse for Notify User 6002 lab*CLI> -- Executing [2221@default-super:1] Macro("SIP/6000-b7c52430", "default-dial-zap-5946cf-000148") in new stack lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:1] Set("SIP/6000-b7c52430", "DYNAMIC_FEATURES=automon#hookflash") in new stack lab*CLI> [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:2] Set("SIP/6000-b7c52430", "TOUCH_MONITOR=1200326126.100") in new stack lab*CLI> [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:3] Set("SIP/6000-b7c52430", "DB(default/6000/RepeatDial)=2221") in new stack lab*CLI> <--- SIP read from 192.168.30.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK54493784;rport From: ;tag=as61cb867a To: "Reception 6002" ;tag=F570E265-895599D2 CSeq: 136 NOTIFY Call-ID: 64cdadc6-2aa2a9cf-4372cd4@192.168.30.200 Contact: Event: presence User-Agent: PolycomSoundPointIP-SPIP_550-UA/2.1.1.0062 Content-Length: 0 <-------------> lab*CLI> --- (10 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived lab*CLI> <--- SIP read from 192.168.30.199:1046 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK0ea8e788;rport=5060 From: ;tag=as314e8d8e To: ;tag=rg47iqt9w3 Call-ID: 3c2670203b58-j6r2fngncv40 CSeq: 133 NOTIFY Content-Length: 0 <-------------> --- (7 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived lab*CLI> [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:4] Set("SIP/6000-b7c52430", "DB(default/wrapup/s/lastcall)=1200326126.100") in new stack lab*CLI> [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: Set -- Executing [s@macro-default-dial-zap-5946cf-000148:5] Set("SIP/6000-b7c52430", "org_cidnum=6000") in new stack [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: Set -- Executing [s@macro-default-dial-zap-5946cf-000148:6] Set("SIP/6000-b7c52430", "GROUP(OUTGOING)=6000") in new stack [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: Set -- Executing [s@macro-default-dial-zap-5946cf-000148:7] GotoIf("SIP/6000-b7c52430", "1?10") in new stack -- Goto (macro-default-dial-zap-5946cf-000148,s,10) [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: GotoIf -- Executing [s@macro-default-dial-zap-5946cf-000148:10] GotoIf("SIP/6000-b7c52430", "1?11:20") in new stack lab*CLI> -- Goto (macro-default-dial-zap-5946cf-000148,s,11) [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: GotoIf -- Executing [s@macro-default-dial-zap-5946cf-000148:11] Set("SIP/6000-b7c52430", "ext_cidname=God Calling") in new stack [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: Set -- Executing [s@macro-default-dial-zap-5946cf-000148:12] Set("SIP/6000-b7c52430", "ext_cidnum=6000") in new stack [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: Set [Jan 14 10:55:26] DEBUG[6455]: func_db.c:70 function_db_read: DB: default/6000/CallerExternalPres not found in database. -- Executing [s@macro-default-dial-zap-5946cf-000148:13] Set("SIP/6000-b7c52430", "ext_cidpres=") in new stack [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: Set -- Executing [s@macro-default-dial-zap-5946cf-000148:14] GotoIf("SIP/6000-b7c52430", "0?16") in new stack [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: GotoIf -- Executing [s@macro-default-dial-zap-5946cf-000148:15] Set("SIP/6000-b7c52430", "CALLERID(number)=6000") in new stack [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: Set -- Executing [s@macro-default-dial-zap-5946cf-000148:16] GotoIf("SIP/6000-b7c52430", "0?18") in new stack [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: GotoIf -- Executing [s@macro-default-dial-zap-5946cf-000148:17] Set("SIP/6000-b7c52430", "CALLERID(name)=God Calling") in new stack [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: Set -- Executing [s@macro-default-dial-zap-5946cf-000148:18] GotoIf("SIP/6000-b7c52430", "1?20") in new stack -- Goto (macro-default-dial-zap-5946cf-000148,s,20) [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: GotoIf -- Executing [s@macro-default-dial-zap-5946cf-000148:20] Goto("SIP/6000-b7c52430", "50") in new stack -- Goto (macro-default-dial-zap-5946cf-000148,s,50) [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: Goto -- Executing [s@macro-default-dial-zap-5946cf-000148:50] GotoIf("SIP/6000-b7c52430", "1?52") in new stack -- Goto (macro-default-dial-zap-5946cf-000148,s,52) [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: GotoIf -- Executing [s@macro-default-dial-zap-5946cf-000148:52] GotoIf("SIP/6000-b7c52430", "0?53:55") in new stack -- Goto (macro-default-dial-zap-5946cf-000148,s,55) [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: GotoIf -- Executing [s@macro-default-dial-zap-5946cf-000148:55] GotoIf("SIP/6000-b7c52430", "0?56:57") in new stack -- Goto (macro-default-dial-zap-5946cf-000148,s,57) [Jan 14 10:55:26] DEBUG[6455]: app_macro.c:337 _macro_exec: Executed application: GotoIf -- Executing [s@macro-default-dial-zap-5946cf-000148:57] Dial("SIP/6000-b7c52430", "Zap/g1/2221|60|TtwW") in new stack lab*CLI> -- Requested transfer capability: 0x00 - SPEECH lab*CLI> -- Called g1/2221 lab*CLI> Audio is at 192.168.30.254 port 19610 lab*CLI> Adding codec 0x4 (ulaw) to SDP lab*CLI> Adding codec 0x100 (g729) to SDP lab*CLI> Adding non-codec 0x1 (telephone-event) to SDP lab*CLI> <--- Transmitting (no NAT) to 192.168.30.162:2084 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-3kov4jizthjt;received=192.168.30.162;rport=2084 From: "Reception 6000" ;tag=azns9srzgc To: ;tag=as2204249a Call-ID: 3c26704eb838-ckqqjy9ahvbg CSeq: 2 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 289 v=0 o=root 8834 8834 IN IP4 192.168.30.254 s=session c=IN IP4 192.168.30.254 t=0 0 m=audio 19610 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> lab*CLI> <--- SIP read from 192.168.30.193:5060 ---> SIP/2.0 500 CSeq Number Out of order Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK261c779d;rport=5060;received=192.168.30.254 From: ;tag=as1bd164c1 To: Reception 6001 ;tag=75fba40d63 Call-ID: 97f0e33a014c2888 CSeq: 131 NOTIFY Server: Aastra 57i/2.1.2.30 Content-Length: 0 <-------------> --- (8 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived -- Incoming call: Got SIP response 500 "CSeq Number Out of order" back from 192.168.30.193 lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK08070bb5;rport=5060 From: ;tag=as5624c84b To: ;tag=tjss8drb6l Call-ID: 3c2670156a44-imyvvf79f9oc CSeq: 104 NOTIFY Content-Length: 0 <-------------> --- (7 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived lab*CLI> [Jan 14 10:55:26] DEBUG[9129]: chan_zap.c:9020 pri_dchannel: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1 lab*CLI> -- Zap/1-1 is proceeding passing it to SIP/6000-b7c52430 lab*CLI> Retransmitting #2 (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK561e638e;rport From: "asterisk" ;tag=as281ecdba To: Contact: Call-ID: 474c41774bc026d65c824463643cfad2@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:24 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> -- Zap/1-1 is ringing <--- Transmitting (no NAT) to 192.168.30.162:2084 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-3kov4jizthjt;received=192.168.30.162;rport=2084 From: "Reception 6000" ;tag=azns9srzgc To: ;tag=as2204249a Call-ID: 3c26704eb838-ckqqjy9ahvbg CSeq: 2 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> lab*CLI> [Jan 14 10:55:27] DEBUG[9129]: chan_zap.c:1420 zt_enable_ec: Echo cancellation already on lab*CLI> -- Zap/1-1 answered SIP/6000-b7c52430 Audio is at 192.168.30.254 port 19610 Adding codec 0x4 (ulaw) to SDP Adding codec 0x100 (g729) to SDP lab*CLI> Adding non-codec 0x1 (telephone-event) to SDP lab*CLI> <--- Reliably Transmitting (no NAT) to 192.168.30.162:2084 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-3kov4jizthjt;received=192.168.30.162;rport=2084 From: "Reception 6000" ;tag=azns9srzgc To: ;tag=as2204249a Call-ID: 3c26704eb838-ckqqjy9ahvbg CSeq: 2 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 289 v=0 o=root 8834 8835 IN IP4 192.168.30.254 s=session c=IN IP4 192.168.30.254 t=0 0 m=audio 19610 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> ACK sip:2221@192.168.30.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-f30aw01l88pv;rport From: "Reception 6000" ;tag=azns9srzgc To: ;tag=as2204249a Call-ID: 3c26704eb838-ckqqjy9ahvbg CSeq: 2 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 <-------------> --- (9 headers 0 lines) --- lab*CLI> Retransmitting #3 (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK561e638e;rport From: "asterisk" ;tag=as281ecdba To: Contact: Call-ID: 474c41774bc026d65c824463643cfad2@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:24 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> Retransmitting #4 (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK561e638e;rport From: "asterisk" ;tag=as281ecdba To: Contact: Call-ID: 474c41774bc026d65c824463643cfad2@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:24 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> Really destroying SIP dialog '474c41774bc026d65c824463643cfad2@192.168.30.254' Method: OPTIONS lab*CLI> [Jan 14 10:55:28] DTMF[6455]: channel.c:2444 __ast_read: DTMF begin '*' received on SIP/6000-b7c52430 [Jan 14 10:55:28] DTMF[6455]: channel.c:2454 __ast_read: DTMF begin passthrough '*' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:29] DTMF[6455]: channel.c:2381 __ast_read: DTMF end '*' received on SIP/6000-b7c52430, duration 120 ms [Jan 14 10:55:29] DTMF[6455]: channel.c:2422 __ast_read: DTMF end accepted with begin '*' on SIP/6000-b7c52430 [Jan 14 10:55:29] DTMF[6455]: channel.c:2438 __ast_read: DTMF end passthrough '*' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:29] DTMF[6455]: channel.c:2444 __ast_read: DTMF begin '9' received on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:29] DTMF[6455]: channel.c:2454 __ast_read: DTMF begin passthrough '9' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:29] DTMF[6455]: channel.c:2381 __ast_read: DTMF end '9' received on SIP/6000-b7c52430, duration 120 ms [Jan 14 10:55:29] DTMF[6455]: channel.c:2422 __ast_read: DTMF end accepted with begin '9' on SIP/6000-b7c52430 [Jan 14 10:55:29] DTMF[6455]: channel.c:2438 __ast_read: DTMF end passthrough '9' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:29] DTMF[6455]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 0 ms [Jan 14 10:55:29] DTMF[6455]: channel.c:2417 __ast_read: DTMF begin emulation of '9' with duration 100 queued on Zap/1-1 lab*CLI> [Jan 14 10:55:29] DTMF[6455]: channel.c:2444 __ast_read: DTMF begin '9' received on SIP/6000-b7c52430 [Jan 14 10:55:29] DTMF[6455]: channel.c:2454 __ast_read: DTMF begin passthrough '9' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:29] DTMF[6455]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on Zap/1-1 lab*CLI> [Jan 14 10:55:29] DTMF[6455]: channel.c:2381 __ast_read: DTMF end '9' received on SIP/6000-b7c52430, duration 120 ms lab*CLI> [Jan 14 10:55:29] DTMF[6455]: channel.c:2422 __ast_read: DTMF end accepted with begin '9' on SIP/6000-b7c52430 [Jan 14 10:55:29] DTMF[6455]: channel.c:2438 __ast_read: DTMF end passthrough '9' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:29] DTMF[6455]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 0 ms lab*CLI> [Jan 14 10:55:29] DTMF[6455]: channel.c:2417 __ast_read: DTMF begin emulation of '9' with duration 100 queued on Zap/1-1 lab*CLI> [Jan 14 10:55:29] DTMF[6455]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on Zap/1-1 lab*CLI> [Jan 14 10:55:30] DTMF[6455]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 0 ms [Jan 14 10:55:30] DTMF[6455]: channel.c:2417 __ast_read: DTMF begin emulation of '9' with duration 100 queued on Zap/1-1 lab*CLI> [Jan 14 10:55:30] DTMF[6455]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on Zap/1-1 lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> [Jan 14 10:55:30] DTMF[6455]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 0 ms [Jan 14 10:55:30] DTMF[6455]: channel.c:2417 __ast_read: DTMF begin emulation of '9' with duration 100 queued on Zap/1-1 lab*CLI> [Jan 14 10:55:30] DTMF[6455]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on Zap/1-1 lab*CLI> [Jan 14 10:55:30] DTMF[6455]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 0 ms [Jan 14 10:55:30] DTMF[6455]: channel.c:2417 __ast_read: DTMF begin emulation of '9' with duration 100 queued on Zap/1-1 lab*CLI> [Jan 14 10:55:31] DTMF[6455]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on Zap/1-1 lab*CLI> [Jan 14 10:55:31] DTMF[6455]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 0 ms lab*CLI> [Jan 14 10:55:31] DTMF[6455]: channel.c:2417 __ast_read: DTMF begin emulation of '9' with duration 100 queued on Zap/1-1 lab*CLI> [Jan 14 10:55:31] DTMF[6455]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on Zap/1-1 lab*CLI> [Jan 14 10:55:31] DTMF[6455]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 0 ms lab*CLI> [Jan 14 10:55:31] DTMF[6455]: channel.c:2417 __ast_read: DTMF begin emulation of '9' with duration 100 queued on Zap/1-1 lab*CLI> Reliably Transmitting (no NAT) to 192.168.30.162:2084: OPTIONS sip:6000@192.168.30.162:2084;line=7m5w9ycs SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK6b49614a;rport From: "asterisk" ;tag=as0f76fafc To: Contact: Call-ID: 1553af527cdc454e3a7533201c4ea748@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:31 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> [Jan 14 10:55:31] DTMF[6455]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on Zap/1-1 lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK6b49614a;rport=5060 From: "asterisk" ;tag=as0f76fafc To: Call-ID: 1553af527cdc454e3a7533201c4ea748@192.168.30.254 CSeq: 102 OPTIONS Contact: ;flow-id=1 User-Agent: snom360/7.1.30 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, callerid Content-Length: 0 <-------------> --- (14 headers 0 lines) --- lab*CLI> Really destroying SIP dialog '1553af527cdc454e3a7533201c4ea748@192.168.30.254' Method: OPTIONS lab*CLI> [Jan 14 10:55:32] DTMF[6455]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 0 ms lab*CLI> [Jan 14 10:55:32] DTMF[6455]: channel.c:2417 __ast_read: DTMF begin emulation of '9' with duration 100 queued on Zap/1-1 lab*CLI> [Jan 14 10:55:32] DTMF[6455]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on Zap/1-1 lab*CLI> [Jan 14 10:55:32] DTMF[6455]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 0 ms [Jan 14 10:55:32] DTMF[6455]: channel.c:2417 __ast_read: DTMF begin emulation of '9' with duration 100 queued on Zap/1-1 lab*CLI> [Jan 14 10:55:32] DTMF[6455]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on Zap/1-1 lab*CLI> [Jan 14 10:55:33] DEBUG[6455]: chan_zap.c:1055 zt_digit_begin: Started VLDTMF digit '*' lab*CLI> [Jan 14 10:55:33] DEBUG[6455]: chan_zap.c:1090 zt_digit_end: Ending VLDTMF digit '*' lab*CLI> [Jan 14 10:55:33] DEBUG[6455]: chan_zap.c:1055 zt_digit_begin: Started VLDTMF digit '9' lab*CLI> [Jan 14 10:55:33] DEBUG[6455]: chan_zap.c:1090 zt_digit_end: Ending VLDTMF digit '9' lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> BYE sip:2221@192.168.30.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-ml36py1cjp77;rport From: "Reception 6000" ;tag=azns9srzgc To: ;tag=as2204249a Call-ID: 3c26704eb838-ckqqjy9ahvbg CSeq: 3 BYE Max-Forwards: 70 Contact: ;flow-id=1 User-Agent: snom360/7.1.30 RTP-RxStat: Total_Rx_Pkts=376,Rx_Pkts=376,Rx_Pkts_Lost=-16,Remote_Rx_Pkts_Lost=0 RTP-TxStat: Total_Tx_Pkts=387,Tx_Pkts=387,Remote_Tx_Pkts=163 Content-Length: 0 <-------------> lab*CLI> --- (12 headers 0 lines) --- Sending to 192.168.30.162 : 2084 (NAT) lab*CLI> <--- Transmitting (NAT) to 192.168.30.162:2084 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-ml36py1cjp77;received=192.168.30.162;rport=2084 From: "Reception 6000" ;tag=azns9srzgc To: ;tag=as2204249a Call-ID: 3c26704eb838-ckqqjy9ahvbg CSeq: 3 BYE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 lab*CLI> <------------> lab*CLI> [Jan 14 10:55:35] DEBUG[6455]: chan_zap.c:2972 zt_setoption: Set option AUDIO MODE, value: ON(1) on Zap/1-1 [Jan 14 10:55:35] DEBUG[6455]: chan_zap.c:2611 zt_hangup: Not yet hungup... Calling hangup once with icause, and clearing call [Jan 14 10:55:35] DEBUG[6455]: chan_zap.c:2968 zt_setoption: Set option AUDIO MODE, value: OFF(0) on Zap/1-1 -- Hungup 'Zap/1-1' lab*CLI> == Spawn extension (macro-default-dial-zap-5946cf-000148, s, 57) exited non-zero on 'SIP/6000-b7c52430' in macro 'default-dial-zap-5946cf-000148' == Spawn extension (macro-default-dial-zap-5946cf-000148, s, 57) exited non-zero on 'SIP/6000-b7c52430' -- Executing [h@macro-default-dial-zap-5946cf-000148:1] ResetCDR("SIP/6000-b7c52430", "w") in new stack -- Executing [h@macro-default-dial-zap-5946cf-000148:2] NoCDR("SIP/6000-b7c52430", "") in new stack -- Executing [h@macro-default-dial-zap-5946cf-000148:3] System("SIP/6000-b7c52430", "/var/www/scopserv/telephony/scripts/billing/cdr.sh 1200326126.100") in new stack lab*CLI> [Jan 14 10:55:35] DEBUG[6455]: chan_sip.c:3224 update_call_counter: Call from peer '6000' removed from call limit 4 lab*CLI> Reliably Transmitting (no NAT) to 192.168.30.162:2084: NOTIFY sip:6000@192.168.30.162:2084;line=7m5w9ycs SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK139bd55b;rport From: ;tag=as5624c84b To: ;tag=tjss8drb6l Contact: Call-ID: 3c2670156a44-imyvvf79f9oc CSeq: 105 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 207 terminated --- Extension Changed 6000 new state Idle for Notify User 6000 Reliably Transmitting (no NAT) to 192.168.30.193:5060: NOTIFY sip:6001@192.168.30.193:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK2c710f01;rport From: ;tag=as1bd164c1 To: Reception 6001 ;tag=75fba40d63 Contact: Call-ID: 97f0e33a014c2888 CSeq: 132 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 213 terminated --- Extension Changed 6000 new state Idle for Notify User 6001 Reliably Transmitting (no NAT) to 192.168.30.199:1046: NOTIFY sip:6003@192.168.30.199:1046;line=guwdxbyt SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK4853ae34;rport From: ;tag=as314e8d8e To: ;tag=rg47iqt9w3 Contact: Call-ID: 3c2670203b58-j6r2fngncv40 CSeq: 134 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 208 terminated --- Extension Changed 6000 new state Idle for Notify User 6003 Reliably Transmitting (no NAT) to 192.168.30.200:5060: NOTIFY sip:6002@192.168.30.200:5060 SIP/2.0 V lab*CLI> ia: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK3f6ff81f;rport From: ;tag=as61cb867a To: "Reception 6002" ;tag=F570E265-895599D2 Contact: Call-ID: 64cdadc6-2aa2a9cf-4372cd4@192.168.30.200 CSeq: 137 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: presence Content-Type: application/xpidf+xml Subscription-State: active Content-Length: 348
--- Extension Changed 6000 new state Idle for Notify User 6002 lab*CLI> <--- SIP read from 192.168.30.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK3f6ff81f;rport From: ;tag=as61cb867a To: "Reception 6002" ;tag=F570E265-895599D2 CSeq: 137 NOTIFY Call-ID: 64cdadc6-2aa2a9cf-4372cd4@192.168.30.200 Contact: Event: presence User-Agent: PolycomSoundPointIP-SPIP_550-UA/2.1.1.0062 Content-Length: 0 <-------------> --- (10 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK139bd55b;rport=5060 From: ;tag=as5624c84b To: ;tag=tjss8drb6l Call-ID: 3c2670156a44-imyvvf79f9oc CSeq: 105 NOTIFY Content-Length: 0 <-------------> --- (7 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived lab*CLI> <--- SIP read from 192.168.30.199:1046 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK4853ae34;rport=5060 From: ;tag=as314e8d8e To: ;tag=rg47iqt9w3 Call-ID: 3c2670203b58-j6r2fngncv40 CSeq: 134 NOTIFY Content-Length: 0 <-------------> --- (7 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived lab*CLI> Really destroying SIP dialog '3c26704eb838-ckqqjy9ahvbg' Method: BYE lab*CLI> <--- SIP read from 192.168.30.193:5060 ---> SIP/2.0 500 CSeq Number Out of order Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK2c710f01;rport=5060;received=192.168.30.254 From: ;tag=as1bd164c1 To: Reception 6001 ;tag=75fba40d63 Call-ID: 97f0e33a014c2888 CSeq: 132 NOTIFY Server: Aastra 57i/2.1.2.30 Content-Length: 0 <-------------> --- (8 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived -- Incoming call: Got SIP response 500 "CSeq Number Out of order" back from 192.168.30.193 lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> Reliably Transmitting (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK623bee97;rport From: "asterisk" ;tag=as55a1773e To: Contact: Call-ID: 0f217fa605cb121d54f2a3b755697a34@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:38 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> Retransmitting #1 (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK623bee97;rport From: "asterisk" ;tag=as55a1773e To: Contact: Call-ID: 0f217fa605cb121d54f2a3b755697a34@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:38 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> INVITE sip:2221@192.168.30.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-z003ygzh744o;rport From: "Reception 6000" ;tag=fgwk4ovyzy To: Call-ID: 3c26705cadf8-zqdkktk5zteo CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/7.1.30 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 479 v=0 o=root 1544956618 1544956618 IN IP4 192.168.30.162 s=call c=IN IP4 192.168.30.162 t=0 0 m=audio 45102 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:ULCx47qyZjc/MRmCQGFEiwsHVbMZG0fhsAuvn8CB a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv <-------------> lab*CLI> --- (18 headers 19 lines) --- [Jan 14 10:55:40] WARNING[8924]: rtp.c:1987 ast_rtp_settos: Unable to set TOS to 184 Sending to 192.168.30.162 : 2084 (NAT) Using INVITE request as basis request - 3c26705cadf8-zqdkktk5zteo <--- Reliably Transmitting (no NAT) to 192.168.30.162:2084 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-z003ygzh744o;received=192.168.30.162;rport=2084 From: "Reception 6000" ;tag=fgwk4ovyzy To: ;tag=as518efab9 Call-ID: 3c26705cadf8-zqdkktk5zteo CSeq: 1 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="fireworx", nonce="3e840bf1" Content-Length: 0 <------------> lab*CLI> Scheduling destruction of SIP dialog '3c26705cadf8-zqdkktk5zteo' in 32000 ms (Method: INVITE) Found user '6000' lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> ACK sip:2221@192.168.30.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-z003ygzh744o;rport From: "Reception 6000" ;tag=fgwk4ovyzy To: ;tag=as518efab9 Call-ID: 3c26705cadf8-zqdkktk5zteo CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 <-------------> --- (9 headers 0 lines) --- lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> INVITE sip:2221@192.168.30.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-raoj13nqr0jn;rport From: "Reception 6000" ;tag=fgwk4ovyzy To: Call-ID: 3c26705cadf8-zqdkktk5zteo CSeq: 2 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/7.1.30 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Proxy-Authorization: Digest username="6000",realm="fireworx",nonce="3e840bf1",uri="sip:2221@192.168.30.254",response="291f81955ba42089ed4d2eada04da1ba",algorithm=MD5 Content-Type: application/sdp Content-Length: 479 v=0 o=root 1544956618 1544956618 IN IP4 192.168.30.162 s=call c=IN IP4 192.168.30.162 t=0 0 m=audio 45102 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:ULCx47qyZjc/MRmCQGFEiwsHVbMZG0fhsAuvn8CB a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv <-------------> lab*CLI> --- (19 headers 19 lines) --- Sending to 192.168.30.162 : 2084 (NAT) Using INVITE request as basis request - 3c26705cadf8-zqdkktk5zteo Found user '6000' lab*CLI> Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 9 Found RTP audio format 2 Found RTP audio format 3 Found RTP audio format 18 Found RTP audio format 4 Found RTP audio format 101 Peer audio RTP is at port 192.168.30.162:45102 Found audio description format pcmu for ID 0 Found audio description format pcma for ID 8 Found audio description format g722 for ID 9 Found audio description format g726-32 for ID 2 Found audio description format gsm for ID 3 Found audio description format g729 for ID 18 Found audio description format g723 for ID 4 Found audio description format telephone-event for ID 101 Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x190f (g723|gsm|ulaw|alaw|g726|g729|g722)/video=0x0 (nothing), combined - 0x104 (ulaw|g729) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 192.168.30.162:45102 [Jan 14 10:55:40] DEBUG[8924]: chan_sip.c:3250 update_call_counter: Call from peer '6000' is 1 out of 4 Looking for 2221 in default-super (domain 192.168.30.254) Reliably Transmitting (no NAT) to 192.168.30.162:2084: NOTIFY sip:6000@192.168.30.162:2084;line=7m5w9ycs SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK478e569a;rport From: ;tag=as5624c84b To: ;tag=tjss8drb6l Contact: Call-ID: 3c2670156a44-imyvvf79f9oc CSeq: 106 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 206 confirmed --- Extension Changed 6000 new state InUse for Notify User 6000 Reliably Transmitting (no NAT) to 192.168.30.193:5060: NOTIFY sip:6001@192.168.30.193:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK4b50e30e;rport From: ;tag=as1bd164c1 To: Reception 6001 ;tag=75fba40d63 Contact: Call-ID: 97f0e33a014c2888 CSeq: 133 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212 confirmed --- lab*CLI> Extension Changed 6000 new state InUse for Notify User 6001 Reliably Transmitting (no NAT) to 192.168.30.199:1046: NOTIFY sip:6003@192.168.30.199:1046;line=guwdxbyt SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK0bf79e46;rport From: ;tag=as314e8d8e To: ;tag=rg47iqt9w3 Contact: Call-ID: 3c2670203b58-j6r2fngncv40 CSeq: 135 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 207 confirmed --- Extension Changed 6000 new state InUse for Notify User 6003 Reliably Transmitting (no NAT) to 192.168.30.200:5060: NOTIFY sip:6002@192.168.30.200:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK188ed35b;rport From: ;tag=as61cb867a To: "Reception 6002" ;tag=F570E265-895599D2 Contact: Call-ID: 64cdadc6-2aa2a9cf-4372cd4@192.168.30.200 CSeq: 138 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: presence Content-Type: application/xpidf+xml Subscription-State: active Content-Length: 353
--- Extension Changed 6000 new state InUse for Notify User 6002 lab*CLI> list_route: hop: <--- Transmitting (no NAT) to 192.168.30.162:2084 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-raoj13nqr0jn;received=192.168.30.162;rport=2084 From: "Reception 6000" ;tag=fgwk4ovyzy To: Call-ID: 3c26705cadf8-zqdkktk5zteo CSeq: 2 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> lab*CLI> -- Executing [2221@default-super:1] Macro("SIP/6000-b7c52430", "default-dial-zap-5946cf-000148") in new stack lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:1] Set("SIP/6000-b7c52430", "DYNAMIC_FEATURES=automon#hookflash") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:2] Set("SIP/6000-b7c52430", "TOUCH_MONITOR=1200326140.102") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:3] Set("SIP/6000-b7c52430", "DB(default/6000/RepeatDial)=2221") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:4] Set("SIP/6000-b7c52430", "DB(default/wrapup/s/lastcall)=1200326140.102") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:5] Set("SIP/6000-b7c52430", "org_cidnum=6000") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:6] Set("SIP/6000-b7c52430", "GROUP(OUTGOING)=6000") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: <--- SIP read from 192.168.30.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK188ed35b;rport From: ;tag=as61cb867a To: "Reception 6002" ;tag=F570E265-895599D2 CSeq: 138 NOTIFY Call-ID: 64cdadc6-2aa2a9cf-4372cd4@192.168.30.200 Contact: Event: presence User-Agent: PolycomSoundPointIP-SPIP_550-UA/2.1.1.0062 Content-Length: 0 <-------------> lab*CLI> Executed application: Set lab*CLI> --- (10 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:7] GotoIf("SIP/6000-b7c52430", "1?10") in new stack lab*CLI> -- Goto (macro-default-dial-zap-5946cf-000148,s,10) lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: GotoIf lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:10] GotoIf("SIP/6000-b7c52430", "1?11:20") in new stack lab*CLI> -- Goto (macro-default-dial-zap-5946cf-000148,s,11) lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: GotoIf lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:11] Set("SIP/6000-b7c52430", "ext_cidname=God Calling") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:12] Set("SIP/6000-b7c52430", "ext_cidnum=6000") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: func_db.c:70 function_db_read: <--- SIP read from 192.168.30.199:1046 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK0bf79e46;rport=5060 From: ;tag=as314e8d8e To: ;tag=rg47iqt9w3 Call-ID: 3c2670203b58-j6r2fngncv40 CSeq: 135 NOTIFY Content-Length: 0 <-------------> DB: default/6000/CallerExternalPres not found in database. lab*CLI> --- (7 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:13] Set("SIP/6000-b7c52430", "ext_cidpres=") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:14] GotoIf("SIP/6000-b7c52430", "0?16") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: GotoIf lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:15] Set("SIP/6000-b7c52430", "CALLERID(number)=6000") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:16] GotoIf("SIP/6000-b7c52430", "0?18") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: GotoIf lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:17] Set("SIP/6000-b7c52430", "CALLERID(name)=God Calling") in new stack lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: Set lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:18] GotoIf("SIP/6000-b7c52430", "1?20") in new stack lab*CLI> -- Goto (macro-default-dial-zap-5946cf-000148,s,20) lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: GotoIf lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:20] Goto("SIP/6000-b7c52430", "50") in new stack lab*CLI> -- Goto (macro-default-dial-zap-5946cf-000148,s,50) lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: Goto lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:50] GotoIf("SIP/6000-b7c52430", "1?52") in new stack lab*CLI> -- Goto (macro-default-dial-zap-5946cf-000148,s,52) lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: GotoIf lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:52] GotoIf("SIP/6000-b7c52430", "0?53:55") in new stack lab*CLI> -- Goto (macro-default-dial-zap-5946cf-000148,s,55) lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: GotoIf lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:55] GotoIf("SIP/6000-b7c52430", "0?56:57") in new stack lab*CLI> -- Goto (macro-default-dial-zap-5946cf-000148,s,57) lab*CLI> [Jan 14 10:55:40] DEBUG[6476]: app_macro.c:337 _macro_exec: Executed application: GotoIf lab*CLI> -- Executing [s@macro-default-dial-zap-5946cf-000148:57] Dial("SIP/6000-b7c52430", "Zap/g1/2221|60|TtwW") in new stack lab*CLI> -- Requested transfer capability: 0x00 - SPEECH lab*CLI> -- Called g1/2221 lab*CLI> <--- SIP read from 192.168.30.193:5060 ---> SIP/2.0 500 CSeq Number Out of order Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK4b50e30e;rport=5060;received=192.168.30.254 From: ;tag=as1bd164c1 To: Reception 6001 ;tag=75fba40d63 Call-ID: 97f0e33a014c2888 CSeq: 133 NOTIFY Server: Aastra 57i/2.1.2.30 Content-Length: 0 <-------------> lab*CLI> --- (8 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived -- Incoming call: Got SIP response 500 "CSeq Number Out of order" back from 192.168.30.193 lab*CLI> Audio is at 192.168.30.254 port 12666 lab*CLI> Adding codec 0x4 (ulaw) to SDP Adding codec 0x100 (g729) to SDP lab*CLI> Adding non-codec 0x1 (telephone-event) to SDP <--- Transmitting (no NAT) to 192.168.30.162:2084 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-raoj13nqr0jn;received=192.168.30.162;rport=2084 From: "Reception 6000" ;tag=fgwk4ovyzy To: ;tag=as1b61c538 Call-ID: 3c26705cadf8-zqdkktk5zteo CSeq: 2 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 289 v=0 o=root 8834 8834 IN IP4 192.168.30.254 s=session c=IN IP4 192.168.30.254 t=0 0 m=audio 12666 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK478e569a;rport=5060 From: ;tag=as5624c84b To: ;tag=tjss8drb6l Call-ID: 3c2670156a44-imyvvf79f9oc CSeq: 106 NOTIFY Content-Length: 0 <-------------> --- (7 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived lab*CLI> [Jan 14 10:55:40] DEBUG[9129]: chan_zap.c:9020 pri_dchannel: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1 lab*CLI> -- Zap/1-1 is proceeding passing it to SIP/6000-b7c52430 lab*CLI> -- Zap/1-1 is ringing lab*CLI> <--- Transmitting (no NAT) to 192.168.30.162:2084 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-raoj13nqr0jn;received=192.168.30.162;rport=2084 From: "Reception 6000" ;tag=fgwk4ovyzy To: ;tag=as1b61c538 Call-ID: 3c26705cadf8-zqdkktk5zteo CSeq: 2 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> lab*CLI> Retransmitting #2 (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK623bee97;rport From: "asterisk" ;tag=as55a1773e To: Contact: Call-ID: 0f217fa605cb121d54f2a3b755697a34@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:38 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> [Jan 14 10:55:41] DEBUG[9129]: chan_zap.c:1420 zt_enable_ec: Echo cancellation already on lab*CLI> -- Zap/1-1 answered SIP/6000-b7c52430 Audio is at 192.168.30.254 port 12666 Adding codec 0x4 (ulaw) to SDP Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP <--- Reliably Transmitting (no NAT) to 192.168.30.162:2084 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-raoj13nqr0jn;received=192.168.30.162;rport=2084 From: "Reception 6000" ;tag=fgwk4ovyzy To: ;tag=as1b61c538 Call-ID: 3c26705cadf8-zqdkktk5zteo CSeq: 2 INVITE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 289 v=0 o=root 8834 8835 IN IP4 192.168.30.254 s=session c=IN IP4 192.168.30.254 t=0 0 m=audio 12666 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a lab*CLI> =ptime:20 a=sendrecv <------------> lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> ACK sip:2221@192.168.30.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-836ajk935w15;rport From: "Reception 6000" ;tag=fgwk4ovyzy To: ;tag=as1b61c538 Call-ID: 3c26705cadf8-zqdkktk5zteo CSeq: 2 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 <-------------> --- (9 headers 0 lines) --- lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> Retransmitting #3 (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK623bee97;rport From: "asterisk" ;tag=as55a1773e To: Contact: Call-ID: 0f217fa605cb121d54f2a3b755697a34@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:38 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> Retransmitting #4 (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK623bee97;rport From: "asterisk" ;tag=as55a1773e To: Contact: Call-ID: 0f217fa605cb121d54f2a3b755697a34@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:38 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- Really destroying SIP dialog '0f217fa605cb121d54f2a3b755697a34@192.168.30.254' Method: OPTIONS lab*CLI> [Jan 14 10:55:43] DTMF[6476]: channel.c:2444 __ast_read: DTMF begin '*' received on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:43] DTMF[6476]: channel.c:2454 __ast_read: DTMF begin passthrough '*' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:43] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '*' received on SIP/6000-b7c52430, duration 60 ms lab*CLI> [Jan 14 10:55:43] DTMF[6476]: channel.c:2422 __ast_read: DTMF end accepted with begin '*' on SIP/6000-b7c52430 [Jan 14 10:55:43] DTMF[6476]: channel.c:2431 __ast_read: DTMF end '*' has duration 60 but want minimum 80, emulating on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:43] DTMF[6476]: channel.c:2470 __ast_read: DTMF end emulation of '*' queued on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:43] DTMF[6476]: channel.c:2444 __ast_read: DTMF begin '9' received on SIP/6000-b7c52430 [Jan 14 10:55:43] DTMF[6476]: channel.c:2454 __ast_read: DTMF begin passthrough '9' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:43] DEBUG[6476]: chan_zap.c:1055 zt_digit_begin: Started VLDTMF digit '*' lab*CLI> [Jan 14 10:55:43] DEBUG[6476]: chan_zap.c:1090 zt_digit_end: Ending VLDTMF digit '*' lab*CLI> [Jan 14 10:55:43] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '9' received on SIP/6000-b7c52430, duration 60 ms [Jan 14 10:55:43] DTMF[6476]: channel.c:2422 __ast_read: DTMF end accepted with begin '9' on SIP/6000-b7c52430 [Jan 14 10:55:43] DTMF[6476]: channel.c:2431 __ast_read: DTMF end '9' has duration 60 but want minimum 80, emulating on SIP/6000-b7c52430 [Jan 14 10:55:43] DTMF[6476]: channel.c:2470 __ast_read: DTMF end emulation of '9' queued on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:43] DEBUG[6476]: chan_zap.c:1055 zt_digit_begin: Started VLDTMF digit '9' lab*CLI> [Jan 14 10:55:43] DEBUG[6476]: chan_zap.c:1090 zt_digit_end: Ending VLDTMF digit '9' lab*CLI> [Jan 14 10:55:44] DTMF[6476]: channel.c:2444 __ast_read: DTMF begin '9' received on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:44] DTMF[6476]: channel.c:2454 __ast_read: DTMF begin passthrough '9' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:44] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '9' received on SIP/6000-b7c52430, duration 80 ms lab*CLI> [Jan 14 10:55:44] DTMF[6476]: channel.c:2422 __ast_read: DTMF end accepted with begin '9' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:44] DTMF[6476]: channel.c:2438 __ast_read: DTMF end passthrough '9' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:44] DEBUG[6476]: chan_zap.c:1055 zt_digit_begin: Started VLDTMF digit '9' lab*CLI> [Jan 14 10:55:44] DEBUG[6476]: chan_zap.c:1090 zt_digit_end: Ending VLDTMF digit '9' lab*CLI> [Jan 14 10:55:44] DTMF[6476]: channel.c:2444 __ast_read: DTMF begin '9' received on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:44] DTMF[6476]: channel.c:2454 __ast_read: DTMF begin passthrough '9' on SIP/6000-b7c52430 [Jan 14 10:55:44] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '9' received on SIP/6000-b7c52430, duration 60 ms [Jan 14 10:55:44] DTMF[6476]: channel.c:2422 __ast_read: DTMF end accepted with begin '9' on SIP/6000-b7c52430 [Jan 14 10:55:44] DTMF[6476]: channel.c:2431 __ast_read: DTMF end '9' has duration 60 but want minimum 80, emulating on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:44] DTMF[6476]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:44] DEBUG[6476]: chan_zap.c:1055 zt_digit_begin: Started VLDTMF digit '9' lab*CLI> [Jan 14 10:55:44] DEBUG[6476]: chan_zap.c:1090 zt_digit_end: Ending VLDTMF digit '9' lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2444 __ast_read: DTMF begin '*' received on SIP/6000-b7c52430 [Jan 14 10:55:46] DTMF[6476]: channel.c:2454 __ast_read: DTMF begin passthrough '*' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '*' received on SIP/6000-b7c52430, duration 60 ms lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2422 __ast_read: DTMF end accepted with begin '*' on SIP/6000-b7c52430 [Jan 14 10:55:46] DTMF[6476]: channel.c:2431 __ast_read: DTMF end '*' has duration 60 but want minimum 80, emulating on SIP/6000-b7c52430 [Jan 14 10:55:46] DTMF[6476]: channel.c:2470 __ast_read: DTMF end emulation of '*' queued on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2444 __ast_read: DTMF begin '9' received on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2454 __ast_read: DTMF begin passthrough '9' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '9' received on SIP/6000-b7c52430, duration 60 ms lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2422 __ast_read: DTMF end accepted with begin '9' on SIP/6000-b7c52430 [Jan 14 10:55:46] DTMF[6476]: channel.c:2431 __ast_read: DTMF end '9' has duration 60 but want minimum 80, emulating on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2470 __ast_read: DTMF end emulation of '9' queued on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2444 __ast_read: DTMF begin '9' received on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2454 __ast_read: DTMF begin passthrough '9' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '9' received on SIP/6000-b7c52430, duration 80 ms lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2422 __ast_read: DTMF end accepted with begin '9' on SIP/6000-b7c52430 [Jan 14 10:55:46] DTMF[6476]: channel.c:2438 __ast_read: DTMF end passthrough '9' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2444 __ast_read: DTMF begin '9' received on SIP/6000-b7c52430 [Jan 14 10:55:46] DTMF[6476]: channel.c:2454 __ast_read: DTMF begin passthrough '9' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '9' received on SIP/6000-b7c52430, duration 60 ms lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2422 __ast_read: DTMF end accepted with begin '9' on SIP/6000-b7c52430 [Jan 14 10:55:46] DTMF[6476]: channel.c:2431 __ast_read: DTMF end '9' has duration 60 but want minimum 80, emulating on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2470 __ast_read: DTMF end emulation of '9' queued on SIP/6000-b7c52430 lab*CLI> -- User hit '*999' to record call. filename: wav|auto-1200326146-1200326140.102|m lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 0 ms lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2417 __ast_read: DTMF begin emulation of '9' with duration 100 queued on Zap/1-1 lab*CLI> [Jan 14 10:55:46] DTMF[6476]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on Zap/1-1 lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> [Jan 14 10:55:47] DTMF[9896]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 0 ms lab*CLI> [Jan 14 10:55:47] DTMF[9896]: channel.c:2427 __ast_read: DTMF end accepted without begin '9' on Zap/1-1 [Jan 14 10:55:47] DTMF[9896]: channel.c:2438 __ast_read: DTMF end passthrough '9' on Zap/1-1 lab*CLI> [Jan 14 10:55:47] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 80 ms [Jan 14 10:55:47] DTMF[6476]: channel.c:2398 __ast_read: DTMF end '9' put into dtmf queue on Zap/1-1 lab*CLI> [Jan 14 10:55:47] DTMF[6476]: channel.c:2254 __ast_read: DTMF begin emulation of '9' with duration 100 queued on Zap/1-1 lab*CLI> [Jan 14 10:55:47] DTMF[6476]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on Zap/1-1 lab*CLI> [Jan 14 10:55:47] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '9' received on Zap/1-1, duration 0 ms [Jan 14 10:55:47] DTMF[6476]: channel.c:2417 __ast_read: DTMF begin emulation of '9' with duration 100 queued on Zap/1-1 lab*CLI> [Jan 14 10:55:47] DTMF[6476]: channel.c:2501 __ast_read: DTMF end emulation of '9' queued on Zap/1-1 lab*CLI> Reliably Transmitting (no NAT) to 192.168.30.198:5060: OPTIONS sip:6007@192.168.30.198;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK37e8da2e;rport From: "asterisk" ;tag=as4f3c3a25 To: Contact: Call-ID: 746187ef2088d812266f37ac1bce2243@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:47 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> <--- SIP read from 192.168.30.198:5060 ---> SIP/2.0 200 OK Call-ID: 746187ef2088d812266f37ac1bce2243@192.168.30.254 CSeq: 102 OPTIONS From: "asterisk" ;tag=as4f3c3a25 To: ;tag=9e1dd522ac8505a Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK37e8da2e;rport Content-Length: 0 Allow:NOTIFY,REFER,OPTIONS,INVITE,ACK,CANCEL,BYE,INFO Contact: Supported: replaces User-Agent: Aastra 480i/1.4.2.3000 Brcm Callctrl/1.5.1.0 MxSF/v3.2.8.45 <-------------> lab*CLI> --- (11 headers 0 lines) --- lab*CLI> Really destroying SIP dialog '746187ef2088d812266f37ac1bce2243@192.168.30.254' Method: OPTIONS lab*CLI> Reliably Transmitting (no NAT) to 192.168.30.199:1046: OPTIONS sip:6003@192.168.30.199:1046;line=guwdxbyt SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK2768f0ba;rport From: "asterisk" ;tag=as0dc857ec To: Contact: Call-ID: 3af899af237c5b0c647796c873ee91c4@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> <--- SIP read from 192.168.30.199:1046 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK2768f0ba;rport=5060 From: "asterisk" ;tag=as0dc857ec To: Call-ID: 3af899af237c5b0c647796c873ee91c4@192.168.30.254 CSeq: 102 OPTIONS Contact: ;flow-id=1 User-Agent: snom370/7.1.30 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, callerid Content-Length: 0 <-------------> --- (14 headers 0 lines) --- lab*CLI> Really destroying SIP dialog '3af899af237c5b0c647796c873ee91c4@192.168.30.254' Method: OPTIONS lab*CLI> Reliably Transmitting (no NAT) to 192.168.30.200:5060: OPTIONS sip:6002@192.168.30.200:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK4ce647e1;rport From: "asterisk" ;tag=as640930b3 To: Contact: Call-ID: 7740271422f2820a3e8f60f848fcd994@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> <--- SIP read from 192.168.30.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK4ce647e1;rport From: "asterisk" ;tag=as640930b3 To: ;tag=9103F64E-C44A1137 CSeq: 102 OPTIONS Call-ID: 7740271422f2820a3e8f60f848fcd994@192.168.30.254 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_550-UA/2.1.1.0062 Content-Length: 0 <-------------> lab*CLI> --- (10 headers 0 lines) --- lab*CLI> Really destroying SIP dialog '7740271422f2820a3e8f60f848fcd994@192.168.30.254' Method: OPTIONS lab*CLI> Reliably Transmitting (no NAT) to 192.168.30.193:5060: OPTIONS sip:6001@192.168.30.193:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK54b76a13;rport From: "asterisk" ;tag=as1b5547e0 To: Contact: Call-ID: 7060e9507f8268f7054d7b145a401ecb@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> <--- SIP read from 192.168.30.193:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK54b76a13;rport=5060;received=192.168.30.254 From: "asterisk" ;tag=as1b5547e0 To: ;tag=789853672 Call-ID: 7060e9507f8268f7054d7b145a401ecb@192.168.30.254 CSeq: 102 OPTIONS Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, OPTIONS, UPDATE, PRACK, SUBSCRIBE, INFO Server: Aastra 57i/2.1.2.30 Content-Length: 0 <-------------> --- (9 headers 0 lines) --- lab*CLI> Really destroying SIP dialog '7060e9507f8268f7054d7b145a401ecb@192.168.30.254' Method: OPTIONS lab*CLI> [Jan 14 10:55:49] DTMF[6476]: channel.c:2444 __ast_read: DTMF begin '*' received on SIP/6000-b7c52430 [Jan 14 10:55:49] DTMF[6476]: channel.c:2454 __ast_read: DTMF begin passthrough '*' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:49] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '*' received on SIP/6000-b7c52430, duration 60 ms lab*CLI> [Jan 14 10:55:49] DTMF[6476]: channel.c:2422 __ast_read: DTMF end accepted with begin '*' on SIP/6000-b7c52430 [Jan 14 10:55:49] DTMF[6476]: channel.c:2431 __ast_read: DTMF end '*' has duration 60 but want minimum 80, emulating on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:49] DTMF[6476]: channel.c:2470 __ast_read: DTMF end emulation of '*' queued on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:49] DTMF[6476]: channel.c:2444 __ast_read: DTMF begin '2' received on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:49] DTMF[6476]: channel.c:2454 __ast_read: DTMF begin passthrough '2' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:49] DEBUG[6476]: chan_zap.c:1055 zt_digit_begin: Started VLDTMF digit '*' lab*CLI> [Jan 14 10:55:49] DEBUG[6476]: chan_zap.c:1090 zt_digit_end: Ending VLDTMF digit '*' lab*CLI> [Jan 14 10:55:49] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '2' received on SIP/6000-b7c52430, duration 80 ms [Jan 14 10:55:49] DTMF[6476]: channel.c:2422 __ast_read: DTMF end accepted with begin '2' on SIP/6000-b7c52430 [Jan 14 10:55:49] DTMF[6476]: channel.c:2438 __ast_read: DTMF end passthrough '2' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:49] DEBUG[6476]: chan_zap.c:1055 zt_digit_begin: Started VLDTMF digit '2' lab*CLI> [Jan 14 10:55:49] DEBUG[6476]: chan_zap.c:1090 zt_digit_end: Ending VLDTMF digit '2' lab*CLI> [Jan 14 10:55:51] DTMF[6476]: channel.c:2444 __ast_read: DTMF begin '*' received on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:51] DTMF[6476]: channel.c:2454 __ast_read: DTMF begin passthrough '*' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:51] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '*' received on SIP/6000-b7c52430, duration 80 ms lab*CLI> [Jan 14 10:55:51] DTMF[6476]: channel.c:2422 __ast_read: DTMF end accepted with begin '*' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:51] DTMF[6476]: channel.c:2438 __ast_read: DTMF end passthrough '*' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:51] DTMF[6476]: channel.c:2444 __ast_read: DTMF begin '2' received on SIP/6000-b7c52430 [Jan 14 10:55:51] DTMF[6476]: channel.c:2454 __ast_read: DTMF begin passthrough '2' on SIP/6000-b7c52430 lab*CLI> [Jan 14 10:55:51] DTMF[6476]: channel.c:2381 __ast_read: DTMF end '2' received on SIP/6000-b7c52430, duration 80 ms lab*CLI> [Jan 14 10:55:51] DTMF[6476]: channel.c:2422 __ast_read: DTMF end accepted with begin '2' on SIP/6000-b7c52430 [Jan 14 10:55:51] DTMF[6476]: channel.c:2438 __ast_read: DTMF end passthrough '2' on SIP/6000-b7c52430 -- Started music on hold, class 'default', on channel 'Zap/1-1' lab*CLI> -- Playing 'pbx-transfer' (language 'en') lab*CLI> [Jan 14 10:55:51] DEBUG[8884]: res_musiconhold.c:568 monmp3thread: Read 140 bytes of audio while expecting 640 lab*CLI> -- Stopped music on hold on Zap/1-1 lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> Reliably Transmitting (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK79cbfc5c;rport From: "asterisk" ;tag=as28ca12b5 To: Contact: Call-ID: 7680068956c945fb6355c9a121d9d592@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:52 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> Retransmitting #1 (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK79cbfc5c;rport From: "asterisk" ;tag=as28ca12b5 To: Contact: Call-ID: 7680068956c945fb6355c9a121d9d592@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:52 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> BYE sip:2221@192.168.30.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-v3dk71bjvjmg;rport From: "Reception 6000" ;tag=fgwk4ovyzy To: ;tag=as1b61c538 Call-ID: 3c26705cadf8-zqdkktk5zteo CSeq: 3 BYE Max-Forwards: 70 Contact: ;flow-id=1 User-Agent: snom360/7.1.30 RTP-RxStat: Total_Rx_Pkts=597,Rx_Pkts=597,Rx_Pkts_Lost=-6,Remote_Rx_Pkts_Lost=0 RTP-TxStat: Total_Tx_Pkts=598,Tx_Pkts=598,Remote_Tx_Pkts=389 Content-Length: 0 <-------------> lab*CLI> --- (12 headers 0 lines) --- lab*CLI> Sending to 192.168.30.162 : 2084 (NAT) lab*CLI> <--- Transmitting (NAT) to 192.168.30.162:2084 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.162:2084;branch=z9hG4bK-v3dk71bjvjmg;received=192.168.30.162;rport=2084 From: "Reception 6000" ;tag=fgwk4ovyzy To: ;tag=as1b61c538 Call-ID: 3c26705cadf8-zqdkktk5zteo CSeq: 3 BYE User-Agent: Asterisk PBX (Fireworx) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 lab*CLI> <------------> lab*CLI> [Jan 14 10:55:54] DEBUG[6476]: chan_zap.c:2972 zt_setoption: Set option AUDIO MODE, value: ON(1) on Zap/1-1 [Jan 14 10:55:54] DEBUG[6476]: chan_zap.c:2611 zt_hangup: Not yet hungup... Calling hangup once with icause, and clearing call [Jan 14 10:55:54] DEBUG[6476]: chan_zap.c:2968 zt_setoption: Set option AUDIO MODE, value: OFF(0) on Zap/1-1 -- Hungup 'Zap/1-1' [Jan 14 10:55:54] DEBUG[6476]: res_monitor.c:325 ast_monitor_stop: monitor executing ( nice -n 19 soxmix "/var/spool/asterisk/monitor/auto-1200326146-1200326140.102-in.wav" "/var/spool/asterisk/monitor/auto-1200326146-1200326140.102-out.wav" "/var/spool/asterisk/monitor/auto-1200326146-1200326140.102.wav" && rm -f "/var/spool/asterisk/monitor/auto-1200326146-1200326140.102-"* ) & lab*CLI> == Spawn extension (macro-default-dial-zap-5946cf-000148, s, 57) exited non-zero on 'SIP/6000-b7c52430' in macro 'default-dial-zap-5946cf-000148' == Spawn extension (macro-default-dial-zap-5946cf-000148, s, 57) exited non-zero on 'SIP/6000-b7c52430' -- Executing [h@macro-default-dial-zap-5946cf-000148:1] ResetCDR("SIP/6000-b7c52430", "w") in new stack -- Executing [h@macro-default-dial-zap-5946cf-000148:2] NoCDR("SIP/6000-b7c52430", "") in new stack -- Executing [h@macro-default-dial-zap-5946cf-000148:3] System("SIP/6000-b7c52430", "/var/www/scopserv/telephony/scripts/billing/cdr.sh 1200326140.102") in new stack lab*CLI> [Jan 14 10:55:54] DEBUG[6476]: chan_sip.c:3224 update_call_counter: Call from peer '6000' removed from call limit 4 lab*CLI> Reliably Transmitting (no NAT) to 192.168.30.162:2084: NOTIFY sip:6000@192.168.30.162:2084;line=7m5w9ycs SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK667ddbce;rport From: ;tag=as5624c84b To: ;tag=tjss8drb6l Contact: Call-ID: 3c2670156a44-imyvvf79f9oc CSeq: 107 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 207 terminated --- lab*CLI> Extension Changed 6000 new state Idle for Notify User 6000 lab*CLI> Reliably Transmitting (no NAT) to 192.168.30.193:5060: NOTIFY sip:6001@192.168.30.193:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK75531ad8;rport From: ;tag=as1bd164c1 To: Reception 6001 ;tag=75fba40d63 Contact: Call-ID: 97f0e33a014c2888 CSeq: 134 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 213 terminated --- Extension Changed 6000 new state Idle for Notify User 6001 Reliably Transmitting (no NAT) to 192.168.30.199:1046: NOTIFY sip:6003@192.168.30.199:1046;line=guwdxbyt SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK0d4b23b7;rport From: ;tag=as314e8d8e To: ;tag=rg47iqt9w3 Contact: Call-ID: 3c2670203b58-j6r2fngncv40 CSeq: 136 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 208 terminated --- Extension Changed 6000 new state Idle for Notify User 6003 Reliably Transmitting (no NAT) to 192.168.30.200:5060: NOTIFY sip:6002@192.168.30.200:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK425c92e9;rport From: ;tag=as61cb867a To: "Reception 6002" ;tag=F570E265-895599D2 Contact: Call-ID: 64cdadc6-2aa2a9cf-4372cd4@192.168.30.200 CSeq: 139 NOTIFY User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Event: presence Content-Type: application/xpidf+xml Subscription-State: active Content-Length: 348
--- Extension Changed 6000 new state Idle for Notify User 6002 lab*CLI> <--- SIP read from 192.168.30.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK425c92e9;rport From: ;tag=as61cb867a To: "Reception 6002" ;tag=F570E265-895599D2 CSeq: 139 NOTIFY Call-ID: 64cdadc6-2aa2a9cf-4372cd4@192.168.30.200 Contact: Event: presence User-Agent: PolycomSoundPointIP-SPIP_550-UA/2.1.1.0062 Content-Length: 0 <-------------> --- (10 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived lab*CLI> <--- SIP read from 192.168.30.199:1046 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK0d4b23b7;rport=5060 From: ;tag=as314e8d8e To: ;tag=rg47iqt9w3 Call-ID: 3c2670203b58-j6r2fngncv40 CSeq: 136 NOTIFY Content-Length: 0 <-------------> --- (7 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived lab*CLI> <--- SIP read from 192.168.30.162:2084 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK667ddbce;rport=5060 From: ;tag=as5624c84b To: ;tag=tjss8drb6l Call-ID: 3c2670156a44-imyvvf79f9oc CSeq: 107 NOTIFY Content-Length: 0 <-------------> --- (7 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived lab*CLI> Really destroying SIP dialog '3c26705cadf8-zqdkktk5zteo' Method: BYE lab*CLI> <--- SIP read from 192.168.30.193:5060 ---> SIP/2.0 500 CSeq Number Out of order Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK75531ad8;rport=5060;received=192.168.30.254 From: ;tag=as1bd164c1 To: Reception 6001 ;tag=75fba40d63 Call-ID: 97f0e33a014c2888 CSeq: 134 NOTIFY Server: Aastra 57i/2.1.2.30 Content-Length: 0 <-------------> --- (8 headers 0 lines) --- SIP Response message for INCOMING dialog NOTIFY arrived -- Incoming call: Got SIP response 500 "CSeq Number Out of order" back from 192.168.30.193 lab*CLI> Retransmitting #2 (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK79cbfc5c;rport From: "asterisk" ;tag=as28ca12b5 To: Contact: Call-ID: 7680068956c945fb6355c9a121d9d592@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:52 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> Retransmitting #3 (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK79cbfc5c;rport From: "asterisk" ;tag=as28ca12b5 To: Contact: Call-ID: 7680068956c945fb6355c9a121d9d592@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:52 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> Retransmitting #4 (no NAT) to 192.168.30.136:5060: OPTIONS sip:192.168.30.136 SIP/2.0 Via: SIP/2.0/UDP 192.168.30.254:5060;branch=z9hG4bK79cbfc5c;rport From: "asterisk" ;tag=as28ca12b5 To: Contact: Call-ID: 7680068956c945fb6355c9a121d9d592@192.168.30.254 CSeq: 102 OPTIONS User-Agent: Asterisk PBX (Fireworx) Max-Forwards: 70 Date: Mon, 14 Jan 2008 15:55:52 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- lab*CLI> Really destroying SIP dialog '7680068956c945fb6355c9a121d9d592@192.168.30.254' Method: OPTIONS lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> == Parsing '/etc/asterisk/manager.conf': Found lab*CLI> ]0;root@lab:~[root@lab ~]# logout