[2014-11-07 14:11:22] Asterisk 13.0.0 built by root @ localhost.localdomain on a x86_64 running Linux on 2014-11-05 11:40:23 UTC [2014-11-07 14:11:22] VERBOSE[5313] config.c: Parsing '/etc/asterisk/logger.conf': Found [2014-11-07 14:11:22] VERBOSE[5313] config.c: Parsing '/etc/asterisk/logger_general_additional.conf': Found [2014-11-07 14:11:22] VERBOSE[5313] config.c: Parsing '/etc/asterisk/logger_general_custom.conf': Found [2014-11-07 14:11:22] VERBOSE[5313] config.c: Parsing '/etc/asterisk/logger_logfiles_additional.conf': Found [2014-11-07 14:11:22] VERBOSE[5313] config.c: Parsing '/etc/asterisk/logger_logfiles_custom.conf': Found [2014-11-07 14:11:22] VERBOSE[5313] logger.c: Asterisk Queue Logger restarted [2014-11-07 14:11:30] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP request (533 bytes) to UDP:192.168.1.9:5060 ---> OPTIONS sip:603@192.168.1.9:5060;registering_acc=192_168_1_8 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.8:5060;rport;branch=z9hG4bKPj8429ef85-25ed-4e0e-bcc8-119e84d2ae88 From: ;tag=d41af505-d2da-4384-8f6d-f23952e0e127 To: Contact: Call-ID: 4994bbcb-807a-4606-adf7-e55c2892553c CSeq: 61407 OPTIONS Max-Forwards: 70 User-Agent: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:11:30] VERBOSE[7517] res_pjsip_logger.c: <--- Transmitting SIP request (477 bytes) to UDP:192.168.1.4:5065 ---> OPTIONS sip:602@192.168.1.4:5065 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.8:5060;rport;branch=z9hG4bKPj9dc7011f-3467-4a8d-8f19-812e706a093d From: ;tag=53156c50-51e7-40b3-aedb-6f6e7c5509b6 To: Contact: Call-ID: 05f07913-c51b-4fdb-83f9-87ca1ca6f9fa CSeq: 13484 OPTIONS Max-Forwards: 70 User-Agent: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:11:30] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP request (507 bytes) to UDP:192.168.1.10:32768 ---> OPTIONS sip:601@192.168.1.10:32768;line=4cjnjse4 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.8:5060;rport;branch=z9hG4bKPjdf5e273a-139a-4ee7-b45d-f037c2c82418 From: ;tag=7d24bc79-89ee-491a-ac03-f1a21f348ffc To: Contact: Call-ID: 34431daf-e966-42b4-a4e8-4378b7923174 CSeq: 2299 OPTIONS Max-Forwards: 70 User-Agent: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:11:30] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP response (616 bytes) from UDP:192.168.1.9:5060 ---> SIP/2.0 200 OK To: ;tag=d765e594 Via: SIP/2.0/UDP 192.168.1.8:5060;rport=5060;branch=z9hG4bKPj8429ef85-25ed-4e0e-bcc8-119e84d2ae88;received=192.168.1.8 CSeq: 61407 OPTIONS Call-ID: 4994bbcb-807a-4606-adf7-e55c2892553c From: ;tag=d41af505-d2da-4384-8f6d-f23952e0e127 Contact: "603" User-Agent: Jitsi2.5.5065Linux Allow: INFO,OPTIONS,MESSAGE,BYE,REFER,SUBSCRIBE,ACK,CANCEL,PUBLISH,NOTIFY,INVITE Allow-Events: refer Content-Length: 0 [2014-11-07 14:11:30] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP response (386 bytes) from UDP:192.168.1.4:5065 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.8:5060;rport;branch=z9hG4bKPj9dc7011f-3467-4a8d-8f19-812e706a093d From: ;tag=53156c50-51e7-40b3-aedb-6f6e7c5509b6 To: ;tag=1174956101 Call-ID: 05f07913-c51b-4fdb-83f9-87ca1ca6f9fa CSeq: 13484 OPTIONS User-Agent: Yealink SIP-T46G 28.71.0.170 Content-Length: 0 [2014-11-07 14:11:30] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP response (694 bytes) from UDP:192.168.1.10:32768 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.8:5060;rport=5060;branch=z9hG4bKPjdf5e273a-139a-4ee7-b45d-f037c2c82418 From: ;tag=7d24bc79-89ee-491a-ac03-f1a21f348ffc To: ;tag=jwcvqe843j Call-ID: 34431daf-e966-42b4-a4e8-4378b7923174 CSeq: 2299 OPTIONS Contact: ;reg-id=1 User-Agent: snom710/8.7.3.25.5 Accept-Language: en Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, from-change Content-Length: 0 [2014-11-07 14:11:34] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (541 bytes) from UDP:192.168.1.9:5060 ---> OPTIONS sip:192.168.1.8 SIP/2.0 Call-ID: 967c15430c2d927e8c9b5c84939e6618@0:0:0:0:0:0:0:0 CSeq: 209 OPTIONS From: "603" ;tag=b3080712 To: "603" Via: SIP/2.0/UDP 192.168.1.9:5060;branch=z9hG4bK-333235-65c603d0aff3a28a95e4a13e1e2646d1 Max-Forwards: 70 Contact: "603" User-Agent: Jitsi2.5.5065Linux Allow: INFO,OPTIONS,MESSAGE,BYE,REFER,SUBSCRIBE,ACK,CANCEL,PUBLISH,NOTIFY,INVITE Allow-Events: refer Content-Length: 0 [2014-11-07 14:11:34] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP response (557 bytes) to UDP:192.168.1.9:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.9:5060;rport=5060;received=192.168.1.9;branch=z9hG4bK-333235-65c603d0aff3a28a95e4a13e1e2646d1 Call-ID: 967c15430c2d927e8c9b5c84939e6618@0:0:0:0:0:0:0:0 From: "603" ;tag=b3080712 To: "603" ;tag=z9hG4bK-333235-65c603d0aff3a28a95e4a13e1e2646d1 CSeq: 209 OPTIONS WWW-Authenticate: Digest realm="asterisk",nonce="1415365894/949a33197efa79bd45ce04c6f3efc617",opaque="4f5d1f6229ac6c99",algorithm=md5,qop="auth" Server: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:11:42] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (871 bytes) from UDP:192.168.1.4:5065 ---> INVITE sip:601@192.168.1.8:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.4:5065;branch=z9hG4bK1804872531 From: "602" ;tag=190886754 To: Call-ID: 703589347@192.168.1.4 CSeq: 1 INVITE Contact: Content-Type: application/sdp Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE Max-Forwards: 70 User-Agent: Yealink SIP-T46G 28.71.0.170 Supported: replaces Allow-Events: talk,hold,conference,refer,check-sync Content-Length: 304 v=0 o=- 20283 20283 IN IP4 192.168.1.4 s=SDP data c=IN IP4 192.168.1.4 t=0 0 m=audio 11798 RTP/AVP 0 8 18 9 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:9 G722/8000 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv [2014-11-07 14:11:42] VERBOSE[7517] res_pjsip_logger.c: <--- Transmitting SIP response (462 bytes) to UDP:192.168.1.4:5065 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.4:5065;rport=5065;received=192.168.1.4;branch=z9hG4bK1804872531 Call-ID: 703589347@192.168.1.4 From: "602" ;tag=190886754 To: ;tag=z9hG4bK1804872531 CSeq: 1 INVITE WWW-Authenticate: Digest realm="asterisk",nonce="1415365902/27f7b2a9173f9767ad5c2a246d180c18",opaque="6843a1b3060eaf5f",algorithm=md5,qop="auth" Server: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:11:42] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (262 bytes) from UDP:192.168.1.4:5065 ---> ACK sip:601@192.168.1.8:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.4:5065;branch=z9hG4bK1804872531 From: "602" ;tag=190886754 To: ;tag=z9hG4bK1804872531 Call-ID: 703589347@192.168.1.4 CSeq: 1 ACK Content-Length: 0 [2014-11-07 14:11:42] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (1140 bytes) from UDP:192.168.1.4:5065 ---> INVITE sip:601@192.168.1.8:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.4:5065;branch=z9hG4bK453267979 From: "602" ;tag=190886754 To: Call-ID: 703589347@192.168.1.4 CSeq: 2 INVITE Contact: Authorization: Digest username="602", realm="asterisk", nonce="1415365902/27f7b2a9173f9767ad5c2a246d180c18", uri="sip:601@192.168.1.8:5060", response="f32ac65eccb8986c9b460abe060b7e98", algorithm=MD5, cnonce="0a4f113b", opaque="6843a1b3060eaf5f", qop=auth, nc=00000001 Content-Type: application/sdp Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE Max-Forwards: 70 User-Agent: Yealink SIP-T46G 28.71.0.170 Supported: replaces Allow-Events: talk,hold,conference,refer,check-sync Content-Length: 304 v=0 o=- 20283 20283 IN IP4 192.168.1.4 s=SDP data c=IN IP4 192.168.1.4 t=0 0 m=audio 11798 RTP/AVP 0 8 18 9 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:9 G722/8000 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv [2014-11-07 14:11:42] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP response (286 bytes) to UDP:192.168.1.4:5065 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.4:5065;rport=5065;received=192.168.1.4;branch=z9hG4bK453267979 Call-ID: 703589347@192.168.1.4 From: "602" ;tag=190886754 To: CSeq: 2 INVITE Server: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [601@from-internal:1] GotoIf("PJSIP/602-00000027", "1?ext-local,601,1") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Goto (ext-local,601,1) [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [601@ext-local:1] Set("PJSIP/602-00000027", "__RINGTIMER=15") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [601@ext-local:2] Macro("PJSIP/602-00000027", "exten-vm,novm,601,0,0,0") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-exten-vm:1] Macro("PJSIP/602-00000027", "user-callerid,") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/602-00000027", "TOUCH_MONITOR=1415365902.320") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/602-00000027", "AMPUSER=602") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("PJSIP/602-00000027", "0?report") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("PJSIP/602-00000027", "1?Set(REALCALLERIDNUM=602)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:5] Set("PJSIP/602-00000027", "AMPUSER=602") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("PJSIP/602-00000027", "0?limit") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:7] Set("PJSIP/602-00000027", "AMPUSERCIDNAME=Int - 602") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("PJSIP/602-00000027", "0?report") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:9] Set("PJSIP/602-00000027", "AMPUSERCID=602") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:10] Set("PJSIP/602-00000027", "__DIAL_OPTIONS=Ttr") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:11] Set("PJSIP/602-00000027", "CALLERID(all)="Int - 602" <602>") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:12] GotoIf("PJSIP/602-00000027", "0?limit") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:13] ExecIf("PJSIP/602-00000027", "0?Set(GROUP(concurrency_limit)=602)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:14] GosubIf("PJSIP/602-00000027", "7?sub-ccss,s,1(macro-exten-vm,)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-ccss:1] ExecIf("PJSIP/602-00000027", "0?Return()") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-ccss:2] Set("PJSIP/602-00000027", "CCSS_SETUP=TRUE") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-ccss:3] GosubIf("PJSIP/602-00000027", "0?monitor_config,1(macro-exten-vm,):monitor_default,1(macro-exten-vm,)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [monitor_default@sub-ccss:1] GotoIf("PJSIP/602-00000027", "0?is_exten") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [monitor_default@sub-ccss:2] StackPop("PJSIP/602-00000027", "") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [monitor_default@sub-ccss:3] Return("PJSIP/602-00000027", "FALSE") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:15] ExecIf("PJSIP/602-00000027", "1?Set(CHANNEL(language)=it)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:16] GotoIf("PJSIP/602-00000027", "0?continue") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:17] ExecIf("PJSIP/602-00000027", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:18] Set("PJSIP/602-00000027", "__TTL=64") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:19] GotoIf("PJSIP/602-00000027", "1?continue") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Goto (macro-user-callerid,s,30) [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:30] Set("PJSIP/602-00000027", "CALLERID(number)=602") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:31] Set("PJSIP/602-00000027", "CALLERID(name)=Int - 602") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:32] Set("PJSIP/602-00000027", "CDR(cnum)=602") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:33] Set("PJSIP/602-00000027", "CDR(cnam)=Int - 602") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-user-callerid:34] Set("PJSIP/602-00000027", "CHANNEL(language)=it") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-exten-vm:2] Set("PJSIP/602-00000027", "RingGroupMethod=none") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-exten-vm:3] Set("PJSIP/602-00000027", "__EXTTOCALL=601") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-exten-vm:4] Set("PJSIP/602-00000027", "__PICKUPMARK=601") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-exten-vm:5] Set("PJSIP/602-00000027", "RT=") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-exten-vm:6] Gosub("PJSIP/602-00000027", "sub-record-check,s,1(exten,601,)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:1] Set("PJSIP/602-00000027", "REC_POLICY_MODE_SAVE=") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:2] GotoIf("PJSIP/602-00000027", "1?check") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Goto (sub-record-check,s,7) [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:7] Set("PJSIP/602-00000027", "__MON_FMT=wav") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:8] GotoIf("PJSIP/602-00000027", "1?next") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Goto (sub-record-check,s,11) [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/602-00000027", "0?Return()") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:12] ExecIf("PJSIP/602-00000027", "0?Set(__REC_POLICY_MODE=)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:13] GotoIf("PJSIP/602-00000027", "0?exten,1") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:14] Set("PJSIP/602-00000027", "__REC_STATUS=INITIALIZED") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:15] Set("PJSIP/602-00000027", "NOW=1415365902") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:16] Set("PJSIP/602-00000027", "__DAY=07") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:17] Set("PJSIP/602-00000027", "__MONTH=11") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:18] Set("PJSIP/602-00000027", "__YEAR=2014") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:19] Set("PJSIP/602-00000027", "__TIMESTR=20141107-141142") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:20] Set("PJSIP/602-00000027", "__FROMEXTEN=602") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:21] Set("PJSIP/602-00000027", "__CALLFILENAME=exten-601-602-20141107-141142-1415365902.320") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-record-check:22] Goto("PJSIP/602-00000027", "exten,1") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Goto (sub-record-check,exten,1) [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [exten@sub-record-check:1] GotoIf("PJSIP/602-00000027", "0?callee") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [exten@sub-record-check:2] Set("PJSIP/602-00000027", "__REC_POLICY_MODE=dontcare") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [exten@sub-record-check:3] GotoIf("PJSIP/602-00000027", "1?caller") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Goto (sub-record-check,exten,10) [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [exten@sub-record-check:10] Set("PJSIP/602-00000027", "__REC_POLICY_MODE=dontcare") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [exten@sub-record-check:11] GosubIf("PJSIP/602-00000027", "0?record,1(exten,601,602)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [exten@sub-record-check:12] Return("PJSIP/602-00000027", "") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-exten-vm:7] GotoIf("PJSIP/602-00000027", "1?macrodial") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Goto (macro-exten-vm,s,13) [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-exten-vm:13] GosubIf("PJSIP/602-00000027", "0?clrheader,1()") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-exten-vm:14] Macro("PJSIP/602-00000027", "dial-one,,Ttr,601") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:1] Set("PJSIP/602-00000027", "DEXTEN=601") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:2] Set("PJSIP/602-00000027", "DIALSTATUS_CW=") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:3] GosubIf("PJSIP/602-00000027", "0?screen,1()") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:4] GosubIf("PJSIP/602-00000027", "0?cf,1()") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:5] GotoIf("PJSIP/602-00000027", "1?skip1") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Goto (macro-dial-one,s,8) [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:8] GotoIf("PJSIP/602-00000027", "0?nodial") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:9] GotoIf("PJSIP/602-00000027", "0?continue") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:10] Set("PJSIP/602-00000027", "EXTHASCW=ENABLED") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:11] GotoIf("PJSIP/602-00000027", "0?next1:cwinusebusy") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Goto (macro-dial-one,s,23) [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:23] GotoIf("PJSIP/602-00000027", "1?next3:continue") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Goto (macro-dial-one,s,24) [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:24] ExecIf("PJSIP/602-00000027", "0?Set(DIALSTATUS_CW=BUSY)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:25] GotoIf("PJSIP/602-00000027", "0?nodial") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:26] GosubIf("PJSIP/602-00000027", "1?dstring,1():dlocal,1()") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:1] Set("PJSIP/602-00000027", "DSTRING=") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:2] Set("PJSIP/602-00000027", "DEVICES=601") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf("PJSIP/602-00000027", "0?Return()") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf("PJSIP/602-00000027", "0?Set(DEVICES=01)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:5] Set("PJSIP/602-00000027", "LOOPCNT=1") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:6] Set("PJSIP/602-00000027", "ITER=1") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:7] Set("PJSIP/602-00000027", "THISDIAL=PJSIP/601") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:8] GosubIf("PJSIP/602-00000027", "1?zap2dahdi,1()") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [zap2dahdi@macro-dial-one:1] ExecIf("PJSIP/602-00000027", "0?Return()") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [zap2dahdi@macro-dial-one:2] Set("PJSIP/602-00000027", "NEWDIAL=") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [zap2dahdi@macro-dial-one:3] Set("PJSIP/602-00000027", "LOOPCNT2=1") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [zap2dahdi@macro-dial-one:4] Set("PJSIP/602-00000027", "ITER2=1") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [zap2dahdi@macro-dial-one:5] Set("PJSIP/602-00000027", "THISPART2=PJSIP/601") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [zap2dahdi@macro-dial-one:6] ExecIf("PJSIP/602-00000027", "0?Set(THISPART2=DAHDIIP/601)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [zap2dahdi@macro-dial-one:7] Set("PJSIP/602-00000027", "NEWDIAL=PJSIP/601&") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [zap2dahdi@macro-dial-one:8] Set("PJSIP/602-00000027", "ITER2=2") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [zap2dahdi@macro-dial-one:9] GotoIf("PJSIP/602-00000027", "0?begin2") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [zap2dahdi@macro-dial-one:10] Set("PJSIP/602-00000027", "THISDIAL=PJSIP/601") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [zap2dahdi@macro-dial-one:11] Return("PJSIP/602-00000027", "") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:9] GotoIf("PJSIP/602-00000027", "0?doset") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:10] NoOp("PJSIP/602-00000027", "Debug: Found PJSIP Destination PJSIP/601, updaing with PJSIP_DIAL_CONTACTS") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:11] Set("PJSIP/602-00000027", "THISDIAL=PJSIP/601/sip:601@192.168.1.10:32768;line=4cjnjse4") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:12] Set("PJSIP/602-00000027", "DSTRING=PJSIP/601/sip:601@192.168.1.10:32768;line=4cjnjse4&") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:13] Set("PJSIP/602-00000027", "ITER=2") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf("PJSIP/602-00000027", "0?begin") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:15] Set("PJSIP/602-00000027", "DSTRING=PJSIP/601/sip:601@192.168.1.10:32768;line=4cjnjse4") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [dstring@macro-dial-one:16] Return("PJSIP/602-00000027", "") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:27] GotoIf("PJSIP/602-00000027", "0?nodial") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:28] GotoIf("PJSIP/602-00000027", "0?skiptrace") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:29] GosubIf("PJSIP/602-00000027", "1?ctset,1():ctclear,1()") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [ctset@macro-dial-one:1] Set("PJSIP/602-00000027", "DB(CALLTRACE/601)=602") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [ctset@macro-dial-one:2] Return("PJSIP/602-00000027", "") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:30] Set("PJSIP/602-00000027", "D_OPTIONS=Ttr") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:31] ExecIf("PJSIP/602-00000027", "0?SIPAddHeader(Alert-Info: )") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:32] ExecIf("PJSIP/602-00000027", "0?SIPAddHeader()") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:33] ExecIf("PJSIP/602-00000027", "0?Set(CHANNEL(musicclass)=)") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:34] GosubIf("PJSIP/602-00000027", "0?qwait,1()") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:35] Set("PJSIP/602-00000027", "__CWIGNORE=") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:36] Set("PJSIP/602-00000027", "__KEEPCID=TRUE") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:37] GotoIf("PJSIP/602-00000027", "0?usegoto,1") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:38] GotoIf("PJSIP/602-00000027", "0?godial") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:39] Gosub("PJSIP/602-00000027", "sub-presencestate-display,s,1(601)") in new stack [2014-11-07 14:11:42] WARNING[7972][C-00000013] func_presencestate.c: PRESENCE_STATE unknown [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@sub-presencestate-display:1] Goto("PJSIP/602-00000027", "state-,1") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Goto (sub-presencestate-display,state-,1) [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [state-@sub-presencestate-display:1] Set("PJSIP/602-00000027", "PRESENCESTATE_DISPLAY=") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [state-@sub-presencestate-display:2] Return("PJSIP/602-00000027", "") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:40] Set("PJSIP/602-00000027", "CONNECTEDLINE(name,i)=Int - 601") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:41] Set("PJSIP/602-00000027", "CONNECTEDLINE(num)=601") in new stack [2014-11-07 14:11:42] VERBOSE[7517] res_pjsip_logger.c: <--- Transmitting SIP response (528 bytes) to UDP:192.168.1.4:5065 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.4:5065;rport=5065;received=192.168.1.4;branch=z9hG4bK453267979 Call-ID: 703589347@192.168.1.4 From: "602" ;tag=190886754 To: ;tag=072e7c7b-4b04-44d4-9a13-f7e301240114 CSeq: 2 INVITE Server: FPBX-12.0.6(13.0.0) Contact: Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REFER, REGISTER, MESSAGE P-Asserted-Identity: "Int - 601" Content-Length: 0 [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:42] Set("PJSIP/602-00000027", "D_OPTIONS=TtrI") in new stack [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-dial-one:43] Dial("PJSIP/602-00000027", "PJSIP/601/sip:601@192.168.1.10:32768;line=4cjnjse4,,TtrI") in new stack [2014-11-07 14:11:42] VERBOSE[7517] res_pjsip_logger.c: <--- Transmitting SIP request (1004 bytes) to UDP:192.168.1.10:32768 ---> INVITE sip:601@192.168.1.10:32768;line=4cjnjse4 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.8:5060;rport;branch=z9hG4bKPj68f17c34-4e33-4969-9586-9754ab8a8695 From: "Int - 602" ;tag=ed0be285-5224-422d-8854-0ce3d7a09e96 To: Contact: Call-ID: 4290917c-5ecd-4ea3-8dbf-d5e1388371ff CSeq: 24946 INVITE Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REFER, REGISTER, MESSAGE Supported: 100rel, timer, replaces, norefersub Session-Expires: 1800 Min-SE: 90 P-Asserted-Identity: "Int - 602" Max-Forwards: 70 User-Agent: FPBX-12.0.6(13.0.0) Content-Type: application/sdp Content-Length: 235 v=0 o=- 1851899967 1851899967 IN IP4 192.168.1.8 s=Asterisk c=IN IP4 192.168.1.8 t=0 0 m=audio 19454 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] app_dial.c: Called PJSIP/601/sip:601@192.168.1.10:32768;line=4cjnjse4 [2014-11-07 14:11:42] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP response (528 bytes) to UDP:192.168.1.4:5065 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.4:5065;rport=5065;received=192.168.1.4;branch=z9hG4bK453267979 Call-ID: 703589347@192.168.1.4 From: "602" ;tag=190886754 To: ;tag=072e7c7b-4b04-44d4-9a13-f7e301240114 CSeq: 2 INVITE Server: FPBX-12.0.6(13.0.0) Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REFER, REGISTER, MESSAGE P-Asserted-Identity: "Int - 601" Contact: Content-Length: 0 [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] app_dial.c: Connected line update to PJSIP/602-00000027 prevented. [2014-11-07 14:11:42] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP response (408 bytes) from UDP:192.168.1.10:32768 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.8:5060;rport=5060;branch=z9hG4bKPj68f17c34-4e33-4969-9586-9754ab8a8695 From: "Int - 602" ;tag=ed0be285-5224-422d-8854-0ce3d7a09e96 To: ;tag=6dzn1go3x9 Call-ID: 4290917c-5ecd-4ea3-8dbf-d5e1388371ff CSeq: 24946 INVITE Contact: ;reg-id=1 Content-Length: 0 [2014-11-07 14:11:42] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP response (577 bytes) from UDP:192.168.1.10:32768 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.8:5060;rport=5060;branch=z9hG4bKPj68f17c34-4e33-4969-9586-9754ab8a8695 From: "Int - 602" ;tag=ed0be285-5224-422d-8854-0ce3d7a09e96 To: ;tag=6dzn1go3x9 Call-ID: 4290917c-5ecd-4ea3-8dbf-d5e1388371ff CSeq: 24946 INVITE Contact: ;reg-id=1 Require: 100rel RSeq: 1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE Allow-Events: talk, hold, refer, call-info Content-Length: 0 [2014-11-07 14:11:42] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP request (450 bytes) to UDP:192.168.1.10:32768 ---> PRACK sip:601@192.168.1.10:32768;line=4cjnjse4 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.8:5060;rport;branch=z9hG4bKPj0adc6f18-cfea-4b93-957e-6a1984b2c787 From: "Int - 602" ;tag=ed0be285-5224-422d-8854-0ce3d7a09e96 To: ;tag=6dzn1go3x9 Call-ID: 4290917c-5ecd-4ea3-8dbf-d5e1388371ff CSeq: 24947 PRACK RAck: 1 24946 INVITE Max-Forwards: 70 User-Agent: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:11:42] VERBOSE[7972][C-00000013] app_dial.c: PJSIP/601-00000028 is ringing [2014-11-07 14:11:42] VERBOSE[7517] res_pjsip_logger.c: <--- Transmitting SIP response (528 bytes) to UDP:192.168.1.4:5065 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.4:5065;rport=5065;received=192.168.1.4;branch=z9hG4bK453267979 Call-ID: 703589347@192.168.1.4 From: "602" ;tag=190886754 To: ;tag=072e7c7b-4b04-44d4-9a13-f7e301240114 CSeq: 2 INVITE Server: FPBX-12.0.6(13.0.0) Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REFER, REGISTER, MESSAGE P-Asserted-Identity: "Int - 601" Contact: Content-Length: 0 [2014-11-07 14:11:42] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP response (403 bytes) from UDP:192.168.1.10:32768 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.1.8:5060;rport=5060;branch=z9hG4bKPj0adc6f18-cfea-4b93-957e-6a1984b2c787 From: "Int - 602" ;tag=ed0be285-5224-422d-8854-0ce3d7a09e96 To: ;tag=6dzn1go3x9 Call-ID: 4290917c-5ecd-4ea3-8dbf-d5e1388371ff CSeq: 24947 PRACK Contact: ;reg-id=1 Content-Length: 0 [2014-11-07 14:11:44] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP response (931 bytes) from UDP:192.168.1.10:32768 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.1.8:5060;rport=5060;branch=z9hG4bKPj68f17c34-4e33-4969-9586-9754ab8a8695 From: "Int - 602" ;tag=ed0be285-5224-422d-8854-0ce3d7a09e96 To: ;tag=6dzn1go3x9 Call-ID: 4290917c-5ecd-4ea3-8dbf-d5e1388371ff CSeq: 24946 INVITE Contact: ;reg-id=1 Require: timer Session-Expires: 1800;refresher=uac User-Agent: snom710/8.7.3.25.5 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, from-change Content-Type: application/sdp Content-Length: 218 v=0 o=root 776953128 776953129 IN IP4 192.168.1.10 s=call c=IN IP4 192.168.1.10 t=0 0 m=audio 49588 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv [2014-11-07 14:11:44] VERBOSE[7517] res_pjsip_logger.c: <--- Transmitting SIP request (424 bytes) to UDP:192.168.1.10:32768 ---> ACK sip:601@192.168.1.10:32768;line=4cjnjse4 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.8:5060;rport;branch=z9hG4bKPj64b47b81-dd8d-484b-80a4-74dc9dea6686 From: "Int - 602" ;tag=ed0be285-5224-422d-8854-0ce3d7a09e96 To: ;tag=6dzn1go3x9 Call-ID: 4290917c-5ecd-4ea3-8dbf-d5e1388371ff CSeq: 24946 ACK Max-Forwards: 70 User-Agent: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:11:44] VERBOSE[7972][C-00000013] app_dial.c: PJSIP/601-00000028 answered PJSIP/602-00000027 [2014-11-07 14:11:44] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP response (830 bytes) to UDP:192.168.1.4:5065 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.4:5065;rport=5065;received=192.168.1.4;branch=z9hG4bK453267979 Call-ID: 703589347@192.168.1.4 From: "602" ;tag=190886754 To: ;tag=072e7c7b-4b04-44d4-9a13-f7e301240114 CSeq: 2 INVITE Server: FPBX-12.0.6(13.0.0) Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REFER, REGISTER, MESSAGE P-Asserted-Identity: "Int - 601" Contact: Supported: 100rel, timer, replaces, norefersub Content-Type: application/sdp Content-Length: 225 v=0 o=- 20283 20285 IN IP4 192.168.1.8 s=Asterisk c=IN IP4 192.168.1.8 t=0 0 m=audio 14470 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [2014-11-07 14:11:44] VERBOSE[7972][C-00000013] bridge_channel.c: Channel PJSIP/602-00000027 joined 'simple_bridge' basic-bridge <23002f95-d3df-41e3-86a0-7edd5c1d59c3> [2014-11-07 14:11:44] VERBOSE[7973][C-00000013] bridge_channel.c: Channel PJSIP/601-00000028 joined 'simple_bridge' basic-bridge <23002f95-d3df-41e3-86a0-7edd5c1d59c3> [2014-11-07 14:11:44] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (374 bytes) from UDP:192.168.1.4:5065 ---> ACK sip:192.168.1.8:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.4:5065;branch=z9hG4bK1474533637 From: "602" ;tag=190886754 To: ;tag=072e7c7b-4b04-44d4-9a13-f7e301240114 Call-ID: 703589347@192.168.1.4 CSeq: 2 ACK Contact: Max-Forwards: 70 User-Agent: Yealink SIP-T46G 28.71.0.170 Content-Length: 0 [2014-11-07 14:11:47] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (1352 bytes) from UDP:192.168.1.10:32768 ---> INVITE sip:5d3db432-12c8-4930-ab76-1fbe001262ac@192.168.1.8:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.10:32768;branch=z9hG4bK-8aj8v4cvz4qb;rport From: ;tag=6dzn1go3x9 To: "Int - 602" ;tag=ed0be285-5224-422d-8854-0ce3d7a09e96 Call-ID: 4290917c-5ecd-4ea3-8dbf-d5e1388371ff CSeq: 1 INVITE Max-Forwards: 70 Contact: ;reg-id=1 X-Serialnumber: 00041376E0BF P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom710/8.7.3.25.5 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, from-change Require: timer Session-Expires: 1800;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 485 v=0 o=root 776953128 776953130 IN IP4 192.168.1.10 s=call c=IN IP4 192.168.1.10 t=0 0 m=audio 49588 RTP/AVP 9 0 8 3 99 108 18 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:GIEVFLzY0CxfzG/kHWI8W1Z/Sn5BuNU8dc1ZyPXa a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:99 G726-32/8000 a=rtpmap:108 AAL2-G726-32/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendonly [2014-11-07 14:11:47] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP response (903 bytes) to UDP:192.168.1.10:32768 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.10:32768;rport=32768;received=192.168.1.10;branch=z9hG4bK-8aj8v4cvz4qb Call-ID: 4290917c-5ecd-4ea3-8dbf-d5e1388371ff From: ;tag=6dzn1go3x9 To: "Int - 602" ;tag=ed0be285-5224-422d-8854-0ce3d7a09e96 CSeq: 1 INVITE Session-Expires: 1800;refresher=uas Contact: Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REFER, REGISTER, MESSAGE Supported: 100rel, timer, replaces, norefersub Server: FPBX-12.0.6(13.0.0) Content-Type: application/sdp Content-Length: 235 v=0 o=- 1851899967 1851899968 IN IP4 192.168.1.8 s=Asterisk c=IN IP4 192.168.1.8 t=0 0 m=audio 19454 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=recvonly [2014-11-07 14:11:47] VERBOSE[7972][C-00000013] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/602-00000027' [2014-11-07 14:11:47] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (442 bytes) from UDP:192.168.1.10:32768 ---> ACK sip:5d3db432-12c8-4930-ab76-1fbe001262ac@192.168.1.8:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.10:32768;branch=z9hG4bK-it3uoihuwq6i;rport From: ;tag=6dzn1go3x9 To: "Int - 602" ;tag=ed0be285-5224-422d-8854-0ce3d7a09e96 Call-ID: 4290917c-5ecd-4ea3-8dbf-d5e1388371ff CSeq: 1 ACK Max-Forwards: 70 Contact: ;reg-id=1 Content-Length: 0 [2014-11-07 14:11:52] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (1255 bytes) from UDP:192.168.1.10:32768 ---> INVITE sip:603@192.168.1.8;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.1.10:32768;branch=z9hG4bK-1j1y0tckwvmt;rport From: "Int - 601" ;tag=r1z9432e2w To: Call-ID: 545cc514ec33-ht8bthg8rdqw CSeq: 1 INVITE Max-Forwards: 70 Contact: ;reg-id=1 X-Serialnumber: 00041376E0BF P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom710/8.7.3.25.5 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, from-change Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 487 v=0 o=root 1869386380 1869386380 IN IP4 192.168.1.10 s=call c=IN IP4 192.168.1.10 t=0 0 m=audio 62034 RTP/AVP 9 0 8 3 99 108 18 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:dzMJW4SpzYsvQxX0hRnTcgy7/iF077kl1KHZWwqc a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:99 G726-32/8000 a=rtpmap:108 AAL2-G726-32/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv [2014-11-07 14:11:52] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP response (494 bytes) to UDP:192.168.1.10:32768 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.10:32768;rport=32768;received=192.168.1.10;branch=z9hG4bK-1j1y0tckwvmt Call-ID: 545cc514ec33-ht8bthg8rdqw From: "Int - 601" ;tag=r1z9432e2w To: ;tag=z9hG4bK-1j1y0tckwvmt CSeq: 1 INVITE WWW-Authenticate: Digest realm="asterisk",nonce="1415365912/6362663456f9761c1961b956f451ba6a",opaque="6fb1b2210c520b07",algorithm=md5,qop="auth" Server: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:11:52] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (384 bytes) from UDP:192.168.1.10:32768 ---> ACK sip:603@192.168.1.8;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.1.10:32768;branch=z9hG4bK-1j1y0tckwvmt;rport From: "Int - 601" ;tag=r1z9432e2w To: ;tag=z9hG4bK-1j1y0tckwvmt Call-ID: 545cc514ec33-ht8bthg8rdqw CSeq: 1 ACK Max-Forwards: 70 Contact: ;reg-id=1 Content-Length: 0 [2014-11-07 14:11:52] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (1522 bytes) from UDP:192.168.1.10:32768 ---> INVITE sip:603@192.168.1.8;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.1.10:32768;branch=z9hG4bK-jiygkhqsx4bu;rport From: "Int - 601" ;tag=r1z9432e2w To: Call-ID: 545cc514ec33-ht8bthg8rdqw CSeq: 2 INVITE Max-Forwards: 70 Contact: ;reg-id=1 X-Serialnumber: 00041376E0BF P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom710/8.7.3.25.5 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, from-change Session-Expires: 3600;refresher=uas Min-SE: 90 Authorization: Digest username="601",realm="asterisk",nonce="1415365912/6362663456f9761c1961b956f451ba6a",uri="sip:603@192.168.1.8;user=phone",qop=auth,nc=00000001,cnonce="35b142d2",response="08ea8f6d49b9c3c5715c34e333c1180a",opaque="6fb1b2210c520b07",algorithm=MD5 Content-Type: application/sdp Content-Length: 487 v=0 o=root 1869386380 1869386380 IN IP4 192.168.1.10 s=call c=IN IP4 192.168.1.10 t=0 0 m=audio 62034 RTP/AVP 9 0 8 3 99 108 18 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:dzMJW4SpzYsvQxX0hRnTcgy7/iF077kl1KHZWwqc a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:99 G726-32/8000 a=rtpmap:108 AAL2-G726-32/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv [2014-11-07 14:11:52] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP response (316 bytes) to UDP:192.168.1.10:32768 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.10:32768;rport=32768;received=192.168.1.10;branch=z9hG4bK-jiygkhqsx4bu Call-ID: 545cc514ec33-ht8bthg8rdqw From: "Int - 601" ;tag=r1z9432e2w To: CSeq: 2 INVITE Server: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [603@from-internal:1] GotoIf("PJSIP/601-00000029", "1?ext-local,603,1") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Goto (ext-local,603,1) [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [603@ext-local:1] Set("PJSIP/601-00000029", "__RINGTIMER=15") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [603@ext-local:2] Macro("PJSIP/601-00000029", "exten-vm,novm,603,0,0,0") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-exten-vm:1] Macro("PJSIP/601-00000029", "user-callerid,") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/601-00000029", "TOUCH_MONITOR=1415365912.328") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/601-00000029", "AMPUSER=601") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("PJSIP/601-00000029", "0?report") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("PJSIP/601-00000029", "1?Set(REALCALLERIDNUM=601)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:5] Set("PJSIP/601-00000029", "AMPUSER=601") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("PJSIP/601-00000029", "0?limit") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:7] Set("PJSIP/601-00000029", "AMPUSERCIDNAME=Int - 601") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("PJSIP/601-00000029", "0?report") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:9] Set("PJSIP/601-00000029", "AMPUSERCID=601") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:10] Set("PJSIP/601-00000029", "__DIAL_OPTIONS=Ttr") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:11] Set("PJSIP/601-00000029", "CALLERID(all)="Int - 601" <601>") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:12] GotoIf("PJSIP/601-00000029", "0?limit") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:13] ExecIf("PJSIP/601-00000029", "0?Set(GROUP(concurrency_limit)=601)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:14] GosubIf("PJSIP/601-00000029", "7?sub-ccss,s,1(macro-exten-vm,)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-ccss:1] ExecIf("PJSIP/601-00000029", "0?Return()") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-ccss:2] Set("PJSIP/601-00000029", "CCSS_SETUP=TRUE") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-ccss:3] GosubIf("PJSIP/601-00000029", "0?monitor_config,1(macro-exten-vm,):monitor_default,1(macro-exten-vm,)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [monitor_default@sub-ccss:1] GotoIf("PJSIP/601-00000029", "0?is_exten") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [monitor_default@sub-ccss:2] StackPop("PJSIP/601-00000029", "") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [monitor_default@sub-ccss:3] Return("PJSIP/601-00000029", "FALSE") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:15] ExecIf("PJSIP/601-00000029", "1?Set(CHANNEL(language)=it)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:16] GotoIf("PJSIP/601-00000029", "0?continue") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:17] ExecIf("PJSIP/601-00000029", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:18] Set("PJSIP/601-00000029", "__TTL=64") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:19] GotoIf("PJSIP/601-00000029", "1?continue") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Goto (macro-user-callerid,s,30) [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:30] Set("PJSIP/601-00000029", "CALLERID(number)=601") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:31] Set("PJSIP/601-00000029", "CALLERID(name)=Int - 601") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:32] Set("PJSIP/601-00000029", "CDR(cnum)=601") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:33] Set("PJSIP/601-00000029", "CDR(cnam)=Int - 601") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-user-callerid:34] Set("PJSIP/601-00000029", "CHANNEL(language)=it") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-exten-vm:2] Set("PJSIP/601-00000029", "RingGroupMethod=none") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-exten-vm:3] Set("PJSIP/601-00000029", "__EXTTOCALL=603") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-exten-vm:4] Set("PJSIP/601-00000029", "__PICKUPMARK=603") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-exten-vm:5] Set("PJSIP/601-00000029", "RT=") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-exten-vm:6] Gosub("PJSIP/601-00000029", "sub-record-check,s,1(exten,603,)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:1] Set("PJSIP/601-00000029", "REC_POLICY_MODE_SAVE=") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:2] GotoIf("PJSIP/601-00000029", "1?check") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Goto (sub-record-check,s,7) [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:7] Set("PJSIP/601-00000029", "__MON_FMT=wav") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:8] GotoIf("PJSIP/601-00000029", "1?next") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Goto (sub-record-check,s,11) [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/601-00000029", "0?Return()") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:12] ExecIf("PJSIP/601-00000029", "0?Set(__REC_POLICY_MODE=)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:13] GotoIf("PJSIP/601-00000029", "0?exten,1") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:14] Set("PJSIP/601-00000029", "__REC_STATUS=INITIALIZED") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:15] Set("PJSIP/601-00000029", "NOW=1415365912") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:16] Set("PJSIP/601-00000029", "__DAY=07") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:17] Set("PJSIP/601-00000029", "__MONTH=11") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:18] Set("PJSIP/601-00000029", "__YEAR=2014") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:19] Set("PJSIP/601-00000029", "__TIMESTR=20141107-141152") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:20] Set("PJSIP/601-00000029", "__FROMEXTEN=601") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:21] Set("PJSIP/601-00000029", "__CALLFILENAME=exten-603-601-20141107-141152-1415365912.328") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-record-check:22] Goto("PJSIP/601-00000029", "exten,1") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Goto (sub-record-check,exten,1) [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [exten@sub-record-check:1] GotoIf("PJSIP/601-00000029", "0?callee") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [exten@sub-record-check:2] Set("PJSIP/601-00000029", "__REC_POLICY_MODE=dontcare") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [exten@sub-record-check:3] GotoIf("PJSIP/601-00000029", "1?caller") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Goto (sub-record-check,exten,10) [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [exten@sub-record-check:10] Set("PJSIP/601-00000029", "__REC_POLICY_MODE=dontcare") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [exten@sub-record-check:11] GosubIf("PJSIP/601-00000029", "0?record,1(exten,603,601)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [exten@sub-record-check:12] Return("PJSIP/601-00000029", "") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-exten-vm:7] GotoIf("PJSIP/601-00000029", "1?macrodial") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Goto (macro-exten-vm,s,13) [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-exten-vm:13] GosubIf("PJSIP/601-00000029", "0?clrheader,1()") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-exten-vm:14] Macro("PJSIP/601-00000029", "dial-one,,Ttr,603") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:1] Set("PJSIP/601-00000029", "DEXTEN=603") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:2] Set("PJSIP/601-00000029", "DIALSTATUS_CW=") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:3] GosubIf("PJSIP/601-00000029", "0?screen,1()") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:4] GosubIf("PJSIP/601-00000029", "0?cf,1()") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:5] GotoIf("PJSIP/601-00000029", "1?skip1") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Goto (macro-dial-one,s,8) [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:8] GotoIf("PJSIP/601-00000029", "0?nodial") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:9] GotoIf("PJSIP/601-00000029", "0?continue") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:10] Set("PJSIP/601-00000029", "EXTHASCW=ENABLED") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:11] GotoIf("PJSIP/601-00000029", "0?next1:cwinusebusy") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Goto (macro-dial-one,s,23) [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:23] GotoIf("PJSIP/601-00000029", "1?next3:continue") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Goto (macro-dial-one,s,24) [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:24] ExecIf("PJSIP/601-00000029", "0?Set(DIALSTATUS_CW=BUSY)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:25] GotoIf("PJSIP/601-00000029", "0?nodial") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:26] GosubIf("PJSIP/601-00000029", "1?dstring,1():dlocal,1()") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:1] Set("PJSIP/601-00000029", "DSTRING=") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:2] Set("PJSIP/601-00000029", "DEVICES=603") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf("PJSIP/601-00000029", "0?Return()") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf("PJSIP/601-00000029", "0?Set(DEVICES=03)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:5] Set("PJSIP/601-00000029", "LOOPCNT=1") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:6] Set("PJSIP/601-00000029", "ITER=1") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:7] Set("PJSIP/601-00000029", "THISDIAL=PJSIP/603") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:8] GosubIf("PJSIP/601-00000029", "1?zap2dahdi,1()") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [zap2dahdi@macro-dial-one:1] ExecIf("PJSIP/601-00000029", "0?Return()") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [zap2dahdi@macro-dial-one:2] Set("PJSIP/601-00000029", "NEWDIAL=") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [zap2dahdi@macro-dial-one:3] Set("PJSIP/601-00000029", "LOOPCNT2=1") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [zap2dahdi@macro-dial-one:4] Set("PJSIP/601-00000029", "ITER2=1") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [zap2dahdi@macro-dial-one:5] Set("PJSIP/601-00000029", "THISPART2=PJSIP/603") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [zap2dahdi@macro-dial-one:6] ExecIf("PJSIP/601-00000029", "0?Set(THISPART2=DAHDIIP/603)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [zap2dahdi@macro-dial-one:7] Set("PJSIP/601-00000029", "NEWDIAL=PJSIP/603&") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [zap2dahdi@macro-dial-one:8] Set("PJSIP/601-00000029", "ITER2=2") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [zap2dahdi@macro-dial-one:9] GotoIf("PJSIP/601-00000029", "0?begin2") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [zap2dahdi@macro-dial-one:10] Set("PJSIP/601-00000029", "THISDIAL=PJSIP/603") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [zap2dahdi@macro-dial-one:11] Return("PJSIP/601-00000029", "") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:9] GotoIf("PJSIP/601-00000029", "0?doset") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:10] NoOp("PJSIP/601-00000029", "Debug: Found PJSIP Destination PJSIP/603, updaing with PJSIP_DIAL_CONTACTS") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:11] Set("PJSIP/601-00000029", "THISDIAL=PJSIP/603/sip:603@192.168.1.9:5060;registering_acc=192_168_1_8") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:12] Set("PJSIP/601-00000029", "DSTRING=PJSIP/603/sip:603@192.168.1.9:5060;registering_acc=192_168_1_8&") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:13] Set("PJSIP/601-00000029", "ITER=2") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf("PJSIP/601-00000029", "0?begin") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:15] Set("PJSIP/601-00000029", "DSTRING=PJSIP/603/sip:603@192.168.1.9:5060;registering_acc=192_168_1_8") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [dstring@macro-dial-one:16] Return("PJSIP/601-00000029", "") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:27] GotoIf("PJSIP/601-00000029", "0?nodial") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:28] GotoIf("PJSIP/601-00000029", "0?skiptrace") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:29] GosubIf("PJSIP/601-00000029", "1?ctset,1():ctclear,1()") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [ctset@macro-dial-one:1] Set("PJSIP/601-00000029", "DB(CALLTRACE/603)=601") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [ctset@macro-dial-one:2] Return("PJSIP/601-00000029", "") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:30] Set("PJSIP/601-00000029", "D_OPTIONS=Ttr") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:31] ExecIf("PJSIP/601-00000029", "0?SIPAddHeader(Alert-Info: )") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:32] ExecIf("PJSIP/601-00000029", "0?SIPAddHeader()") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:33] ExecIf("PJSIP/601-00000029", "0?Set(CHANNEL(musicclass)=)") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:34] GosubIf("PJSIP/601-00000029", "0?qwait,1()") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:35] Set("PJSIP/601-00000029", "__CWIGNORE=") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:36] Set("PJSIP/601-00000029", "__KEEPCID=TRUE") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:37] GotoIf("PJSIP/601-00000029", "0?usegoto,1") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:38] GotoIf("PJSIP/601-00000029", "0?godial") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:39] Gosub("PJSIP/601-00000029", "sub-presencestate-display,s,1(603)") in new stack [2014-11-07 14:11:52] WARNING[7974][C-00000014] func_presencestate.c: PRESENCE_STATE unknown [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@sub-presencestate-display:1] Goto("PJSIP/601-00000029", "state-,1") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Goto (sub-presencestate-display,state-,1) [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [state-@sub-presencestate-display:1] Set("PJSIP/601-00000029", "PRESENCESTATE_DISPLAY=") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [state-@sub-presencestate-display:2] Return("PJSIP/601-00000029", "") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:40] Set("PJSIP/601-00000029", "CONNECTEDLINE(name,i)=Int - 603") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:41] Set("PJSIP/601-00000029", "CONNECTEDLINE(num)=603") in new stack [2014-11-07 14:11:52] VERBOSE[7517] res_pjsip_logger.c: <--- Transmitting SIP response (569 bytes) to UDP:192.168.1.10:32768 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.10:32768;rport=32768;received=192.168.1.10;branch=z9hG4bK-jiygkhqsx4bu Call-ID: 545cc514ec33-ht8bthg8rdqw From: "Int - 601" ;tag=r1z9432e2w To: ;tag=03e60059-d1c7-48e1-b26e-e4b14e87cd92 CSeq: 2 INVITE Server: FPBX-12.0.6(13.0.0) Contact: Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REFER, REGISTER, MESSAGE P-Asserted-Identity: "Int - 603" Content-Length: 0 [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:42] Set("PJSIP/601-00000029", "D_OPTIONS=TtrI") in new stack [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-dial-one:43] Dial("PJSIP/601-00000029", "PJSIP/603/sip:603@192.168.1.9:5060;registering_acc=192_168_1_8,,TtrI") in new stack [2014-11-07 14:11:52] VERBOSE[7517] res_pjsip_logger.c: <--- Transmitting SIP request (1026 bytes) to UDP:192.168.1.9:5060 ---> INVITE sip:603@192.168.1.9:5060;registering_acc=192_168_1_8 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.8:5060;rport;branch=z9hG4bKPj9b313e6d-f7f5-4f14-9a79-91f7364f28af From: "Int - 601" ;tag=25d0511a-e7b2-4ba4-9f71-c14ac8512675 To: Contact: Call-ID: 2469fb83-fdff-4b6c-a953-c8285f8d60e9 CSeq: 1075 INVITE Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REFER, REGISTER, MESSAGE Supported: 100rel, timer, replaces, norefersub Session-Expires: 1800 Min-SE: 90 P-Asserted-Identity: "Int - 601" Max-Forwards: 70 User-Agent: FPBX-12.0.6(13.0.0) Content-Type: application/sdp Content-Length: 233 v=0 o=- 401877098 401877098 IN IP4 192.168.1.8 s=Asterisk c=IN IP4 192.168.1.8 t=0 0 m=audio 19566 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] app_dial.c: Called PJSIP/603/sip:603@192.168.1.9:5060;registering_acc=192_168_1_8 [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] app_dial.c: Connected line update to PJSIP/601-00000029 prevented. [2014-11-07 14:11:52] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP response (569 bytes) to UDP:192.168.1.10:32768 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.10:32768;rport=32768;received=192.168.1.10;branch=z9hG4bK-jiygkhqsx4bu Call-ID: 545cc514ec33-ht8bthg8rdqw From: "Int - 601" ;tag=r1z9432e2w To: ;tag=03e60059-d1c7-48e1-b26e-e4b14e87cd92 CSeq: 2 INVITE Server: FPBX-12.0.6(13.0.0) Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REFER, REGISTER, MESSAGE P-Asserted-Identity: "Int - 603" Contact: Content-Length: 0 [2014-11-07 14:11:52] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP response (495 bytes) from UDP:192.168.1.9:5060 ---> SIP/2.0 180 Ringing To: ;tag=d7a09e7b Via: SIP/2.0/UDP 192.168.1.8:5060;rport=5060;branch=z9hG4bKPj9b313e6d-f7f5-4f14-9a79-91f7364f28af;received=192.168.1.8 CSeq: 1075 INVITE Call-ID: 2469fb83-fdff-4b6c-a953-c8285f8d60e9 From: "Int - 601" ;tag=25d0511a-e7b2-4ba4-9f71-c14ac8512675 Contact: "603" User-Agent: Jitsi2.5.5065Linux Content-Length: 0 [2014-11-07 14:11:52] VERBOSE[7974][C-00000014] app_dial.c: PJSIP/603-0000002a is ringing [2014-11-07 14:11:52] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP response (569 bytes) to UDP:192.168.1.10:32768 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.10:32768;rport=32768;received=192.168.1.10;branch=z9hG4bK-jiygkhqsx4bu Call-ID: 545cc514ec33-ht8bthg8rdqw From: "Int - 601" ;tag=r1z9432e2w To: ;tag=03e60059-d1c7-48e1-b26e-e4b14e87cd92 CSeq: 2 INVITE Server: FPBX-12.0.6(13.0.0) Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REFER, REGISTER, MESSAGE P-Asserted-Identity: "Int - 603" Contact: Content-Length: 0 [2014-11-07 14:11:53] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP response (495 bytes) from UDP:192.168.1.9:5060 ---> SIP/2.0 180 Ringing To: ;tag=d7a09e7b Via: SIP/2.0/UDP 192.168.1.8:5060;rport=5060;branch=z9hG4bKPj9b313e6d-f7f5-4f14-9a79-91f7364f28af;received=192.168.1.8 CSeq: 1075 INVITE Call-ID: 2469fb83-fdff-4b6c-a953-c8285f8d60e9 From: "Int - 601" ;tag=25d0511a-e7b2-4ba4-9f71-c14ac8512675 Contact: "603" User-Agent: Jitsi2.5.5065Linux Content-Length: 0 [2014-11-07 14:11:53] VERBOSE[7974][C-00000014] app_dial.c: PJSIP/603-0000002a is ringing [2014-11-07 14:11:54] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP response (495 bytes) from UDP:192.168.1.9:5060 ---> SIP/2.0 180 Ringing To: ;tag=d7a09e7b Via: SIP/2.0/UDP 192.168.1.8:5060;rport=5060;branch=z9hG4bKPj9b313e6d-f7f5-4f14-9a79-91f7364f28af;received=192.168.1.8 CSeq: 1075 INVITE Call-ID: 2469fb83-fdff-4b6c-a953-c8285f8d60e9 From: "Int - 601" ;tag=25d0511a-e7b2-4ba4-9f71-c14ac8512675 Contact: "603" User-Agent: Jitsi2.5.5065Linux Content-Length: 0 [2014-11-07 14:11:54] VERBOSE[7974][C-00000014] app_dial.c: PJSIP/603-0000002a is ringing [2014-11-07 14:11:56] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP response (495 bytes) from UDP:192.168.1.9:5060 ---> SIP/2.0 180 Ringing To: ;tag=d7a09e7b Via: SIP/2.0/UDP 192.168.1.8:5060;rport=5060;branch=z9hG4bKPj9b313e6d-f7f5-4f14-9a79-91f7364f28af;received=192.168.1.8 CSeq: 1075 INVITE Call-ID: 2469fb83-fdff-4b6c-a953-c8285f8d60e9 From: "Int - 601" ;tag=25d0511a-e7b2-4ba4-9f71-c14ac8512675 Contact: "603" User-Agent: Jitsi2.5.5065Linux Content-Length: 0 [2014-11-07 14:11:56] VERBOSE[7974][C-00000014] app_dial.c: PJSIP/603-0000002a is ringing [2014-11-07 14:11:56] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP response (677 bytes) from UDP:192.168.1.9:5060 ---> SIP/2.0 200 OK To: ;tag=d7a09e7b Via: SIP/2.0/UDP 192.168.1.8:5060;rport=5060;branch=z9hG4bKPj9b313e6d-f7f5-4f14-9a79-91f7364f28af;received=192.168.1.8 CSeq: 1075 INVITE Call-ID: 2469fb83-fdff-4b6c-a953-c8285f8d60e9 From: "Int - 601" ;tag=25d0511a-e7b2-4ba4-9f71-c14ac8512675 Contact: "603" User-Agent: Jitsi2.5.5065Linux Content-Type: application/sdp Content-Length: 154 v=0 o=603 0 0 IN IP4 192.168.1.9 s=- c=IN IP4 192.168.1.9 t=0 0 m=audio 5022 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 [2014-11-07 14:11:56] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP request (446 bytes) to UDP:192.168.1.9:5060 ---> ACK sip:603@192.168.1.9:5060;registering_acc=192_168_1_8 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.8:5060;rport;branch=z9hG4bKPj294ff68f-fecf-460b-9542-72444db4e38d From: "Int - 601" ;tag=25d0511a-e7b2-4ba4-9f71-c14ac8512675 To: ;tag=d7a09e7b Call-ID: 2469fb83-fdff-4b6c-a953-c8285f8d60e9 CSeq: 1075 ACK Max-Forwards: 70 User-Agent: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:11:56] VERBOSE[7974][C-00000014] app_dial.c: PJSIP/603-0000002a answered PJSIP/601-00000029 [2014-11-07 14:11:56] VERBOSE[7974][C-00000014] bridge_channel.c: Channel PJSIP/601-00000029 joined 'simple_bridge' basic-bridge <6aec0854-a9d8-4a55-93bb-1488d4a09809> [2014-11-07 14:11:56] VERBOSE[7517] res_pjsip_logger.c: <--- Transmitting SIP response (918 bytes) to UDP:192.168.1.10:32768 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.10:32768;rport=32768;received=192.168.1.10;branch=z9hG4bK-jiygkhqsx4bu Call-ID: 545cc514ec33-ht8bthg8rdqw From: "Int - 601" ;tag=r1z9432e2w To: ;tag=03e60059-d1c7-48e1-b26e-e4b14e87cd92 CSeq: 2 INVITE Server: FPBX-12.0.6(13.0.0) Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REFER, REGISTER, MESSAGE P-Asserted-Identity: "Int - 603" Contact: Supported: 100rel, timer, replaces, norefersub Session-Expires: 3600;refresher=uas Content-Type: application/sdp Content-Length: 235 v=0 o=- 1869386380 1869386382 IN IP4 192.168.1.8 s=Asterisk c=IN IP4 192.168.1.8 t=0 0 m=audio 19290 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [2014-11-07 14:11:56] VERBOSE[7975][C-00000014] bridge_channel.c: Channel PJSIP/603-0000002a joined 'simple_bridge' basic-bridge <6aec0854-a9d8-4a55-93bb-1488d4a09809> [2014-11-07 14:11:56] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (390 bytes) from UDP:192.168.1.10:32768 ---> ACK sip:192.168.1.8:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.10:32768;branch=z9hG4bK-ixklzi1jzcvw;rport From: "Int - 601" ;tag=r1z9432e2w To: ;tag=03e60059-d1c7-48e1-b26e-e4b14e87cd92 Call-ID: 545cc514ec33-ht8bthg8rdqw CSeq: 2 ACK Max-Forwards: 70 Contact: ;reg-id=1 Content-Length: 0 [2014-11-07 14:11:59] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (541 bytes) from UDP:192.168.1.9:5060 ---> OPTIONS sip:192.168.1.8 SIP/2.0 Call-ID: c76561a9dc36bcd639c2ac4709f2bfe9@0:0:0:0:0:0:0:0 CSeq: 210 OPTIONS From: "603" ;tag=1e4d13be To: "603" Via: SIP/2.0/UDP 192.168.1.9:5060;branch=z9hG4bK-333235-03948ab4114f55269e7cc1fb3bfb8698 Max-Forwards: 70 Contact: "603" User-Agent: Jitsi2.5.5065Linux Allow: INFO,OPTIONS,MESSAGE,BYE,REFER,SUBSCRIBE,ACK,CANCEL,PUBLISH,NOTIFY,INVITE Allow-Events: refer Content-Length: 0 [2014-11-07 14:11:59] VERBOSE[7517] res_pjsip_logger.c: <--- Transmitting SIP response (557 bytes) to UDP:192.168.1.9:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.9:5060;rport=5060;received=192.168.1.9;branch=z9hG4bK-333235-03948ab4114f55269e7cc1fb3bfb8698 Call-ID: c76561a9dc36bcd639c2ac4709f2bfe9@0:0:0:0:0:0:0:0 From: "603" ;tag=1e4d13be To: "603" ;tag=z9hG4bK-333235-03948ab4114f55269e7cc1fb3bfb8698 CSeq: 210 OPTIONS WWW-Authenticate: Digest realm="asterisk",nonce="1415365919/e1649c57bcdf90396df7cfef6e02c748",opaque="432e35e8715d7640",algorithm=md5,qop="auth" Server: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:12:01] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (1286 bytes) from UDP:192.168.1.10:32768 ---> INVITE sip:192.168.1.8:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.10:32768;branch=z9hG4bK-0123i682oulo;rport From: "Int - 601" ;tag=r1z9432e2w To: ;tag=03e60059-d1c7-48e1-b26e-e4b14e87cd92 Call-ID: 545cc514ec33-ht8bthg8rdqw CSeq: 3 INVITE Max-Forwards: 70 Contact: ;reg-id=1 X-Serialnumber: 00041376E0BF P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom710/8.7.3.25.5 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, from-change Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 487 v=0 o=root 1869386380 1869386381 IN IP4 192.168.1.10 s=call c=IN IP4 192.168.1.10 t=0 0 m=audio 62034 RTP/AVP 9 0 8 3 99 108 18 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:dzMJW4SpzYsvQxX0hRnTcgy7/iF077kl1KHZWwqc a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:99 G726-32/8000 a=rtpmap:108 AAL2-G726-32/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendonly [2014-11-07 14:12:01] VERBOSE[7975][C-00000014] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/603-0000002a' [2014-11-07 14:12:01] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP response (851 bytes) to UDP:192.168.1.10:32768 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.10:32768;rport=32768;received=192.168.1.10;branch=z9hG4bK-0123i682oulo Call-ID: 545cc514ec33-ht8bthg8rdqw From: "Int - 601" ;tag=r1z9432e2w To: ;tag=03e60059-d1c7-48e1-b26e-e4b14e87cd92 CSeq: 3 INVITE Session-Expires: 3600;refresher=uas Contact: Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REFER, REGISTER, MESSAGE Supported: 100rel, timer, replaces, norefersub Server: FPBX-12.0.6(13.0.0) Content-Type: application/sdp Content-Length: 235 v=0 o=- 1869386380 1869386383 IN IP4 192.168.1.8 s=Asterisk c=IN IP4 192.168.1.8 t=0 0 m=audio 19290 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=recvonly [2014-11-07 14:12:01] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (390 bytes) from UDP:192.168.1.10:32768 ---> ACK sip:192.168.1.8:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.10:32768;branch=z9hG4bK-q146rvmotp8l;rport From: "Int - 601" ;tag=r1z9432e2w To: ;tag=03e60059-d1c7-48e1-b26e-e4b14e87cd92 Call-ID: 545cc514ec33-ht8bthg8rdqw CSeq: 3 ACK Max-Forwards: 70 Contact: ;reg-id=1 Content-Length: 0 [2014-11-07 14:12:05] VERBOSE[5262] res_pjsip_logger.c: <--- Received SIP request (661 bytes) from UDP:192.168.1.10:32768 ---> REFER sip:5d3db432-12c8-4930-ab76-1fbe001262ac@192.168.1.8:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.10:32768;branch=z9hG4bK-igk8hoys35gx;rport From: ;tag=6dzn1go3x9 To: "Int - 602" ;tag=ed0be285-5224-422d-8854-0ce3d7a09e96 Call-ID: 4290917c-5ecd-4ea3-8dbf-d5e1388371ff CSeq: 2 REFER Max-Forwards: 70 Contact: ;reg-id=1 Refer-To: sip:603@192.168.1.8;user=phone?Replaces=545cc514ec33-ht8bthg8rdqw%3Bto-tag%3D03e60059-d1c7-48e1-b26e-e4b14e87cd92%3Bfrom-tag%3Dr1z9432e2w Referred-By: sip:601@192.168.1.8 User-Agent: snom710/8.7.3.25.5 Content-Length: 0 [2014-11-07 14:12:05] VERBOSE[5257] res_pjsip_logger.c: <--- Transmitting SIP response (376 bytes) to UDP:192.168.1.10:32768 ---> SIP/2.0 400 Bad Request Via: SIP/2.0/UDP 192.168.1.10:32768;rport=32768;received=192.168.1.10;branch=z9hG4bK-igk8hoys35gx Call-ID: 4290917c-5ecd-4ea3-8dbf-d5e1388371ff From: ;tag=6dzn1go3x9 To: "Int - 602" ;tag=ed0be285-5224-422d-8854-0ce3d7a09e96 CSeq: 2 REFER Server: FPBX-12.0.6(13.0.0) Content-Length: 0 [2014-11-07 14:12:21] VERBOSE[7972][C-00000013] res_musiconhold.c: Stopped music on hold on PJSIP/602-00000027 [2014-11-07 14:12:22] VERBOSE[7973][C-00000013] bridge_channel.c: Channel PJSIP/601-00000028 left 'simple_bridge' basic-bridge <23002f95-d3df-41e3-86a0-7edd5c1d59c3> [2014-11-07 14:12:22] VERBOSE[7972][C-00000013] bridge_channel.c: Channel PJSIP/602-00000027 left 'simple_bridge' basic-bridge <23002f95-d3df-41e3-86a0-7edd5c1d59c3> [2014-11-07 14:12:22] VERBOSE[7972][C-00000013] app_macro.c: Spawn extension (macro-dial-one, s, 43) exited non-zero on 'PJSIP/602-00000027' in macro 'dial-one' [2014-11-07 14:12:22] VERBOSE[7972][C-00000013] app_macro.c: Spawn extension (macro-exten-vm, s, 14) exited non-zero on 'PJSIP/602-00000027' in macro 'exten-vm' [2014-11-07 14:12:22] VERBOSE[7972][C-00000013] pbx.c: Spawn extension (ext-local, 601, 2) exited non-zero on 'PJSIP/602-00000027' [2014-11-07 14:12:22] VERBOSE[7972][C-00000013] pbx.c: Executing [h@ext-local:1] Macro("PJSIP/602-00000027", "hangupcall,") in new stack [2014-11-07 14:12:22] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("PJSIP/602-00000027", "1?theend") in new stack [2014-11-07 14:12:22] VERBOSE[7972][C-00000013] pbx.c: Goto (macro-hangupcall,s,3) [2014-11-07 14:12:22] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("PJSIP/602-00000027", "0?Set(CDR(recordingfile)=)") in new stack [2014-11-07 14:12:22] VERBOSE[7972][C-00000013] pbx.c: Executing [s@macro-hangupcall:4] Hangup("PJSIP/602-00000027", "") in new stack [2014-11-07 14:12:22] VERBOSE[7972][C-00000013] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'PJSIP/602-00000027' in macro 'hangupcall' [2014-11-07 14:12:22] VERBOSE[7972][C-00000013] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'PJSIP/602-00000027' [2014-11-07 14:12:24] VERBOSE[7975][C-00000014] res_musiconhold.c: Stopped music on hold on PJSIP/603-0000002a [2014-11-07 14:12:26] VERBOSE[7974][C-00000014] bridge_channel.c: Channel PJSIP/601-00000029 left 'simple_bridge' basic-bridge <6aec0854-a9d8-4a55-93bb-1488d4a09809> [2014-11-07 14:12:26] VERBOSE[7974][C-00000014] app_macro.c: Spawn extension (macro-dial-one, s, 43) exited non-zero on 'PJSIP/601-00000029' in macro 'dial-one' [2014-11-07 14:12:26] VERBOSE[7974][C-00000014] app_macro.c: Spawn extension (macro-exten-vm, s, 14) exited non-zero on 'PJSIP/601-00000029' in macro 'exten-vm' [2014-11-07 14:12:26] VERBOSE[7974][C-00000014] pbx.c: Spawn extension (ext-local, 603, 2) exited non-zero on 'PJSIP/601-00000029' [2014-11-07 14:12:26] VERBOSE[7974][C-00000014] pbx.c: Executing [h@ext-local:1] Macro("PJSIP/601-00000029", "hangupcall,") in new stack [2014-11-07 14:12:26] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("PJSIP/601-00000029", "1?theend") in new stack [2014-11-07 14:12:26] VERBOSE[7974][C-00000014] pbx.c: Goto (macro-hangupcall,s,3) [2014-11-07 14:12:26] VERBOSE[7975][C-00000014] bridge_channel.c: Channel PJSIP/603-0000002a left 'simple_bridge' basic-bridge <6aec0854-a9d8-4a55-93bb-1488d4a09809> [2014-11-07 14:12:26] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("PJSIP/601-00000029", "0?Set(CDR(recordingfile)=)") in new stack [2014-11-07 14:12:26] VERBOSE[7974][C-00000014] pbx.c: Executing [s@macro-hangupcall:4] Hangup("PJSIP/601-00000029", "") in new stack [2014-11-07 14:12:26] VERBOSE[7974][C-00000014] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'PJSIP/601-00000029' in macro 'hangupcall' [2014-11-07 14:12:26] VERBOSE[7974][C-00000014] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'PJSIP/601-00000029'