[Mar 7 09:31:57] VERBOSE[4894] loader.c: app_queue.so => (True Call Queueing) [Mar 7 09:31:57] VERBOSE[4894] asterisk.c: Asterisk Ready. [Mar 7 09:32:06] VERBOSE[4900] asterisk.c: -- Remote UNIX connection [Mar 7 09:32:18] VERBOSE[4911] netsock2.c: == Using SIP RTP TOS bits 184 [Mar 7 09:32:18] VERBOSE[4911] netsock2.c: == Using SIP RTP CoS mark 5 [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [1173@from-internal:1] Macro("SIP/1820-00000000", "user-callerid,SKIPTTL,") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/1820-00000000", "AMPUSER=1820") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/1820-00000000", "0?report") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/1820-00000000", "1?Set(REALCALLERIDNUM=1820)") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-user-callerid:4] Set("SIP/1820-00000000", "AMPUSER=1820") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/1820-00000000", "AMPUSERCIDNAME=Asterisk Test") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/1820-00000000", "0?report") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-user-callerid:7] Set("SIP/1820-00000000", "AMPUSERCID=1820") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-user-callerid:8] Set("SIP/1820-00000000", "CALLERID(all)="Asterisk Test" <1820>") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-user-callerid:9] GotoIf("SIP/1820-00000000", "1?continue") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Goto (macro-user-callerid,s,18) [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-user-callerid:18] Set("SIP/1820-00000000", "CALLERID(number)=1820") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-user-callerid:19] Set("SIP/1820-00000000", "CALLERID(name)=Asterisk Test") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-user-callerid:20] NoOp("SIP/1820-00000000", "Using CallerID "Asterisk Test" <1820>") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [1173@from-internal:2] NoOp("SIP/1820-00000000", "Calling Out Route: ToLync") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [1173@from-internal:3] Set("SIP/1820-00000000", "MOHCLASS=default") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [1173@from-internal:4] Set("SIP/1820-00000000", "_NODEST=") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [1173@from-internal:5] Macro("SIP/1820-00000000", "record-enable,1820,OUT,") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-record-enable:1] GotoIf("SIP/1820-00000000", "1?check") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Goto (macro-record-enable,s,4) [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-record-enable:4] ExecIf("SIP/1820-00000000", "0?MacroExit()") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-record-enable:5] GotoIf("SIP/1820-00000000", "0?Group:OUT") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Goto (macro-record-enable,s,15) [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-record-enable:15] GotoIf("SIP/1820-00000000", "0?IN") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-record-enable:16] ExecIf("SIP/1820-00000000", "1?MacroExit()") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [1173@from-internal:6] Macro("SIP/1820-00000000", "dialout-trunk,2,1173,") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:1] Set("SIP/1820-00000000", "DIAL_TRUNK=2") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/1820-00000000", "0?sub-pincheck,s,1") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/1820-00000000", "0?disabletrunk,1") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:4] Set("SIP/1820-00000000", "DIAL_NUMBER=1173") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:5] Set("SIP/1820-00000000", "DIAL_TRUNK_OPTIONS=tr") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:6] Set("SIP/1820-00000000", "OUTBOUND_GROUP=OUT_2") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/1820-00000000", "1?nomax") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Goto (macro-dialout-trunk,s,9) [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/1820-00000000", "0?skipoutcid") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:10] Set("SIP/1820-00000000", "DIAL_TRUNK_OPTIONS=") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:11] Macro("SIP/1820-00000000", "outbound-callerid,2") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/1820-00000000", "0?Set(CALLERPRES()=)") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/1820-00000000", "0?Set(REALCALLERIDNUM=1820)") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/1820-00000000", "1?normcid") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Goto (macro-outbound-callerid,s,6) [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-outbound-callerid:6] Set("SIP/1820-00000000", "USEROUTCID=") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-outbound-callerid:7] Set("SIP/1820-00000000", "EMERGENCYCID=") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-outbound-callerid:8] Set("SIP/1820-00000000", "TRUNKOUTCID=") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/1820-00000000", "1?trunkcid") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Goto (macro-outbound-callerid,s,12) [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-outbound-callerid:12] ExecIf("SIP/1820-00000000", "0?Set(CALLERID(all)=)") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-outbound-callerid:13] ExecIf("SIP/1820-00000000", "0?Set(CALLERID(all)=)") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/1820-00000000", "0?Set(CALLERID(all)=)") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-outbound-callerid:15] ExecIf("SIP/1820-00000000", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:12] GosubIf("SIP/1820-00000000", "0?sub-flp-2,s,1") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:13] Set("SIP/1820-00000000", "OUTNUM=1173") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:14] Set("SIP/1820-00000000", "custom=SIP/Lync") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/1820-00000000", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default))") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:16] Macro("SIP/1820-00000000", "dialout-trunk-predial-hook,") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/1820-00000000", "") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:17] GotoIf("SIP/1820-00000000", "0?bypass,1") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/1820-00000000", "0?customtrunk") in new stack [Mar 7 09:32:18] VERBOSE[4961] pbx.c: -- Executing [s@macro-dialout-trunk:19] Dial("SIP/1820-00000000", "SIP/Lync/1173,300,") in new stack [Mar 7 09:32:18] VERBOSE[4961] netsock2.c: == Using SIP RTP TOS bits 184 [Mar 7 09:32:18] VERBOSE[4961] netsock2.c: == Using SIP RTP CoS mark 5 [Mar 7 09:32:18] VERBOSE[4961] app_dial.c: -- Called Lync/1173 [Mar 7 09:32:20] VERBOSE[4961] app_dial.c: -- SIP/Lync-00000001 is ringing [Mar 7 09:32:20] VERBOSE[4961] app_dial.c: -- SIP/Lync-00000001 is ringing [Mar 7 09:32:20] VERBOSE[4961] app_dial.c: -- SIP/Lync-00000001 is ringing [Mar 7 09:32:20] VERBOSE[4961] app_dial.c: -- SIP/Lync-00000001 is ringing [Mar 7 09:32:21] VERBOSE[4961] app_dial.c: -- SIP/Lync-00000001 is ringing [Mar 7 09:32:22] VERBOSE[4961] app_dial.c: -- SIP/Lync-00000001 answered SIP/1820-00000000 [Mar 7 09:32:22] VERBOSE[4961] rtp_engine.c: -- Locally bridging SIP/1820-00000000 and SIP/Lync-00000001 [Mar 7 09:32:43] DEBUG[4961] res_rtp_asterisk.c: Got RTCP report of 176 bytes [Mar 7 09:32:43] DEBUG[4953] manager.c: Examining event: Event: RTCPReceived Privilege: reporting,all From 172.16.2.35:63467 PT: 200(Sender Report) ReceptionReports: 1 SenderSSRC: 0 FractionLost: 0 PacketsLost: 0 HighestSequence: 12070 SequenceNumberCycles: 0 IAJitter: 33 LastSR: 0.0000000000 DLSR: 0.0000(sec) [Mar 7 09:32:44] DEBUG[4911] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog 'YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM.' Method: ACK [Mar 7 09:32:44] DEBUG[4911] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '28ba006b47288d45414094342413525b@172.28.5.45:5060' Method: INVITE [Mar 7 09:32:44] DEBUG[4961] res_rtp_asterisk.c: Got RTCP report of 28 bytes [Mar 7 09:32:44] DEBUG[4961] res_rtp_asterisk.c: Got RTCP report of 188 bytes [Mar 7 09:32:44] DEBUG[4953] manager.c: Examining event: Event: RTCPReceived Privilege: reporting,all From 172.28.200.200:55679 PT: 200(Sender Report) ReceptionReports: 1 SenderSSRC: 0 FractionLost: 0 PacketsLost: 0 HighestSequence: 1128 SequenceNumberCycles: 0 IAJitter: 15 LastSR: 0.0000000000 DLSR: 0.0000(sec) [Mar 7 09:32:45] DEBUG[4911] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog 'YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM.' Method: ACK [Mar 7 09:32:45] DEBUG[4911] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '28ba006b47288d45414094342413525b@172.28.5.45:5060' Method: INVITE [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 0 [ 54]: INVITE sip:1820@172.28.5.45:5060;transport=TCP SIP/2.0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 1 [ 77]: FROM: ;epid=E5790B0758;tag=150c0a6d4 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 2 [ 41]: TO: ;tag=as32c704a0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 3 [ 14]: CSEQ: 1 INVITE [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 4 [ 58]: CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 5 [ 16]: MAX-FORWARDS: 70 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 6 [ 59]: VIA: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bK28e88b81 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 7 [107]: CONTACT: [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 8 [ 19]: CONTENT-LENGTH: 260 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 9 [ 16]: SUPPORTED: timer [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 10 [ 17]: SUPPORTED: 100rel [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 11 [ 40]: USER-AGENT: RTCC/4.0.0.0 MediationServer [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 12 [ 29]: CONTENT-TYPE: application/sdp [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 13 [ 21]: Session-Expires: 1800 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 14 [ 10]: Min-SE: 90 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 15 [ 0]: [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: <--- SIP read from TCP:172.28.200.200:5068 ---> INVITE sip:1820@172.28.5.45:5060;transport=TCP SIP/2.0 FROM: ;epid=E5790B0758;tag=150c0a6d4 TO: ;tag=as32c704a0 CSEQ: 1 INVITE CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 MAX-FORWARDS: 70 VIA: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bK28e88b81 CONTACT: CONTENT-LENGTH: 260 SUPPORTED: timer SUPPORTED: 100rel USER-AGENT: RTCC/4.0.0.0 MediationServer CONTENT-TYPE: application/sdp Session-Expires: 1800 Min-SE: 90 v=0 o=- 63 2 IN IP4 172.28.200.200 s=session c=IN IP4 172.28.200.200 b=CT:1000 t=0 0 m=audio 55678 RTP/AVP 0 101 c=IN IP4 172.28.200.200 a=rtcp:55679 a=label:Audio a=inactive a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 <-------------> [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 0 [ 54]: INVITE sip:1820@172.28.5.45:5060;transport=TCP SIP/2.0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 1 [ 77]: FROM: ;epid=E5790B0758;tag=150c0a6d4 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 2 [ 41]: TO: ;tag=as32c704a0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 3 [ 14]: CSEQ: 1 INVITE [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 4 [ 58]: CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 5 [ 16]: MAX-FORWARDS: 70 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 6 [ 59]: VIA: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bK28e88b81 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 7 [107]: CONTACT: [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 8 [ 19]: CONTENT-LENGTH: 260 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 9 [ 16]: SUPPORTED: timer [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 10 [ 17]: SUPPORTED: 100rel [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 11 [ 40]: USER-AGENT: RTCC/4.0.0.0 MediationServer [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 12 [ 29]: CONTENT-TYPE: application/sdp [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 13 [ 21]: Session-Expires: 1800 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 14 [ 10]: Min-SE: 90 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 15 [ 0]: [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 0 [ 3]: v=0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 1 [ 30]: o=- 63 2 IN IP4 172.28.200.200 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 2 [ 9]: s=session [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 3 [ 23]: c=IN IP4 172.28.200.200 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 4 [ 9]: b=CT:1000 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 5 [ 5]: t=0 0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 6 [ 27]: m=audio 55678 RTP/AVP 0 101 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 7 [ 23]: c=IN IP4 172.28.200.200 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 8 [ 12]: a=rtcp:55679 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 9 [ 13]: a=label:Audio [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 10 [ 10]: a=inactive [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 11 [ 20]: a=rtpmap:0 PCMU/8000 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 12 [ 33]: a=rtpmap:101 telephone-event/8000 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Body 13 [ 15]: a=fmtp:101 0-16 [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: --- (15 headers 14 lines) --- [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: = Looking for Call ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 (Checking From) --From tag 150c0a6d4 --To-tag as32c704a0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Mar 7 09:32:46] DEBUG[4962] sip/reqresp_parser.c: Begin: parsing SIP "Supported: timer" [Mar 7 09:32:46] DEBUG[4962] sip/reqresp_parser.c: Found SIP option: -timer- [Mar 7 09:32:46] DEBUG[4962] sip/reqresp_parser.c: Matched SIP option: timer [Mar 7 09:32:46] DEBUG[4962] netsock2.c: Splitting '172.28.200.200:5068' gives... [Mar 7 09:32:46] DEBUG[4962] netsock2.c: ...host '172.28.200.200' and port '5068'. [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: Sending to 172.28.200.200:5068 (no NAT) [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Initializing initreq for method INVITE - callid 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing session-level SDP o=- 63 2 IN IP4 172.28.200.200... UNSUPPORTED. [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing session-level SDP s=session... UNSUPPORTED. [Mar 7 09:32:46] DEBUG[4962] netsock2.c: Splitting '172.28.200.200' gives... [Mar 7 09:32:46] DEBUG[4962] netsock2.c: ...host '172.28.200.200' and port '(null)'. [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing session-level SDP c=IN IP4 172.28.200.200... OK. [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing session-level SDP b=CT:1000... UNSUPPORTED. [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: Found RTP audio format 0 [Mar 7 09:32:46] DEBUG[4962] rtp_engine.c: Setting payload 0 based on m type on 0x41f42f90 [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: Found RTP audio format 101 [Mar 7 09:32:46] DEBUG[4962] rtp_engine.c: Setting payload 101 based on m type on 0x41f42f90 [Mar 7 09:32:46] DEBUG[4962] netsock2.c: Splitting '172.28.200.200' gives... [Mar 7 09:32:46] DEBUG[4962] netsock2.c: ...host '172.28.200.200' and port '(null)'. [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing media-level (audio) SDP c=IN IP4 172.28.200.200... OK. [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing media-level (audio) SDP a=rtcp:55679... UNSUPPORTED. [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing media-level (audio) SDP a=label:Audio... UNSUPPORTED. [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing media-level (audio) SDP a=inactive... OK. [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: Found audio description format PCMU for ID 0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: Found audio description format telephone-event for ID 101 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED. [Mar 7 09:32:46] DEBUG[4962] rtp_engine.c: Incorporating payload 0 on 0x41f42f90 [Mar 7 09:32:46] DEBUG[4962] rtp_engine.c: Incorporating payload 101 on 0x41f42f90 [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw) [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Mar 7 09:32:46] DEBUG[4962] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x19aa3fc8' [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: Peer audio RTP is at port 172.28.200.200:55678 [Mar 7 09:32:46] DEBUG[4962] rtp_engine.c: Copying payload 0 from 0x41f42f90 to 0x19aa4190 [Mar 7 09:32:46] DEBUG[4962] rtp_engine.c: Copying payload 101 from 0x41f42f90 to 0x19aa4190 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: We have an owner, now see if we need to change this call [Mar 7 09:32:46] DEBUG[4962] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x19aa3fc8' [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Got a SIP re-invite for call 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Incoming INVITE with 'timer' option supported and "Session-Expires" header. [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Session-Expires: 1800 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Received Min-SE: 90 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Restarting session-timers on a refresh - 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Session timer stopped: -1 - 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Session timer started: 17 - 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: SIP/Lync-00000001: This call is UP.... [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: <--- Transmitting (no NAT) to 172.28.200.200:5068 ---> SIP/2.0 100 Trying Via: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bK28e88b81;received=172.28.200.200 From: ;epid=E5790B0758;tag=150c0a6d4 To: ;tag=as32c704a0 Call-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 CSeq: 1 INVITE Server: FPBX-2.8.1(1.8.309808) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Session-Expires: 1800;refresher=uas Contact: Content-Length: 0 <------------> [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Trying to put 'SIP/2.0 100' onto TCP socket destined for 172.28.200.200:5068 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Setting framing from config on incoming call [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: True Text flag: True [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: Audio is at 5060 [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: -- Done with adding codecs to SDP [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: <--- Reliably Transmitting (no NAT) to 172.28.200.200:5068 ---> SIP/2.0 200 OK Via: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bK28e88b81;received=172.28.200.200 From: ;epid=E5790B0758;tag=150c0a6d4 To: ;tag=as32c704a0 Call-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 CSeq: 1 INVITE Server: FPBX-2.8.1(1.8.309808) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Session-Expires: 1800;refresher=uas Contact: Content-Type: application/sdp Content-Length: 249 v=0 o=root 1724375099 1724375100 IN IP4 172.28.5.45 s=Asterisk PBX SVN-branch-1.8-r309808 c=IN IP4 172.28.5.45 t=0 0 m=audio 13984 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=inactive <------------> [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Trying to put 'SIP/2.0 200' onto TCP socket destined for 172.28.200.200:5068 [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: Setting the marker bit due to a source update [Mar 7 09:32:46] VERBOSE[4961] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/1820-00000000 [Mar 7 09:32:46] DEBUG[4961] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: Setting the marker bit due to a source update [Mar 7 09:32:46] DEBUG[4953] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Start Channel: SIP/1820-00000000 UniqueID: 1299508338.0 Class: default [Mar 7 09:32:46] DEBUG[4961] channel.c: Set channel SIP/1820-00000000 to write format slin [Mar 7 09:32:46] DEBUG[4961] res_musiconhold.c: SIP/1820-00000000 Opened file 0 '/var/lib/asterisk/mohmp3/TristeAlegriaPromo' [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4903] devicestate.c: No provider found, checking channel drivers for SIP - Lync [Mar 7 09:32:46] DEBUG[4903] chan_sip.c: Checking device state for peer Lync [Mar 7 09:32:46] DEBUG[4903] devicestate.c: Changing state for SIP/Lync - state 8 (On Hold) [Mar 7 09:32:46] DEBUG[4903] devicestate.c: device 'SIP/Lync' state '8' [Mar 7 09:32:46] DEBUG[4917] app_queue.c: Device 'SIP/Lync' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 0 [ 51]: ACK sip:1820@172.28.5.45:5060;transport=TCP SIP/2.0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 1 [ 77]: FROM: ;epid=E5790B0758;tag=150c0a6d4 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 2 [ 41]: TO: ;tag=as32c704a0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 3 [ 11]: CSEQ: 1 ACK [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 4 [ 58]: CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 5 [ 16]: MAX-FORWARDS: 70 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 6 [ 59]: VIA: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bK7f1ba34e [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 7 [ 17]: CONTENT-LENGTH: 0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 8 [ 40]: USER-AGENT: RTCC/4.0.0.0 MediationServer [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 9 [ 0]: [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: <--- SIP read from TCP:172.28.200.200:5068 ---> ACK sip:1820@172.28.5.45:5060;transport=TCP SIP/2.0 FROM: ;epid=E5790B0758;tag=150c0a6d4 TO: ;tag=as32c704a0 CSEQ: 1 ACK CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 MAX-FORWARDS: 70 VIA: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bK7f1ba34e CONTENT-LENGTH: 0 USER-AGENT: RTCC/4.0.0.0 MediationServer <-------------> [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 0 [ 51]: ACK sip:1820@172.28.5.45:5060;transport=TCP SIP/2.0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 1 [ 77]: FROM: ;epid=E5790B0758;tag=150c0a6d4 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 2 [ 41]: TO: ;tag=as32c704a0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 3 [ 11]: CSEQ: 1 ACK [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 4 [ 58]: CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 5 [ 16]: MAX-FORWARDS: 70 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 6 [ 59]: VIA: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bK7f1ba34e [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 7 [ 17]: CONTENT-LENGTH: 0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Header 8 [ 40]: USER-AGENT: RTCC/4.0.0.0 MediationServer [Mar 7 09:32:46] VERBOSE[4962] chan_sip.c: --- (9 headers 0 lines) --- [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: = Looking for Call ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 (Checking From) --From tag 150c0a6d4 --To-tag as32c704a0 [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Mar 7 09:32:46] DEBUG[4962] chan_sip.c: Stopping retransmission on '28ba006b47288d45414094342413525b@172.28.5.45:5060' of Response 1: Match Not Found [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:46] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Got RTCP report of 200 bytes [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:47] DEBUG[4953] manager.c: Examining event: Event: RTCPReceived Privilege: reporting,all From 172.16.2.35:63467 PT: 200(Sender Report) ReceptionReports: 2 SenderSSRC: 0 FractionLost: 0 PacketsLost: 0 HighestSequence: 5059 SequenceNumberCycles: 0 IAJitter: 2 LastSR: 0.0000000000 DLSR: 0.0000(sec) [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: No remote address on RTP instance '0x19aa3fc8' so dropping frame [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 0 [ 53]: REFER sip:1820@172.28.5.45:5060;transport=TCP SIP/2.0 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 1 [ 77]: FROM: ;epid=E5790B0758;tag=150c0a6d4 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 2 [ 41]: TO: ;tag=as32c704a0 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 3 [ 13]: CSEQ: 2 REFER [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 4 [ 58]: CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 5 [ 16]: MAX-FORWARDS: 70 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 6 [ 58]: VIA: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bK5d14dc6 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 7 [107]: CONTACT: [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 8 [ 17]: CONTENT-LENGTH: 0 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 9 [200]: REFER-TO: [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 10 [ 40]: USER-AGENT: RTCC/4.0.0.0 MediationServer [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 11 [ 0]: [Mar 7 09:32:47] VERBOSE[4962] chan_sip.c: <--- SIP read from TCP:172.28.200.200:5068 ---> REFER sip:1820@172.28.5.45:5060;transport=TCP SIP/2.0 FROM: ;epid=E5790B0758;tag=150c0a6d4 TO: ;tag=as32c704a0 CSEQ: 2 REFER CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 MAX-FORWARDS: 70 VIA: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bK5d14dc6 CONTACT: CONTENT-LENGTH: 0 REFER-TO: USER-AGENT: RTCC/4.0.0.0 MediationServer <-------------> [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 0 [ 53]: REFER sip:1820@172.28.5.45:5060;transport=TCP SIP/2.0 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 1 [ 77]: FROM: ;epid=E5790B0758;tag=150c0a6d4 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 2 [ 41]: TO: ;tag=as32c704a0 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 3 [ 13]: CSEQ: 2 REFER [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 4 [ 58]: CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 5 [ 16]: MAX-FORWARDS: 70 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 6 [ 58]: VIA: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bK5d14dc6 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 7 [107]: CONTACT: [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 8 [ 17]: CONTENT-LENGTH: 0 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 9 [200]: REFER-TO: [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 10 [ 40]: USER-AGENT: RTCC/4.0.0.0 MediationServer [Mar 7 09:32:47] VERBOSE[4962] chan_sip.c: --- (11 headers 0 lines) --- [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: = Looking for Call ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 (Checking From) --From tag 150c0a6d4 --To-tag as32c704a0 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: **** Received REFER (9) - Command in SIP REFER [Mar 7 09:32:47] VERBOSE[4962] chan_sip.c: Call 28ba006b47288d45414094342413525b@172.28.5.45:5060 got a SIP call transfer from caller: (REFER)! [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Attended transfer: Will use Replace-Call-ID : 21756586-526e-452e-ba52-d404e9d9781e F-tag: 2e1a693eca T-tag: 5f680762a0 [Mar 7 09:32:47] VERBOSE[4962] chan_sip.c: SIP transfer to extension FL000SLYN001.Network.Root:5068@from-internal-xfer by (null) [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: SIP attended transfer: Transferer channel SIP/Lync-00000001, transferee channel SIP/1820-00000000 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Got SIP transfer, applying to bridged peer 'SIP/1820-00000000' [Mar 7 09:32:47] VERBOSE[4962] chan_sip.c: <--- Transmitting (no NAT) to 172.28.200.200:5068 ---> SIP/2.0 202 Accepted Via: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bK5d14dc6;received=172.28.200.200 From: ;epid=E5790B0758;tag=150c0a6d4 To: ;tag=as32c704a0 Call-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 CSeq: 2 REFER Server: FPBX-2.8.1(1.8.309808) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Trying to put 'SIP/2.0 202' onto TCP socket destined for 172.28.200.200:5068 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Looking for callid 21756586-526e-452e-ba52-d404e9d9781e (fromtag 2e1a693eca totag 5f680762a0) [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Strict routing enforced for session 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:47] VERBOSE[4962] chan_sip.c: set_destination: Parsing for address/port to send to [Mar 7 09:32:47] DEBUG[4962] netsock2.c: Splitting 'FL000SLYN001.Network.Root:5068' gives... [Mar 7 09:32:47] DEBUG[4962] netsock2.c: ...host 'FL000SLYN001.Network.Root' and port '5068'. [Mar 7 09:32:47] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: SIPREFERRINGCONTEXT Value: from-internal Uniqueid: 1299508338.0 [Mar 7 09:32:47] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: SIPREFERREDBYHDR Value: Uniqueid: 1299508338.0 [Mar 7 09:32:47] DEBUG[4962] netsock2.c: Splitting '172.28.200.200' gives... [Mar 7 09:32:47] DEBUG[4962] netsock2.c: ...host '172.28.200.200' and port '(null)'. [Mar 7 09:32:47] VERBOSE[4962] chan_sip.c: set_destination: set destination to 172.28.200.200:5068 [Mar 7 09:32:47] VERBOSE[4962] chan_sip.c: Reliably Transmitting (no NAT) to 172.28.200.200:5068: NOTIFY sip:FL000SLYN001.Network.Root:5068;transport=Tcp;maddr=172.28.200.200 SIP/2.0 Via: SIP/2.0/TCP 172.28.5.45:5060;branch=z9hG4bK29d4bb2b Max-Forwards: 70 From: ;tag=as32c704a0 To: ;epid=E5790B0758;tag=150c0a6d4 Contact: Call-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 CSeq: 103 NOTIFY User-Agent: FPBX-2.8.1(1.8.309808) Event: refer;id=2 Subscription-state: terminated;reason=noresource Content-Type: message/sipfrag;version=2.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 49 SIP/2.0 481 Call leg/transaction does not exist --- [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Trying to put 'NOTIFY sip:' onto TCP socket destined for 172.28.200.200:5068 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: SIP message could not be handled, bad request: 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Setting the marker bit due to a source update [Mar 7 09:32:47] VERBOSE[4961] res_musiconhold.c: -- Stopped music on hold on SIP/1820-00000000 [Mar 7 09:32:47] DEBUG[4961] channel.c: Set channel SIP/1820-00000000 to write format ulaw [Mar 7 09:32:47] DEBUG[4961] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4953] manager.c: Examining event: Event: MusicOnHold Privilege: call,all State: Stop Channel: SIP/1820-00000000 UniqueID: 1299508338.0 [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 1 [ 43]: FROM: ;tag=as32c704a0 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 2 [ 75]: TO: ;tag=150c0a6d4;epid=E5790B0758 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 3 [ 16]: CSEQ: 103 NOTIFY [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 4 [ 58]: CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 5 [ 56]: VIA: SIP/2.0/TCP 172.28.5.45:5060;branch=z9hG4bK29d4bb2b [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 6 [ 17]: CONTENT-LENGTH: 0 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 7 [ 36]: SERVER: RTCC/4.0.0.0 MediationServer [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 8 [ 0]: [Mar 7 09:32:47] VERBOSE[4962] chan_sip.c: <--- SIP read from TCP:172.28.200.200:5068 ---> SIP/2.0 200 OK FROM: ;tag=as32c704a0 TO: ;tag=150c0a6d4;epid=E5790B0758 CSEQ: 103 NOTIFY CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 VIA: SIP/2.0/TCP 172.28.5.45:5060;branch=z9hG4bK29d4bb2b CONTENT-LENGTH: 0 SERVER: RTCC/4.0.0.0 MediationServer <-------------> [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 1 [ 43]: FROM: ;tag=as32c704a0 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 2 [ 75]: TO: ;tag=150c0a6d4;epid=E5790B0758 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 3 [ 16]: CSEQ: 103 NOTIFY [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 4 [ 58]: CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 5 [ 56]: VIA: SIP/2.0/TCP 172.28.5.45:5060;branch=z9hG4bK29d4bb2b [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 6 [ 17]: CONTENT-LENGTH: 0 [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Header 7 [ 36]: SERVER: RTCC/4.0.0.0 MediationServer [Mar 7 09:32:47] VERBOSE[4962] chan_sip.c: --- (8 headers 0 lines) --- [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: = Looking for Call ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 (Checking To) --From tag as32c704a0 --To-tag 150c0a6d4 [Mar 7 09:32:47] VERBOSE[4962] chan_sip.c: SIP Response message for INCOMING dialog NOTIFY arrived [Mar 7 09:32:47] DEBUG[4962] chan_sip.c: Got 200 OK on NOTIFY for transfer [Mar 7 09:32:47] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: ~HASH~SIP_CAUSE~SIP/Lync-00000001~ Value: SIP 200 OK Uniqueid: 1299508338.0 [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:47] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4911] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog 'YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM.' Method: ACK [Mar 7 09:32:48] DEBUG[4911] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '28ba006b47288d45414094342413525b@172.28.5.45:5060' Method: REFER [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Got RTCP report of 136 bytes [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:48] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4911] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog 'YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM.' Method: ACK [Mar 7 09:32:49] DEBUG[4911] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '28ba006b47288d45414094342413525b@172.28.5.45:5060' Method: REFER [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:49] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4911] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog 'YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM.' Method: ACK [Mar 7 09:32:50] DEBUG[4911] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '28ba006b47288d45414094342413525b@172.28.5.45:5060' Method: REFER [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Got RTCP report of 200 bytes [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: RTCPReceived Privilege: reporting,all From 172.16.2.35:63467 PT: 200(Sender Report) ReceptionReports: 2 SenderSSRC: 0 FractionLost: 0 PacketsLost: 0 HighestSequence: 5065 SequenceNumberCycles: 0 IAJitter: 4 LastSR: 0.0000000000 DLSR: 0.0000(sec) [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Got RTCP report of 76 bytes [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Remote address is null, most likely RTP has been stopped [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 0 [ 51]: BYE sip:1820@172.28.5.45:5060;transport=TCP SIP/2.0 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 1 [ 77]: FROM: ;epid=E5790B0758;tag=150c0a6d4 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 2 [ 41]: TO: ;tag=as32c704a0 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 3 [ 11]: CSEQ: 3 BYE [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 4 [ 58]: CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 5 [ 16]: MAX-FORWARDS: 70 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 6 [ 59]: VIA: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bKe9c527e1 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 7 [ 80]: CONTACT: [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 8 [ 17]: CONTENT-LENGTH: 0 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 9 [ 40]: USER-AGENT: RTCC/4.0.0.0 MediationServer [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 10 [ 0]: [Mar 7 09:32:50] VERBOSE[4962] chan_sip.c: <--- SIP read from TCP:172.28.200.200:5068 ---> BYE sip:1820@172.28.5.45:5060;transport=TCP SIP/2.0 FROM: ;epid=E5790B0758;tag=150c0a6d4 TO: ;tag=as32c704a0 CSEQ: 3 BYE CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 MAX-FORWARDS: 70 VIA: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bKe9c527e1 CONTACT: CONTENT-LENGTH: 0 USER-AGENT: RTCC/4.0.0.0 MediationServer <-------------> [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 0 [ 51]: BYE sip:1820@172.28.5.45:5060;transport=TCP SIP/2.0 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 1 [ 77]: FROM: ;epid=E5790B0758;tag=150c0a6d4 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 2 [ 41]: TO: ;tag=as32c704a0 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 3 [ 11]: CSEQ: 3 BYE [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 4 [ 58]: CALL-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 5 [ 16]: MAX-FORWARDS: 70 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 6 [ 59]: VIA: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bKe9c527e1 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 7 [ 80]: CONTACT: [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 8 [ 17]: CONTENT-LENGTH: 0 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Header 9 [ 40]: USER-AGENT: RTCC/4.0.0.0 MediationServer [Mar 7 09:32:50] VERBOSE[4962] chan_sip.c: --- (10 headers 0 lines) --- [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: = Looking for Call ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 (Checking From) --From tag 150c0a6d4 --To-tag as32c704a0 [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Initializing initreq for method BYE - callid 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:50] DEBUG[4962] netsock2.c: Splitting '172.28.200.200:5068' gives... [Mar 7 09:32:50] DEBUG[4962] netsock2.c: ...host '172.28.200.200' and port '5068'. [Mar 7 09:32:50] VERBOSE[4962] chan_sip.c: Sending to 172.28.200.200:5068 (no NAT) [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Setting SIP_ALREADYGONE on dialog 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:50] DEBUG[4962] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x19aa3fc8' [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Session timer stopped: -1 - 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:50] VERBOSE[4962] chan_sip.c: Scheduling destruction of SIP dialog '28ba006b47288d45414094342413525b@172.28.5.45:5060' in 32000 ms (Method: BYE) [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Received bye, issuing owner hangup [Mar 7 09:32:50] VERBOSE[4962] chan_sip.c: <--- Transmitting (no NAT) to 172.28.200.200:5068 ---> SIP/2.0 200 OK Via: SIP/2.0/TCP 172.28.200.200:5068;branch=z9hG4bKe9c527e1;received=172.28.200.200 From: ;epid=E5790B0758;tag=150c0a6d4 To: ;tag=as32c704a0 Call-ID: 28ba006b47288d45414094342413525b@172.28.5.45:5060 CSeq: 3 BYE Server: FPBX-2.8.1(1.8.309808) Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [Mar 7 09:32:50] DEBUG[4962] chan_sip.c: Trying to put 'SIP/2.0 200' onto TCP socket destined for 172.28.200.200:5068 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/Lync-00000001 Variable: RTPAUDIOQOS Value: ssrc=73041945;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000 Uniqueid: 1299508338.1 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOSBRIDGED Value: ssrc=73041945;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000 Uniqueid: 1299508338.0 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/Lync-00000001 Variable: RTPAUDIOQOSJITTER Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000; Uniqueid: 1299508338.1 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOSJITTERBRIDGED Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000; Uniqueid: 1299508338.0 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/Lync-00000001 Variable: RTPAUDIOQOSLOSS Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000; Uniqueid: 1299508338.1 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOSLOSSBRIDGED Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000; Uniqueid: 1299508338.0 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/Lync-00000001 Variable: RTPAUDIOQOSRTT Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000; Uniqueid: 1299508338.1 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOSRTTBRIDGED Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000; Uniqueid: 1299508338.0 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOS Value: ssrc=1907744397;themssrc=303656648;lp=0;rxjitter=0.000074;rxcount=55;txjitter=0.000000;txcount=55;rlp=0;rtt=0.000000 Uniqueid: 1299508338.0 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/Lync-00000001 Variable: RTPAUDIOQOSBRIDGED Value: ssrc=1907744397;themssrc=303656648;lp=0;rxjitter=0.000074;rxcount=55;txjitter=0.000000;txcount=55;rlp=0;rtt=0.000000 Uniqueid: 1299508338.1 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOSJITTER Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000; Uniqueid: 1299508338.0 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/Lync-00000001 Variable: RTPAUDIOQOSJITTERBRIDGED Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000; Uniqueid: 1299508338.1 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOSLOSS Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000; Uniqueid: 1299508338.0 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/Lync-00000001 Variable: RTPAUDIOQOSLOSSBRIDGED Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000; Uniqueid: 1299508338.1 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOSRTT Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000; Uniqueid: 1299508338.0 [Mar 7 09:32:50] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/Lync-00000001 Variable: RTPAUDIOQOSRTTBRIDGED Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000; Uniqueid: 1299508338.1 [Mar 7 09:32:50] DEBUG[4961] rtp_engine.c: rtp-engine-local-bridge: Ooh, got a hangup [Mar 7 09:32:50] DEBUG[4961] channel.c: Returning from native bridge, channels: SIP/1820-00000000, SIP/Lync-00000001 [Mar 7 09:32:50] DEBUG[4961] pbx.c: Launching 'Macro' [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Executing [h@macro-dialout-trunk:1] Macro("SIP/1820-00000000", "hangupcall,") in new stack [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'USE_CONFIRMATION' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'RINGGROUP_INDEX' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'CHANNEL' is 'SIP/1820-00000000' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'UNIQCHAN' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Expression result is '1' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Launching 'GotoIf' [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Executing [s@macro-hangupcall:1] GotoIf("SIP/1820-00000000", "1?skiprg") in new stack [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Goto (macro-hangupcall,s,4) [Mar 7 09:32:50] DEBUG[4961] app_macro.c: Executed application: GotoIf [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'BLKVM_BASE' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'BLKVM_BASE' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'CHANNEL' is 'SIP/1820-00000000' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'BLKVM_OVERRIDE' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Expression result is '1' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Launching 'GotoIf' [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Executing [s@macro-hangupcall:4] GotoIf("SIP/1820-00000000", "1?skipblkvm") in new stack [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Goto (macro-hangupcall,s,7) [Mar 7 09:32:50] DEBUG[4961] app_macro.c: Executed application: GotoIf [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'FMGRP' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'FMUNIQUE' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'CHANNEL' is 'SIP/1820-00000000' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'FMUNIQUE' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Expression result is '1' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Launching 'GotoIf' [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Executing [s@macro-hangupcall:7] GotoIf("SIP/1820-00000000", "1?theend") in new stack [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Goto (macro-hangupcall,s,9) [Mar 7 09:32:50] DEBUG[4961] app_macro.c: Executed application: GotoIf [Mar 7 09:32:50] DEBUG[4961] pbx.c: Launching 'Hangup' [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Executing [s@macro-hangupcall:9] Hangup("SIP/1820-00000000", "") in new stack [Mar 7 09:32:50] DEBUG[4961] app_macro.c: Spawn extension (macro-hangupcall,s,9) exited non-zero on 'SIP/1820-00000000' in macro 'hangupcall' [Mar 7 09:32:50] VERBOSE[4961] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/1820-00000000' in macro 'hangupcall' [Mar 7 09:32:50] DEBUG[4961] features.c: Spawn extension (macro-dialout-trunk,h,1) exited non-zero on 'SIP/1820-00000000' [Mar 7 09:32:50] VERBOSE[4961] features.c: == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on 'SIP/1820-00000000' [Mar 7 09:32:50] DEBUG[4961] channel.c: Hanging up channel 'SIP/Lync-00000001' [Mar 7 09:32:50] DEBUG[4961] chan_sip.c: Hangup call SIP/Lync-00000001, SIP callid 28ba006b47288d45414094342413525b@172.28.5.45:5060 [Mar 7 09:32:50] DEBUG[4961] chan_sip.c: update_call_counter(1173) - decrement call limit counter on hangup [Mar 7 09:32:50] DEBUG[4961] chan_sip.c: Updating call counter for outgoing call [Mar 7 09:32:50] DEBUG[4961] chan_sip.c: Call to peer 'Lync' removed from call limit 0 [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x19aa3fc8' [Mar 7 09:32:50] DEBUG[4961] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Mar 7 09:32:50] DEBUG[4961] app_macro.c: Spawn extension (macro-dialout-trunk,s,19) exited non-zero on 'SIP/1820-00000000' in macro 'dialout-trunk' [Mar 7 09:32:50] VERBOSE[4961] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on 'SIP/1820-00000000' in macro 'dialout-trunk' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Spawn extension (from-internal,1173,6) exited non-zero on 'SIP/1820-00000000' [Mar 7 09:32:50] VERBOSE[4961] pbx.c: == Spawn extension (from-internal, 1173, 6) exited non-zero on 'SIP/1820-00000000' [Mar 7 09:32:50] DEBUG[4961] channel.c: Soft-Hanging up channel 'SIP/1820-00000000' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Launching 'Macro' [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Executing [h@from-internal:1] Macro("SIP/1820-00000000", "hangupcall") in new stack [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'USE_CONFIRMATION' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'RINGGROUP_INDEX' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'CHANNEL' is 'SIP/1820-00000000' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'UNIQCHAN' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Expression result is '1' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Launching 'GotoIf' [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Executing [s@macro-hangupcall:1] GotoIf("SIP/1820-00000000", "1?skiprg") in new stack [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Goto (macro-hangupcall,s,4) [Mar 7 09:32:50] DEBUG[4961] app_macro.c: Executed application: GotoIf [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'BLKVM_BASE' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'BLKVM_BASE' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'CHANNEL' is 'SIP/1820-00000000' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'BLKVM_OVERRIDE' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Expression result is '1' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Launching 'GotoIf' [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Executing [s@macro-hangupcall:4] GotoIf("SIP/1820-00000000", "1?skipblkvm") in new stack [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Goto (macro-hangupcall,s,7) [Mar 7 09:32:50] DEBUG[4961] app_macro.c: Executed application: GotoIf [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'FMGRP' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'FMUNIQUE' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'CHANNEL' is 'SIP/1820-00000000' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Result of 'FMUNIQUE' is NULL [Mar 7 09:32:50] DEBUG[4961] pbx.c: Expression result is '1' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Launching 'GotoIf' [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Executing [s@macro-hangupcall:7] GotoIf("SIP/1820-00000000", "1?theend") in new stack [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Goto (macro-hangupcall,s,9) [Mar 7 09:32:50] DEBUG[4961] app_macro.c: Executed application: GotoIf [Mar 7 09:32:50] DEBUG[4961] pbx.c: Launching 'Hangup' [Mar 7 09:32:50] VERBOSE[4961] pbx.c: -- Executing [s@macro-hangupcall:9] Hangup("SIP/1820-00000000", "") in new stack [Mar 7 09:32:50] DEBUG[4961] app_macro.c: Spawn extension (macro-hangupcall,s,9) exited non-zero on 'SIP/1820-00000000' in macro 'hangupcall' [Mar 7 09:32:50] VERBOSE[4961] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/1820-00000000' in macro 'hangupcall' [Mar 7 09:32:50] DEBUG[4961] pbx.c: Spawn extension (from-internal,h,1) exited non-zero on 'SIP/1820-00000000' [Mar 7 09:32:50] VERBOSE[4961] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/1820-00000000' [Mar 7 09:32:50] DEBUG[4961] channel.c: Hanging up channel 'SIP/1820-00000000' [Mar 7 09:32:50] DEBUG[4961] chan_sip.c: Hangup call SIP/1820-00000000, SIP callid YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM. [Mar 7 09:32:50] DEBUG[4961] chan_sip.c: update_call_counter(1820) - decrement call limit counter on hangup [Mar 7 09:32:50] DEBUG[4961] chan_sip.c: Updating call counter for incoming call [Mar 7 09:32:50] DEBUG[4961] chan_sip.c: Call from peer '1820' removed from call limit 2147483647 [Mar 7 09:32:50] DEBUG[4961] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x19a9df78' [Mar 7 09:32:50] VERBOSE[4961] chan_sip.c: Scheduling destruction of SIP dialog 'YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM.' in 6400 ms (Method: ACK) [Mar 7 09:32:50] DEBUG[4961] chan_sip.c: Strict routing enforced for session YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM. [Mar 7 09:32:50] VERBOSE[4961] chan_sip.c: set_destination: Parsing for address/port to send to [Mar 7 09:32:50] DEBUG[4961] netsock2.c: Splitting '172.16.2.35:41232' gives... [Mar 7 09:32:50] DEBUG[4961] netsock2.c: ...host '172.16.2.35' and port '41232'. [Mar 7 09:32:50] VERBOSE[4961] chan_sip.c: set_destination: set destination to 172.16.2.35:41232 [Mar 7 09:32:50] VERBOSE[4961] chan_sip.c: Reliably Transmitting (NAT) to 172.16.2.35:41232: BYE sip:1820@172.16.2.35:41232 SIP/2.0 Via: SIP/2.0/UDP 172.28.5.45:5060;branch=z9hG4bK5b0d07b8;rport Max-Forwards: 70 From: "1173";tag=as4e8c975d To: "Louis Asterisk";tag=743a7f13 Call-ID: YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM. CSeq: 102 BYE User-Agent: FPBX-2.8.1(1.8.309808) Proxy-Authorization: Digest username="1820", realm="asterisk", algorithm=MD5, uri="172.26.0.155", nonce="", response="5a243540a7803864bd5d9b9858764c61" X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 --- [Mar 7 09:32:50] DEBUG[4961] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #21 [Mar 7 09:32:50] DEBUG[4961] chan_sip.c: Trying to put 'BYE sip:182' onto UDP socket destined for 172.16.2.35:41232 [Mar 7 09:32:51] VERBOSE[4911] chan_sip.c: <--- SIP read from UDP:172.16.2.35:41232 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.28.5.45:5060;branch=z9hG4bK5b0d07b8;rport=5060 Contact: To: "Louis Asterisk";tag=743a7f13 From: "1173";tag=as4e8c975d Call-ID: YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM. CSeq: 102 BYE User-Agent: X-Lite 4 release 4.0 stamp 58832 Content-Length: 0 <-------------> [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: Header 1 [ 67]: Via: SIP/2.0/UDP 172.28.5.45:5060;branch=z9hG4bK5b0d07b8;rport=5060 [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: Header 2 [ 37]: Contact: [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: Header 3 [ 55]: To: "Louis Asterisk";tag=743a7f13 [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: Header 4 [ 50]: From: "1173";tag=as4e8c975d [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: Header 5 [ 53]: Call-ID: YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM. [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: Header 6 [ 13]: CSeq: 102 BYE [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: Header 7 [ 44]: User-Agent: X-Lite 4 release 4.0 stamp 58832 [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Mar 7 09:32:51] VERBOSE[4911] chan_sip.c: --- (9 headers 0 lines) --- [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: = Looking for Call ID: YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM. (Checking To) --From tag as4e8c975d --To-tag 743a7f13 [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #21 [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: Stopping retransmission on 'YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM.' of Request 102: Match Found [Mar 7 09:32:51] VERBOSE[4911] chan_sip.c: SIP Response message for INCOMING dialog BYE arrived [Mar 7 09:32:51] DEBUG[4911] chan_sip.c: Destroying SIP dialog YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM. [Mar 7 09:32:51] VERBOSE[4911] chan_sip.c: Really destroying SIP dialog 'YzhlZjRiNTUwZjkwNTFiNWRmODIxYjc3NTQ3ZjkxMTM.' Method: ACK [Mar 7 09:32:51] DEBUG[4911] rtp_engine.c: Destroyed RTP instance '0x19a9df78' [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Unlink Privilege: call,all Channel1: SIP/1820-00000000 Channel2: SIP/Lync-00000001 Uniqueid1: 1299508338.0 Uniqueid2: 1299508338.1 CallerID1: 1820 CallerID2: 1173 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: ANSWEREDTIME Value: 28 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: DIALEDTIME Value: 32 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: SIP/1820-00000000 Context: macro-dialout-trunk Extension: h Priority: 1 Application: Macro AppData: hangupcall, Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_IN_HANGUP Value: 1 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_EXTEN Value: h Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_CONTEXT Value: macro-dialout-trunk Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_PRIORITY Value: 1 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: ARG1 Value: Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: SIP/1820-00000000 Context: macro-hangupcall Extension: s Priority: 1 Application: GotoIf AppData: 1?skiprg Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: SIP/1820-00000000 Context: macro-hangupcall Extension: s Priority: 4 Application: GotoIf AppData: 1?skipblkvm Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: SIP/1820-00000000 Context: macro-hangupcall Extension: s Priority: 7 Application: GotoIf AppData: 1?theend Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 2 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: SIP/1820-00000000 Context: macro-hangupcall Extension: s Priority: 9 Application: Hangup AppData: Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: ARG1 Value: 2 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_EXTEN Value: 1173 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_CONTEXT Value: from-internal Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_PRIORITY Value: 6 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: SIP/Lync-00000001 Uniqueid: 1299508338.1 CallerIDNum: 1173 CallerIDName: Cause: 16 Cause-txt: Normal Clearing [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: DIALSTATUS Value: ANSWER Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Dial Privilege: call,all SubEvent: End Channel: SIP/1820-00000000 UniqueID: 1299508338.0 DialStatus: ANSWER [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 0 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: SIP/1820-00000000 Context: from-internal Extension: h Priority: 1 Application: Macro AppData: hangupcall Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_IN_HANGUP Value: 1 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_EXTEN Value: h Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_CONTEXT Value: from-internal Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_PRIORITY Value: 1 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: SIP/1820-00000000 Context: macro-hangupcall Extension: s Priority: 1 Application: GotoIf AppData: 1?skiprg Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: SIP/1820-00000000 Context: macro-hangupcall Extension: s Priority: 4 Application: GotoIf AppData: 1?skipblkvm Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: SIP/1820-00000000 Context: macro-hangupcall Extension: s Priority: 7 Application: GotoIf AppData: 1?theend Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 1 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: SIP/1820-00000000 Context: macro-hangupcall Extension: s Priority: 9 Application: Hangup AppData: Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: MACRO_DEPTH Value: 0 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOS Value: ssrc=1907744397;themssrc=303656648;lp=0;rxjitter=0.000074;rxcount=55;txjitter=0.000000;txcount=55;rlp=0;rtt=0.000000 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOSJITTER Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000; Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOSLOSS Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000; Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOSRTT Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000; Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: SIP/1820-00000000 Variable: RTPAUDIOQOS Value: ssrc=1907744397;themssrc=303656648;lp=0;rxjitter=0.000074;rxcount=55;txjitter=0.000000;txcount=55;rlp=0;rtt=0.000000 Uniqueid: 1299508338.0 [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: SIP/1820-00000000 Uniqueid: 1299508338.0 CallerIDNum: 1820 CallerIDName: Asterisk Test Cause: 16 Cause-txt: Normal Clearing [Mar 7 09:32:51] DEBUG[4903] devicestate.c: No provider found, checking channel drivers for SIP - Lync [Mar 7 09:32:51] DEBUG[4903] chan_sip.c: Checking device state for peer Lync [Mar 7 09:32:51] DEBUG[4903] devicestate.c: Changing state for SIP/Lync - state 1 (Not in use) [Mar 7 09:32:51] DEBUG[4903] devicestate.c: device 'SIP/Lync' state '1' [Mar 7 09:32:51] DEBUG[4903] devicestate.c: No provider found, checking channel drivers for SIP - Lync [Mar 7 09:32:51] DEBUG[4903] chan_sip.c: Checking device state for peer Lync [Mar 7 09:32:51] DEBUG[4903] devicestate.c: Changing state for SIP/Lync - state 1 (Not in use) [Mar 7 09:32:51] DEBUG[4903] devicestate.c: device 'SIP/Lync' state '1' [Mar 7 09:32:51] DEBUG[4903] devicestate.c: No provider found, checking channel drivers for SIP - Lync [Mar 7 09:32:51] DEBUG[4903] chan_sip.c: Checking device state for peer Lync [Mar 7 09:32:51] DEBUG[4903] devicestate.c: Changing state for SIP/Lync - state 1 (Not in use) [Mar 7 09:32:51] DEBUG[4903] devicestate.c: device 'SIP/Lync' state '1' [Mar 7 09:32:51] DEBUG[4903] devicestate.c: No provider found, checking channel drivers for SIP - 1820 [Mar 7 09:32:51] DEBUG[4903] chan_sip.c: Checking device state for peer 1820 [Mar 7 09:32:51] DEBUG[4903] devicestate.c: Changing state for SIP/1820 - state 1 (Not in use) [Mar 7 09:32:51] DEBUG[4903] devicestate.c: device 'SIP/1820' state '1' [Mar 7 09:32:51] DEBUG[4903] devicestate.c: No provider found, checking channel drivers for SIP - 1820 [Mar 7 09:32:51] DEBUG[4903] chan_sip.c: Checking device state for peer 1820 [Mar 7 09:32:51] DEBUG[4903] devicestate.c: Changing state for SIP/1820 - state 1 (Not in use) [Mar 7 09:32:51] DEBUG[4903] devicestate.c: device 'SIP/1820' state '1' [Mar 7 09:32:51] DEBUG[4953] manager.c: Examining event: Event: ExtensionStatus Privilege: call,all Exten: 1820 Context: ext-local Hint: SIP/1820 Status: 0 [Mar 7 09:32:51] DEBUG[4904] app_queue.c: Extension '1820@ext-local' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 7 09:32:51] DEBUG[4917] app_queue.c: Device 'SIP/Lync' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 7 09:32:51] DEBUG[4917] app_queue.c: Device 'SIP/Lync' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 7 09:32:51] DEBUG[4917] app_queue.c: Device 'SIP/Lync' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 7 09:32:51] DEBUG[4917] app_queue.c: Device 'SIP/1820' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 7 09:32:51] DEBUG[4917] app_queue.c: Device 'SIP/1820' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 7 09:32:56] DEBUG[4911] chan_sip.c: Allocating new SIP dialog for 282bb89a0385f82b4e673bb92367a5b5@127.0.0.1:0 - OPTIONS (No RTP) [Mar 7 09:32:56] DEBUG[4911] acl.c: For destination '172.16.2.35', our source address is '172.28.5.45'. [Mar 7 09:32:56] DEBUG[4911] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 172.28.5.45:5060 [Mar 7 09:32:56] DEBUG[4911] chan_sip.c: Initializing initreq for method OPTIONS - callid 3e216a1f6b80a7b52bfd81e63ea00c0a@172.28.5.45:5060 [Mar 7 09:32:56] DEBUG[4911] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.16.2.35:41232 [Mar 7 09:32:56] DEBUG[4911] chan_sip.c: = Looking for Call ID: 3e216a1f6b80a7b52bfd81e63ea00c0a@172.28.5.45:5060 (Checking To) --From tag as5b29c840 --To-tag b863cd97 [Mar 7 09:32:56] DEBUG[4911] chan_sip.c: Stopping retransmission on '3e216a1f6b80a7b52bfd81e63ea00c0a@172.28.5.45:5060' of Request 102: Match Found [Mar 7 09:32:56] DEBUG[4911] chan_sip.c: Destroying SIP dialog 3e216a1f6b80a7b52bfd81e63ea00c0a@172.28.5.45:5060 [Mar 7 09:32:58] VERBOSE[4960] asterisk.c: -- Remote UNIX connection disconnected