[Jan 10 16:25:58] DEBUG[15080] xmldoc.c: Cannot find variable 'description' in tree 'SIPPEER' [Jan 10 16:25:58] DEBUG[15080] xmldoc.c: Cannot find variable 'description' in tree 'SIPCHANINFO' [Jan 10 16:25:58] DEBUG[15080] xmldoc.c: Cannot find variable 'description' in tree 'MEETME_INFO' [Jan 10 16:26:21] DEBUG[15282] manager.c: Running action 'Challenge' [Jan 10 16:26:21] DEBUG[15282] manager.c: Running action 'Login' [Jan 10 16:26:21] DEBUG[15282] manager.c: Running action 'Command' [Jan 10 16:26:22] DEBUG[15283] manager.c: Running action 'Challenge' [Jan 10 16:26:22] DEBUG[15283] manager.c: Running action 'Login' [Jan 10 16:26:22] DEBUG[15283] manager.c: Running action 'Command' [Jan 10 16:26:22] DEBUG[15283] manager.c: Running action 'SIPpeers' [Jan 10 16:26:22] DEBUG[15283] manager.c: Running action 'Command' [Jan 10 16:26:23] DEBUG[15086] chan_sip.c: Header 0 [ 0]: [Jan 10 16:26:30] DEBUG[15086] chan_sip.c: Auto destroying SIP dialog '01064d3f28eb715f2e562f0c099bd282@77.888.999.888:5060' [Jan 10 16:26:30] DEBUG[15086] chan_sip.c: Destroying SIP dialog 01064d3f28eb715f2e562f0c099bd282@77.888.999.888:5060 [Jan 10 16:26:30] DEBUG[15086] chan_sip.c: Auto destroying SIP dialog '623b60ea26969c82538eb8766914195c@192.168.13.1' [Jan 10 16:26:30] DEBUG[15086] chan_sip.c: Destroying SIP dialog 623b60ea26969c82538eb8766914195c@192.168.13.1 [Jan 10 16:26:30] DEBUG[15086] chan_sip.c: Auto destroying SIP dialog '730d59f341507a810c1bb41023c166e3@99.888.777.66:5060' [Jan 10 16:26:30] DEBUG[15086] chan_sip.c: Destroying SIP dialog 730d59f341507a810c1bb41023c166e3@99.888.777.66:5060 [Jan 10 16:26:30] DEBUG[15086] chan_sip.c: Auto destroying SIP dialog '6fe6fc194a05625b3e0aa30014e5e61c@192.168.13.1' [Jan 10 16:26:30] DEBUG[15086] chan_sip.c: Destroying SIP dialog 6fe6fc194a05625b3e0aa30014e5e61c@192.168.13.1 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 0 [ 40]: INVITE sip:226@192.168.13.1:5060 SIP/2.0 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 1 [ 61]: Via: SIP/2.0/UDP 192.168.13.115:5062;branch=z9hG4bK1839201812 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 2 [ 58]: From: "tiptel-ip280" ;tag=2140902273 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 3 [ 26]: To: [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 4 [ 19]: Call-ID: 1215291252 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 5 [ 14]: CSeq: 1 INVITE [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 6 [ 38]: Contact: [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 7 [ 29]: Content-Type: application/sdp [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 8 [115]: Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 10 [ 49]: User-Agent: Tiptel IP 280 9.70.13.16 00156522c75f [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 11 [ 19]: Supported: replaces [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 12 [ 51]: Allow-Events: talk,hold,conference,refer,check-sync [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 13 [ 19]: Content-Length: 310 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 14 [ 0]: [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 0 [ 3]: v=0 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 1 [ 37]: o=- 20012 20012 IN IP4 192.168.13.115 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 2 [ 10]: s=SDP data [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.13.115 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 4 [ 5]: t=0 0 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 5 [ 34]: m=audio 11784 RTP/AVP 0 8 18 9 101 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 8 [ 21]: a=rtpmap:18 G729/8000 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 9 [ 19]: a=fmtp:18 annexb=no [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 10 [ 20]: a=rtpmap:9 G722/8000 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 11 [ 15]: a=fmtp:101 0-15 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 12 [ 33]: a=rtpmap:101 telephone-event/8000 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 13 [ 10]: a=ptime:20 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 14 [ 10]: a=sendrecv [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: = Looking for Call ID: 1215291252 (Checking From) --From tag 2140902273 --To-tag [Jan 10 16:26:50] DEBUG[15086] acl.c: For destination '192.168.13.115', our source address is '192.168.13.1'. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.13.1:5060 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Allocating new SIP dialog for 1215291252 - INVITE (No RTP) [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Jan 10 16:26:50] DEBUG[15086] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces" [Jan 10 16:26:50] DEBUG[15086] sip/reqresp_parser.c: Found SIP option: -replaces- [Jan 10 16:26:50] DEBUG[15086] sip/reqresp_parser.c: Matched SIP option: replaces [Jan 10 16:26:50] DEBUG[15086] netsock2.c: Splitting '192.168.13.115:5062' into... [Jan 10 16:26:50] DEBUG[15086] netsock2.c: ...host '192.168.13.115' and port '5062'. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Initializing initreq for method INVITE - callid 1215291252 [Jan 10 16:26:50] DEBUG[15086] netsock2.c: Splitting '192.168.13.1' into... [Jan 10 16:26:50] DEBUG[15086] netsock2.c: ...host '192.168.13.1' and port ''. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #35 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.13.115:5062 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 0 [ 37]: ACK sip:226@192.168.13.1:5060 SIP/2.0 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 1 [ 61]: Via: SIP/2.0/UDP 192.168.13.115:5062;branch=z9hG4bK1839201812 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 2 [ 58]: From: "tiptel-ip280" ;tag=2140902273 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 3 [ 41]: To: ;tag=as07050d03 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 4 [ 19]: Call-ID: 1215291252 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 5 [ 11]: CSeq: 1 ACK [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: = Looking for Call ID: 1215291252 (Checking From) --From tag 2140902273 --To-tag as07050d03 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #35 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Stopping retransmission on '1215291252' of Response 1: Match Found [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 0 [ 40]: INVITE sip:226@192.168.13.1:5060 SIP/2.0 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 1 [ 60]: Via: SIP/2.0/UDP 192.168.13.115:5062;branch=z9hG4bK775226874 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 2 [ 58]: From: "tiptel-ip280" ;tag=2140902273 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 3 [ 26]: To: [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 4 [ 19]: Call-ID: 1215291252 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 5 [ 14]: CSeq: 2 INVITE [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 6 [ 38]: Contact: [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 7 [165]: Authorization: Digest username="228", realm="asterisk", nonce="2315ebe7", uri="sip:226@192.168.13.1:5060", response="d7179969fc1d2d12dac0239916be9094", algorithm=MD5 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 8 [ 29]: Content-Type: application/sdp [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 9 [115]: Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 10 [ 16]: Max-Forwards: 70 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 11 [ 49]: User-Agent: Tiptel IP 280 9.70.13.16 00156522c75f [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 12 [ 19]: Supported: replaces [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 13 [ 51]: Allow-Events: talk,hold,conference,refer,check-sync [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 14 [ 19]: Content-Length: 310 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 15 [ 0]: [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 0 [ 3]: v=0 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 1 [ 37]: o=- 20012 20012 IN IP4 192.168.13.115 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 2 [ 10]: s=SDP data [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.13.115 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 4 [ 5]: t=0 0 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 5 [ 34]: m=audio 11784 RTP/AVP 0 8 18 9 101 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 8 [ 21]: a=rtpmap:18 G729/8000 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 9 [ 19]: a=fmtp:18 annexb=no [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 10 [ 20]: a=rtpmap:9 G722/8000 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 11 [ 15]: a=fmtp:101 0-15 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 12 [ 33]: a=rtpmap:101 telephone-event/8000 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 13 [ 10]: a=ptime:20 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Body 14 [ 10]: a=sendrecv [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: = Looking for Call ID: 1215291252 (Checking From) --From tag 2140902273 --To-tag [Jan 10 16:26:50] DEBUG[15086] netsock2.c: Splitting '192.168.13.1:5060' into... [Jan 10 16:26:50] DEBUG[15086] netsock2.c: ...host '192.168.13.1' and port '5060'. [Jan 10 16:26:50] DEBUG[15086] netsock2.c: Splitting '192.168.13.1:5060' into... [Jan 10 16:26:50] DEBUG[15086] netsock2.c: ...host '192.168.13.1' and port '5060'. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Jan 10 16:26:50] DEBUG[15086] netsock2.c: Splitting '192.168.13.115:5062' into... [Jan 10 16:26:50] DEBUG[15086] netsock2.c: ...host '192.168.13.115' and port '5062'. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Initializing initreq for method INVITE - callid 1215291252 [Jan 10 16:26:50] DEBUG[15086] netsock2.c: Splitting '192.168.13.1' into... [Jan 10 16:26:50] DEBUG[15086] netsock2.c: ...host '192.168.13.1' and port ''. [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x10050a8' [Jan 10 16:26:50] DEBUG[15086] res_rtp_asterisk.c: Allocated port 12954 for RTP instance '0x10050a8' [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: RTP instance '0x10050a8' is setup and ready to go [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f7ffc0b78e8' [Jan 10 16:26:50] DEBUG[15086] res_rtp_asterisk.c: Allocated port 12622 for RTP instance '0x7f7ffc0b78e8' [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: RTP instance '0x7f7ffc0b78e8' is setup and ready to go [Jan 10 16:26:50] DEBUG[15086] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f7ffc0b78e8' [Jan 10 16:26:50] DEBUG[15086] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x10050a8' [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Setting NAT on RTP to Off [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Setting NAT on VRTP to Off [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing session-level SDP o=- 20012 20012 IN IP4 192.168.13.115... OK. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing session-level SDP s=SDP data... UNSUPPORTED OR FAILED. [Jan 10 16:26:50] DEBUG[15086] netsock2.c: Splitting '192.168.13.115' into... [Jan 10 16:26:50] DEBUG[15086] netsock2.c: ...host '192.168.13.115' and port ''. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.13.115... OK. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Setting payload 0 based on m type on 0x7f8003d2e030 [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Setting payload 8 based on m type on 0x7f8003d2e030 [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Setting payload 18 based on m type on 0x7f8003d2e030 [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Setting payload 9 based on m type on 0x7f8003d2e030 [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Setting payload 101 based on m type on 0x7f8003d2e030 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED OR FAILED. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Incorporating payload 0 on 0x7f8003d2e030 [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Incorporating payload 8 on 0x7f8003d2e030 [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Incorporating payload 9 on 0x7f8003d2e030 [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Incorporating payload 18 on 0x7f8003d2e030 [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Incorporating payload 101 on 0x7f8003d2e030 [Jan 10 16:26:50] DEBUG[15086] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x10050a8' [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Copying payload 0 from 0x7f8003d2e030 to 0x1005270 [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Copying payload 8 from 0x7f8003d2e030 to 0x1005270 [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Copying payload 9 from 0x7f8003d2e030 to 0x1005270 [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Copying payload 18 from 0x7f8003d2e030 to 0x1005270 [Jan 10 16:26:50] DEBUG[15086] rtp_engine.c: Copying payload 101 from 0x7f8003d2e030 to 0x1005270 [Jan 10 16:26:50] DEBUG[15086] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x10050a8' [Jan 10 16:26:50] DEBUG[15086] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f7ffc0b78e8' [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Checking SIP call limits for device 228 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Updating call counter for incoming call [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Call from peer '228' is 1 out of 2 [Jan 10 16:26:50] DEBUG[15086] netsock2.c: Splitting '192.168.13.1:5060' into... [Jan 10 16:26:50] DEBUG[15086] netsock2.c: ...host '192.168.13.1' and port ''. [Jan 10 16:26:50] DEBUG[15086] netsock2.c: Splitting '192.168.13.1' into... [Jan 10 16:26:50] DEBUG[15086] netsock2.c: ...host '192.168.13.1' and port ''. [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: *** Our native formats are 0x8 (alaw) [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: *** Our capabilities are 0x28000a (gsm|alaw|h263|h264) [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: This channel can handle video! HOLLYWOOD next! [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: build_route: Contact hop: [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: SIP/228-00000000: New call is still down.... Trying... [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.13.115:5062 [Jan 10 16:26:50] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 228 [Jan 10 16:26:50] DEBUG[15088] chan_sip.c: Checking device state for peer 228 [Jan 10 16:26:50] DEBUG[15088] devicestate.c: Changing state for SIP/228 - state 2 (In use) [Jan 10 16:26:50] DEBUG[15088] devicestate.c: device 'SIP/228' state '2' [Jan 10 16:26:50] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 228 [Jan 10 16:26:50] DEBUG[15088] chan_sip.c: Checking device state for peer 228 [Jan 10 16:26:50] DEBUG[15088] devicestate.c: Changing state for SIP/228 - state 2 (In use) [Jan 10 16:26:50] DEBUG[15088] devicestate.c: device 'SIP/228' state '2' [Jan 10 16:26:50] DEBUG[15097] app_queue.c: Device 'SIP/228' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jan 10 16:26:50] DEBUG[15097] app_queue.c: Device 'SIP/228' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jan 10 16:26:50] DEBUG[15289] pbx.c: Launching 'Dial' [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Asked to create a SIP channel with formats: 0x8 (alaw) [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Allocating new SIP dialog for 76f48c844d6e9691403734b35ee347b6@192.168.13.1:5060 - INVITE (No RTP) [Jan 10 16:26:50] DEBUG[15289] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xfff148' [Jan 10 16:26:50] DEBUG[15289] res_rtp_asterisk.c: Allocated port 12784 for RTP instance '0xfff148' [Jan 10 16:26:50] DEBUG[15289] rtp_engine.c: RTP instance '0xfff148' is setup and ready to go [Jan 10 16:26:50] DEBUG[15289] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x100b468' [Jan 10 16:26:50] DEBUG[15289] res_rtp_asterisk.c: Allocated port 12762 for RTP instance '0x100b468' [Jan 10 16:26:50] DEBUG[15289] rtp_engine.c: RTP instance '0x100b468' is setup and ready to go [Jan 10 16:26:50] DEBUG[15289] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x100b468' [Jan 10 16:26:50] DEBUG[15289] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xfff148' [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Setting NAT on RTP to Off [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Setting NAT on VRTP to Off [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Jan 10 16:26:50] DEBUG[15289] acl.c: For destination '192.168.13.113', our source address is '192.168.13.1'. [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.13.1:5060 [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: SIP call-id changed from '76f48c844d6e9691403734b35ee347b6@192.168.13.1:5060' to '6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060' [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: *** Our native formats are 0x8 (alaw) [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: *** Our capabilities are 0x28000a (gsm|alaw|h263|h264) [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: *** Our preferred formats from the incoming channel are 0x8 (alaw) [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: This channel can handle video! HOLLYWOOD next! [Jan 10 16:26:50] DEBUG[15289] rtp_engine.c: Seeded SDP of 'SIP/226-00000001' with that of 'SIP/228-00000000' [Jan 10 16:26:50] DEBUG[15289] channel.c: Not copying variable DIALEDTIME. [Jan 10 16:26:50] DEBUG[15289] channel.c: Not copying variable ANSWEREDTIME. [Jan 10 16:26:50] DEBUG[15289] channel.c: Not copying variable DIALEDPEERNAME. [Jan 10 16:26:50] DEBUG[15289] channel.c: Not copying variable DIALEDPEERNUMBER. [Jan 10 16:26:50] DEBUG[15289] channel.c: Not copying variable DIALSTATUS. [Jan 10 16:26:50] DEBUG[15289] channel.c: Not copying variable SIPCALLID. [Jan 10 16:26:50] DEBUG[15289] channel.c: Not copying variable SIPDOMAIN. [Jan 10 16:26:50] DEBUG[15289] channel.c: Not copying variable SIPURI. [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Outgoing Call for 226 [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Updating call counter for outgoing call [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Call to peer '226' is 1 out of 2 [Jan 10 16:26:50] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 226 [Jan 10 16:26:50] DEBUG[15088] chan_sip.c: Checking device state for peer 226 [Jan 10 16:26:50] DEBUG[15088] devicestate.c: Changing state for SIP/226 - state 6 (Ringing) [Jan 10 16:26:50] DEBUG[15088] devicestate.c: device 'SIP/226' state '6' [Jan 10 16:26:50] DEBUG[15097] app_queue.c: Device 'SIP/226' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: This call needs video offers! [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: ** Our capability: 0x28000a (gsm|alaw|h263|h264) Video flag: False Text flag: False [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: -- Done with adding codecs to SDP [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Done building SDP. Settling with this capability: 0x28000a (gsm|alaw|h263|h264) [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Initializing initreq for method INVITE - callid 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 0 [ 42]: INVITE sip:226@192.168.13.113:5062 SIP/2.0 [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK4cc92578 [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 3 [ 58]: From: "tiptel-ip280" ;tag=as08287b1f [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 4 [ 33]: To: [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 5 [ 36]: Contact: [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 6 [ 59]: Call-ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 8 [ 18]: User-Agent: PBX [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 9 [ 35]: Date: Fri, 10 Jan 2014 15:26:50 GMT [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #38 [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.13.113:5062 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK4cc92578 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 2 [ 58]: From: "tiptel-ip280" ;tag=as08287b1f [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 3 [ 33]: To: [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 4 [ 59]: Call-ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 6 [ 38]: User-Agent: Yealink SIP-T20P 9.70.13.9 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: = Looking for Call ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 (Checking To) --From tag as08287b1f --To-tag [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: *** SIP TIMER: Cancelling retransmission #38 - INVITE (got response) [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060' Request 102: Found [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: SIP response 100 to standard invite [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK4cc92578 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 2 [ 58]: From: "tiptel-ip280" ;tag=as08287b1f [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 3 [ 48]: To: ;tag=1844667989 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 4 [ 59]: Call-ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 6 [ 38]: Contact: [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 7 [115]: Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 8 [ 38]: User-Agent: Yealink SIP-T20P 9.70.13.9 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 9 [ 51]: Allow-Events: talk,hold,conference,refer,check-sync [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: = Looking for Call ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 (Checking To) --From tag as08287b1f --To-tag 1844667989 [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060' Request 102: Found [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: SIP response 180 to standard invite [Jan 10 16:26:50] DEBUG[15086] chan_sip.c: build_route: Contact hop: [Jan 10 16:26:50] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 226 [Jan 10 16:26:50] DEBUG[15088] chan_sip.c: Checking device state for peer 226 [Jan 10 16:26:50] DEBUG[15088] devicestate.c: Changing state for SIP/226 - state 6 (Ringing) [Jan 10 16:26:50] DEBUG[15088] devicestate.c: device 'SIP/226' state '6' [Jan 10 16:26:50] DEBUG[15097] app_queue.c: Device 'SIP/226' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Jan 10 16:26:50] DEBUG[15289] rtp_engine.c: Setting early bridge SDP of 'SIP/228-00000000' with that of 'SIP/226-00000001' [Jan 10 16:26:50] DEBUG[15289] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 192.168.13.115:5062 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK4cc92578 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 2 [ 58]: From: "tiptel-ip280" ;tag=as08287b1f [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 3 [ 48]: To: ;tag=1844667989 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 4 [ 59]: Call-ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 6 [ 38]: Contact: [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 7 [ 29]: Content-Type: application/sdp [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 8 [115]: Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 9 [ 38]: User-Agent: Yealink SIP-T20P 9.70.13.9 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 10 [ 19]: Content-Length: 297 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 11 [ 0]: [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 0 [ 3]: v=0 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 1 [ 37]: o=- 20009 20009 IN IP4 192.168.13.113 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 2 [ 10]: s=SDP data [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.13.113 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 4 [ 5]: t=0 0 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 5 [ 26]: m=audio 11794 RTP/AVP 8 96 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 7 [ 10]: a=sendrecv [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 8 [ 10]: a=ptime:20 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 9 [ 14]: a=fmtp:96 0-15 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 10 [ 32]: a=rtpmap:96 telephone-event/8000 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 11 [ 23]: m=video 0 RTP/AVP 34 99 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 12 [ 22]: a=rtpmap:34 H263/90000 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 13 [ 22]: a=rtpmap:99 H264/90000 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Body 14 [ 10]: a=sendrecv [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: = Looking for Call ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 (Checking To) --From tag as08287b1f --To-tag 1844667989 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Acked pending invite 102 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Stopping retransmission on '6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060' of Request 102: Match Found [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: SIP response 200 to standard invite [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Processing session-level SDP o=- 20009 20009 IN IP4 192.168.13.113... OK. [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Processing session-level SDP s=SDP data... UNSUPPORTED OR FAILED. [Jan 10 16:26:52] DEBUG[15086] netsock2.c: Splitting '192.168.13.113' into... [Jan 10 16:26:52] DEBUG[15086] netsock2.c: ...host '192.168.13.113' and port ''. [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.13.113... OK. [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Jan 10 16:26:52] DEBUG[15086] rtp_engine.c: Setting payload 8 based on m type on 0x7f8003d2e9f0 [Jan 10 16:26:52] DEBUG[15086] rtp_engine.c: Setting payload 96 based on m type on 0x7f8003d2e9f0 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=fmtp:96 0-15... UNSUPPORTED OR FAILED. [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:96 telephone-event/8000... OK. [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Ignoring video media offer because port number is zero [Jan 10 16:26:52] DEBUG[15086] rtp_engine.c: Incorporating payload 8 on 0x7f8003d2e9f0 [Jan 10 16:26:52] DEBUG[15086] rtp_engine.c: Incorporating payload 96 on 0x7f8003d2e9f0 [Jan 10 16:26:52] DEBUG[15086] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xfff148' [Jan 10 16:26:52] DEBUG[15086] rtp_engine.c: Copying payload 8 from 0x7f8003d2e9f0 to 0xfff310 [Jan 10 16:26:52] DEBUG[15086] rtp_engine.c: Copying payload 96 from 0x7f8003d2e9f0 to 0xfff310 [Jan 10 16:26:52] DEBUG[15086] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0xfff148' [Jan 10 16:26:52] DEBUG[15086] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x100b468' [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: We have an owner, now see if we need to change this call [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Updating call counter for outgoing call [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: build_route: Contact hop: [Jan 10 16:26:52] DEBUG[15086] netsock2.c: Splitting '192.168.13.113:5062' into... [Jan 10 16:26:52] DEBUG[15086] netsock2.c: ...host '192.168.13.113' and port '5062'. [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Strict routing enforced for session 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:26:52] DEBUG[15086] netsock2.c: Splitting '192.168.13.113:5062' into... [Jan 10 16:26:52] DEBUG[15086] netsock2.c: ...host '192.168.13.113' and port '5062'. [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Trying to put 'ACK sip:226' onto UDP socket destined for 192.168.13.113:5062 [Jan 10 16:26:52] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 226 [Jan 10 16:26:52] DEBUG[15088] chan_sip.c: Checking device state for peer 226 [Jan 10 16:26:52] DEBUG[15088] devicestate.c: Changing state for SIP/226 - state 2 (In use) [Jan 10 16:26:52] DEBUG[15088] devicestate.c: device 'SIP/226' state '2' [Jan 10 16:26:52] DEBUG[15097] app_queue.c: Device 'SIP/226' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jan 10 16:26:52] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 226 [Jan 10 16:26:52] DEBUG[15088] chan_sip.c: Checking device state for peer 226 [Jan 10 16:26:52] DEBUG[15088] devicestate.c: Changing state for SIP/226 - state 2 (In use) [Jan 10 16:26:52] DEBUG[15088] devicestate.c: device 'SIP/226' state '2' [Jan 10 16:26:52] DEBUG[15097] app_queue.c: Device 'SIP/226' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jan 10 16:26:52] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 228 [Jan 10 16:26:52] DEBUG[15088] chan_sip.c: Checking device state for peer 228 [Jan 10 16:26:52] DEBUG[15088] devicestate.c: Changing state for SIP/228 - state 2 (In use) [Jan 10 16:26:52] DEBUG[15088] devicestate.c: device 'SIP/228' state '2' [Jan 10 16:26:52] DEBUG[15097] app_queue.c: Device 'SIP/228' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jan 10 16:26:52] DEBUG[15289] chan_sip.c: SIP answering channel: SIP/228-00000000 [Jan 10 16:26:52] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:52] DEBUG[15289] chan_sip.c: Setting framing from config on incoming call [Jan 10 16:26:52] DEBUG[15289] chan_sip.c: ** Our capability: 0x8 (alaw) Video flag: True Text flag: True [Jan 10 16:26:52] DEBUG[15289] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Jan 10 16:26:52] DEBUG[15289] chan_sip.c: -- Done with adding codecs to SDP [Jan 10 16:26:52] DEBUG[15289] chan_sip.c: Done building SDP. Settling with this capability: 0x8 (alaw) [Jan 10 16:26:52] DEBUG[15289] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #41 [Jan 10 16:26:52] DEBUG[15289] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.13.115:5062 [Jan 10 16:26:52] DEBUG[15289] features.c: bridge answer set, chan answer set [Jan 10 16:26:52] DEBUG[15289] features.c: Removing dialed interfaces datastore on SIP/226-00000001 since we're bridging [Jan 10 16:26:52] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:52] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 0 [ 37]: ACK sip:226@192.168.13.1:5060 SIP/2.0 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.13.115:5062;branch=z9hG4bK65665391 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 2 [ 58]: From: "tiptel-ip280" ;tag=2140902273 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 3 [ 41]: To: ;tag=as46d06b94 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 4 [ 19]: Call-ID: 1215291252 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 5 [ 11]: CSeq: 2 ACK [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 6 [ 38]: Contact: [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 8 [ 49]: User-Agent: Tiptel IP 280 9.70.13.16 00156522c75f [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: = Looking for Call ID: 1215291252 (Checking From) --From tag 2140902273 --To-tag as46d06b94 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #41 [Jan 10 16:26:52] DEBUG[15086] chan_sip.c: Stopping retransmission on '1215291252' of Response 2: Match Found [Jan 10 16:26:52] DEBUG[15289] res_rtp_asterisk.c: Ooh, format changed from unknown to alaw [Jan 10 16:26:52] DEBUG[15289] res_rtp_asterisk.c: Created smoother: format: alaw ms: 20 len: 160 [Jan 10 16:26:52] DEBUG[15289] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0xfff148' [Jan 10 16:26:52] DEBUG[15289] res_rtp_asterisk.c: Ooh, format changed from unknown to alaw [Jan 10 16:26:52] DEBUG[15289] res_rtp_asterisk.c: Created smoother: format: alaw ms: 20 len: 160 [Jan 10 16:26:53] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Jan 10 16:26:53] DEBUG[15289] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 42 (*), at 192.168.13.113:11794 [Jan 10 16:26:53] DEBUG[15289] channel.c: Got DTMF begin on channel (SIP/226-00000001) [Jan 10 16:26:53] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:53] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:53] DEBUG[15289] channel.c: Bridge stops bridging channels SIP/228-00000000 and SIP/226-00000001 [Jan 10 16:26:53] DEBUG[15289] features.c: Not passing DTMF through, since it may be a feature code [Jan 10 16:26:53] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:53] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:53] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Jan 10 16:26:53] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Jan 10 16:26:53] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Jan 10 16:26:53] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Creating END DTMF Frame: 42 (*), at 192.168.13.113:11794 [Jan 10 16:26:54] DEBUG[15289] channel.c: Got DTMF end on channel (SIP/226-00000001) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:54] DEBUG[15289] channel.c: Bridge stops bridging channels SIP/228-00000000 and SIP/226-00000001 [Jan 10 16:26:54] DEBUG[15289] features.c: Feature interpret: chan=SIP/228-00000000, peer=SIP/226-00000001, code=*, sense=2, features=18, dynamic=# [Jan 10 16:26:54] DEBUG[15289] features.c: Set feature timer to 6000 ms [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 51 (3), at 192.168.13.113:11794 [Jan 10 16:26:54] DEBUG[15289] channel.c: Got DTMF begin on channel (SIP/226-00000001) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:54] DEBUG[15289] channel.c: Bridge stops bridging channels SIP/228-00000000 and SIP/226-00000001 [Jan 10 16:26:54] DEBUG[15289] features.c: Not passing DTMF through, since it may be a feature code [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Creating END DTMF Frame: 51 (3), at 192.168.13.113:11794 [Jan 10 16:26:54] DEBUG[15289] channel.c: Got DTMF end on channel (SIP/226-00000001) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:54] DEBUG[15289] channel.c: Bridge stops bridging channels SIP/228-00000000 and SIP/226-00000001 [Jan 10 16:26:54] DEBUG[15289] features.c: Feature interpret: chan=SIP/228-00000000, peer=SIP/226-00000001, code=*3, sense=2, features=18, dynamic=# [Jan 10 16:26:54] DEBUG[15289] features.c: Feature detected: fname=Attended Transfer sname=atxfer exten=*3 [Jan 10 16:26:54] DEBUG[15289] features.c: Executing Attended Transfer SIP/228-00000000, SIP/226-00000001 (sense=2) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:54] DEBUG[15289] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jan 10 16:26:54] DEBUG[15289] channel.c: Set channel SIP/226-00000001 to write format slin [Jan 10 16:26:54] DEBUG[15289] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jan 10 16:26:54] DEBUG[15291] channel.c: Set channel SIP/228-00000000 to write format slin [Jan 10 16:26:54] DEBUG[15291] res_musiconhold.c: SIP/228-00000000 Opened file 5 '/var/lib/asterisk/moh//You_look_good_in_orange' [Jan 10 16:26:54] DEBUG[15291] res_rtp_asterisk.c: Difference is 1296, ms is 182 [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Jan 10 16:26:54] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Jan 10 16:26:55] DEBUG[15289] channel.c: Scheduling timer at (727 requested / 727 actual) timer ticks per second [Jan 10 16:26:55] DEBUG[15289] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:55] DEBUG[15289] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:55] DEBUG[15289] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:55] DEBUG[15289] channel.c: Set channel SIP/226-00000001 to write format alaw [Jan 10 16:26:55] DEBUG[15289] channel.c: Set channel SIP/226-00000001 to write format slin [Jan 10 16:26:55] DEBUG[15289] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: Got RTCP report of 72 bytes [Jan 10 16:26:55] DEBUG[15291] res_rtp_asterisk.c: Got RTCP report of 72 bytes [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000001 (len = 4) [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 49 (1), at 192.168.13.113:11794 [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000001 (len = 4) [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000001 (len = 4) [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000001 (len = 4) [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000001 (len = 4) [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000001 (len = 4) [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000001 (len = 4) [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000001 (len = 4) [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: Creating END DTMF Frame: 49 (1), at 192.168.13.113:11794 [Jan 10 16:26:55] DEBUG[15289] channel.c: Set channel SIP/226-00000001 to write format alaw [Jan 10 16:26:55] DEBUG[15289] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000001 (len = 4) [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000001 (len = 4) [Jan 10 16:26:55] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 48 (0), at 192.168.13.113:11794 [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: Creating END DTMF Frame: 48 (0), at 192.168.13.113:11794 [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 48 (0), at 192.168.13.113:11794 [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: Creating END DTMF Frame: 48 (0), at 192.168.13.113:11794 [Jan 10 16:26:56] DEBUG[15289] features.c: Checking if 100@start is a parking exten [Jan 10 16:26:56] DEBUG[15289] channel.c: Not copying variable BRIDGEPVTCALLID. [Jan 10 16:26:56] DEBUG[15289] channel.c: Not copying variable BRIDGEPEER. [Jan 10 16:26:56] DEBUG[15289] channel.c: Not copying variable DIALEDPEERNUMBER. [Jan 10 16:26:56] DEBUG[15289] channel.c: Not copying variable SIPCALLID. [Jan 10 16:26:56] DEBUG[15292] pbx.c: Launching 'Goto' [Jan 10 16:26:56] DEBUG[15292] pbx.c: Launching 'Park' [Jan 10 16:26:56] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for Local - 100@start [Jan 10 16:26:56] DEBUG[15088] chan_local.c: Checking if extension 100@start exists (devicestate) [Jan 10 16:26:56] DEBUG[15088] devicestate.c: Changing state for Local/100@start - state 2 (In use) [Jan 10 16:26:56] DEBUG[15088] devicestate.c: device 'Local/100@start' state '2' [Jan 10 16:26:56] DEBUG[15289] features.c: Dial party C result: newchan:1, outstate:4 [Jan 10 16:26:56] DEBUG[15289] features.c: Actually doing an attended transfer. [Jan 10 16:26:56] DEBUG[15289] features.c: bridge answer set, chan answer set [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:56] DEBUG[15097] app_queue.c: Device 'Local/100@start' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jan 10 16:26:56] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for Local - 100@start [Jan 10 16:26:56] DEBUG[15088] chan_local.c: Checking if extension 100@start exists (devicestate) [Jan 10 16:26:56] DEBUG[15088] devicestate.c: Changing state for Local/100@start - state 2 (In use) [Jan 10 16:26:56] DEBUG[15088] devicestate.c: device 'Local/100@start' state '2' [Jan 10 16:26:56] DEBUG[15289] channel.c: Got a FRAME_CONTROL (-1) frame on channel Local/100@start-00000000;1 [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:56] DEBUG[15289] channel.c: Bridge stops bridging channels SIP/226-00000001 and Local/100@start-00000000;1 [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:26:56] DEBUG[15097] app_queue.c: Device 'Local/100@start' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:56] DEBUG[15289] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Jan 10 16:26:57] DEBUG[15292] features.c: Multiparking: default refcount now 2 [Jan 10 16:26:57] DEBUG[15292] features.c: Multiparking: default refcount now 3 [Jan 10 16:26:57] DEBUG[15292] features.c: Parking lot: default [Jan 10 16:26:57] DEBUG[15292] channel.c: Planning to masquerade channel Local/100@start-00000000;2 into the structure of Parked/Local/100@start-00000000;2 [Jan 10 16:26:57] DEBUG[15292] channel.c: Done planning to masquerade channel Local/100@start-00000000;2 into the structure of Parked/Local/100@start-00000000;2 [Jan 10 16:26:57] DEBUG[15292] channel.c: Actually Masquerading Local/100@start-00000000;2(6) into the structure of Parked/Local/100@start-00000000;2(0) [Jan 10 16:26:57] DEBUG[15292] channel.c: Putting channel Local/100@start-00000000;2 in alaw/alaw formats [Jan 10 16:26:57] DEBUG[15292] channel.c: Done Masquerading Local/100@start-00000000;2 (6) [Jan 10 16:26:57] DEBUG[15289] res_rtp_asterisk.c: Changing ssrc from 909683382 to 172431852 due to a source change [Jan 10 16:26:57] DEBUG[15292] features.c: peer->name: Local/100@start-00000000;2 [Jan 10 16:26:57] DEBUG[15292] features.c: args->orig_chan_name: Local/100@start-00000000;2 [Jan 10 16:26:57] DEBUG[15292] features.c: pu->peername: SIP/226-00000001 [Jan 10 16:26:57] DEBUG[15292] features.c: AMI ParkedCall Channel: Local/100@start-00000000;2 [Jan 10 16:26:57] DEBUG[15292] features.c: AMI ParkedCall From: Local/100@start-00000000;2 [Jan 10 16:26:57] DEBUG[15292] pbx.c: Added extension '101' priority 1 to parkedcalls (0xfc8300) [Jan 10 16:26:57] DEBUG[15292] features.c: Notification of state change to metermaids 101@parkedcalls to state 'In use'[Jan 10 16:26:57] DEBUG[15292] devicestate.c: device 'park:101@parkedcalls' state '2' [Jan 10 16:26:57] DEBUG[15097] app_queue.c: Device 'park:101@parkedcalls' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jan 10 16:26:57] DEBUG[15292] channel.c: Set channel Local/100@start-00000000;2 to write format slin [Jan 10 16:26:57] DEBUG[15289] res_rtp_asterisk.c: Difference is 14080, ms is 1780 [Jan 10 16:26:57] DEBUG[15292] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jan 10 16:26:57] DEBUG[15086] chan_sip.c: Header 0 [ 0]: [Jan 10 16:26:57] DEBUG[15292] channel.c: Scheduling timer at (157 requested / 157 actual) timer ticks per second [Jan 10 16:26:57] DEBUG[15292] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:57] DEBUG[15292] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:57] DEBUG[15292] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:57] DEBUG[15292] channel.c: Set channel Local/100@start-00000000;2 to write format alaw [Jan 10 16:26:57] DEBUG[15292] channel.c: Set channel Local/100@start-00000000;2 to write format slin [Jan 10 16:26:57] DEBUG[15292] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Allocating new SIP dialog for 2b6d29d935bf6a5e5b5347ac46d3e3f6@192.168.13.1:5060 - OPTIONS (No RTP) [Jan 10 16:26:58] DEBUG[15086] acl.c: For destination '99.888.777.66', our source address is '111.222.33.444'. [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 111.222.33.444:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: SIP call-id changed from '2b6d29d935bf6a5e5b5347ac46d3e3f6@192.168.13.1:5060' to '2023d2cf08b8e5e4604d7f7027f99aee@111.222.33.444:5060' [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Initializing initreq for method OPTIONS - callid 2023d2cf08b8e5e4604d7f7027f99aee@111.222.33.444:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 0 [ 42]: OPTIONS sip:switch1.sip.example.tld SIP/2.0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 111.222.33.444:5060;branch=z9hG4bK59ffddb0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as0dc1b4c2 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 4 [ 32]: To: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 5 [ 43]: Contact: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 6 [ 61]: Call-ID: 2023d2cf08b8e5e4604d7f7027f99aee@111.222.33.444:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 8 [ 18]: User-Agent: PBX [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 9 [ 35]: Date: Fri, 10 Jan 2014 15:26:58 GMT [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #44 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 99.888.777.66:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 1 [ 94]: Via: SIP/2.0/UDP 111.222.33.444:5060;branch=z9hG4bK59ffddb0;received=111.222.33.444;rport=5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 2 [ 61]: From: "asterisk" ;tag=as0dc1b4c2 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 3 [ 47]: To: ;tag=as61a21ff6 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 4 [ 61]: Call-ID: 2023d2cf08b8e5e4604d7f7027f99aee@111.222.33.444:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 6 [ 20]: Server: Asterisk 1.8 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 7 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 9 [ 33]: Contact: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 10 [ 23]: Accept: application/sdp [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: = Looking for Call ID: 2023d2cf08b8e5e4604d7f7027f99aee@111.222.33.444:5060 (Checking To) --From tag as0dc1b4c2 --To-tag as61a21ff6 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #44 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Stopping retransmission on '2023d2cf08b8e5e4604d7f7027f99aee@111.222.33.444:5060' of Request 102: Match Found [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Destroying SIP dialog 2023d2cf08b8e5e4604d7f7027f99aee@111.222.33.444:5060 [Jan 10 16:26:58] DEBUG[15292] channel.c: Scheduling timer at (104 requested / 104 actual) timer ticks per second [Jan 10 16:26:58] DEBUG[15292] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:58] DEBUG[15292] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:58] DEBUG[15292] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:58] DEBUG[15292] channel.c: Set channel Local/100@start-00000000;2 to write format alaw [Jan 10 16:26:58] DEBUG[15292] channel.c: Set channel Local/100@start-00000000;2 to write format slin [Jan 10 16:26:58] DEBUG[15292] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Allocating new SIP dialog for 20d8e52939b180de40e7679d4ed34537@192.168.13.1:5060 - OPTIONS (No RTP) [Jan 10 16:26:58] DEBUG[15086] acl.c: For destination '77.888.999.888', our source address is '111.222.33.444'. [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 111.222.33.444:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: SIP call-id changed from '20d8e52939b180de40e7679d4ed34537@192.168.13.1:5060' to '2a8e3cc102236ecf3362b8c301299641@111.222.33.444:5060' [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Initializing initreq for method OPTIONS - callid 2a8e3cc102236ecf3362b8c301299641@111.222.33.444:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 0 [ 42]: OPTIONS sip:switch2.sip.example.tld SIP/2.0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 111.222.33.444:5060;branch=z9hG4bK171df1c5 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as7546910d [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 4 [ 32]: To: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 5 [ 43]: Contact: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 6 [ 61]: Call-ID: 2a8e3cc102236ecf3362b8c301299641@111.222.33.444:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 8 [ 18]: User-Agent: PBX [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 9 [ 35]: Date: Fri, 10 Jan 2014 15:26:58 GMT [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #47 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 77.888.999.888:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Allocating new SIP dialog for 097e155a3da1531161ce3527004b62d6@192.168.13.1:5060 - OPTIONS (No RTP) [Jan 10 16:26:58] DEBUG[15086] acl.c: For destination '192.168.13.113', our source address is '192.168.13.1'. [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.13.1:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: SIP call-id changed from '097e155a3da1531161ce3527004b62d6@192.168.13.1:5060' to '3b2241041c1d61e13433ab2634b87624@192.168.13.1:5060' [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Initializing initreq for method OPTIONS - callid 3b2241041c1d61e13433ab2634b87624@192.168.13.1:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 0 [ 43]: OPTIONS sip:226@192.168.13.113:5062 SIP/2.0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK2a03ac7f [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 3 [ 59]: From: "asterisk" ;tag=as4ec43b1b [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 4 [ 33]: To: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 5 [ 41]: Contact: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 6 [ 59]: Call-ID: 3b2241041c1d61e13433ab2634b87624@192.168.13.1:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 8 [ 18]: User-Agent: PBX [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 9 [ 35]: Date: Fri, 10 Jan 2014 15:26:58 GMT [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #49 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.13.113:5062 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 1 [ 94]: Via: SIP/2.0/UDP 111.222.33.444:5060;branch=z9hG4bK171df1c5;received=111.222.33.444;rport=5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 2 [ 61]: From: "asterisk" ;tag=as7546910d [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 3 [ 47]: To: ;tag=as09615577 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 4 [ 61]: Call-ID: 2a8e3cc102236ecf3362b8c301299641@111.222.33.444:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 6 [ 20]: Server: Asterisk 1.8 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 7 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 9 [ 34]: Contact: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 10 [ 23]: Accept: application/sdp [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: = Looking for Call ID: 2a8e3cc102236ecf3362b8c301299641@111.222.33.444:5060 (Checking To) --From tag as7546910d --To-tag as09615577 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #47 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Stopping retransmission on '2a8e3cc102236ecf3362b8c301299641@111.222.33.444:5060' of Request 102: Match Found [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Destroying SIP dialog 2a8e3cc102236ecf3362b8c301299641@111.222.33.444:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK2a03ac7f [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 2 [ 59]: From: "asterisk" ;tag=as4ec43b1b [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 3 [ 47]: To: ;tag=555852828 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 4 [ 59]: Call-ID: 3b2241041c1d61e13433ab2634b87624@192.168.13.1:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 6 [ 38]: User-Agent: Yealink SIP-T20P 9.70.13.9 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: = Looking for Call ID: 3b2241041c1d61e13433ab2634b87624@192.168.13.1:5060 (Checking To) --From tag as4ec43b1b --To-tag 555852828 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #49 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Stopping retransmission on '3b2241041c1d61e13433ab2634b87624@192.168.13.1:5060' of Request 102: Match Found [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Destroying SIP dialog 3b2241041c1d61e13433ab2634b87624@192.168.13.1:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Allocating new SIP dialog for 1113408622e21a3b53438ec500aaad29@192.168.13.1:5060 - OPTIONS (No RTP) [Jan 10 16:26:58] DEBUG[15086] acl.c: For destination '192.168.13.115', our source address is '192.168.13.1'. [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.13.1:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: SIP call-id changed from '1113408622e21a3b53438ec500aaad29@192.168.13.1:5060' to '2959b6ef55c505e11f028de57e252d47@192.168.13.1:5060' [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Initializing initreq for method OPTIONS - callid 2959b6ef55c505e11f028de57e252d47@192.168.13.1:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 0 [ 43]: OPTIONS sip:228@192.168.13.115:5062 SIP/2.0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK73bf2b73 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 3 [ 59]: From: "asterisk" ;tag=as6c39c2e0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 4 [ 33]: To: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 5 [ 41]: Contact: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 6 [ 59]: Call-ID: 2959b6ef55c505e11f028de57e252d47@192.168.13.1:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 8 [ 18]: User-Agent: PBX [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 9 [ 35]: Date: Fri, 10 Jan 2014 15:26:58 GMT [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #53 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.13.115:5062 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK73bf2b73 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 2 [ 59]: From: "asterisk" ;tag=as6c39c2e0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 3 [ 48]: To: ;tag=2146437613 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 4 [ 59]: Call-ID: 2959b6ef55c505e11f028de57e252d47@192.168.13.1:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 6 [ 49]: User-Agent: Tiptel IP 280 9.70.13.16 00156522c75f [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: = Looking for Call ID: 2959b6ef55c505e11f028de57e252d47@192.168.13.1:5060 (Checking To) --From tag as6c39c2e0 --To-tag 2146437613 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #53 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Stopping retransmission on '2959b6ef55c505e11f028de57e252d47@192.168.13.1:5060' of Request 102: Match Found [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Destroying SIP dialog 2959b6ef55c505e11f028de57e252d47@192.168.13.1:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 0 [ 41]: OPTIONS sip:s@111.222.33.444:5060 SIP/2.0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 77.888.999.888:5060;branch=z9hG4bK0b013697 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as4faac6bf [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 4 [ 31]: To: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 5 [ 43]: Contact: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 6 [ 61]: Call-ID: 3608b4d5612705ec4d95e0fe7897d9ad@77.888.999.888:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 8 [ 24]: User-Agent: Asterisk 1.8 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 9 [ 35]: Date: Fri, 10 Jan 2014 15:26:58 GMT [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: = Looking for Call ID: 3608b4d5612705ec4d95e0fe7897d9ad@77.888.999.888:5060 (Checking From) --From tag as4faac6bf --To-tag [Jan 10 16:26:58] DEBUG[15086] acl.c: For destination '77.888.999.888', our source address is '111.222.33.444'. [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 111.222.33.444:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Allocating new SIP dialog for 3608b4d5612705ec4d95e0fe7897d9ad@77.888.999.888:5060 - OPTIONS (No RTP) [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [Jan 10 16:26:58] DEBUG[15086] netsock2.c: Splitting '111.222.33.444:5060' into... [Jan 10 16:26:58] DEBUG[15086] netsock2.c: ...host '111.222.33.444' and port ''. [Jan 10 16:26:58] DEBUG[15086] netsock2.c: Splitting '77.888.999.888' into... [Jan 10 16:26:58] DEBUG[15086] netsock2.c: ...host '77.888.999.888' and port ''. [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 77.888.999.888:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 0 [ 41]: OPTIONS sip:s@111.222.33.444:5060 SIP/2.0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 99.888.777.66:5060;branch=z9hG4bK34ca010b [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as32c24686 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 4 [ 31]: To: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 5 [ 42]: Contact: [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 6 [ 60]: Call-ID: 4dee8faf09f5b20c799e5dd21a49fe9c@99.888.777.66:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 8 [ 24]: User-Agent: Asterisk 1.8 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 9 [ 35]: Date: Fri, 10 Jan 2014 15:26:58 GMT [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: = Looking for Call ID: 4dee8faf09f5b20c799e5dd21a49fe9c@99.888.777.66:5060 (Checking From) --From tag as32c24686 --To-tag [Jan 10 16:26:58] DEBUG[15086] acl.c: For destination '99.888.777.66', our source address is '111.222.33.444'. [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 111.222.33.444:5060 [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Allocating new SIP dialog for 4dee8faf09f5b20c799e5dd21a49fe9c@99.888.777.66:5060 - OPTIONS (No RTP) [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [Jan 10 16:26:58] DEBUG[15086] netsock2.c: Splitting '111.222.33.444:5060' into... [Jan 10 16:26:58] DEBUG[15086] netsock2.c: ...host '111.222.33.444' and port ''. [Jan 10 16:26:58] DEBUG[15086] netsock2.c: Splitting '99.888.777.66' into... [Jan 10 16:26:58] DEBUG[15086] netsock2.c: ...host '99.888.777.66' and port ''. [Jan 10 16:26:58] DEBUG[15086] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 99.888.777.66:5060 [Jan 10 16:26:58] DEBUG[15292] channel.c: Scheduling timer at (157 requested / 157 actual) timer ticks per second [Jan 10 16:26:58] DEBUG[15292] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:58] DEBUG[15292] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:58] DEBUG[15292] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:26:58] DEBUG[15292] channel.c: Set channel Local/100@start-00000000;2 to write format alaw [Jan 10 16:26:58] DEBUG[15292] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jan 10 16:26:58] DEBUG[15292] features.c: Multiparking: default refcount now 2 [Jan 10 16:26:58] DEBUG[15292] pbx.c: Spawn extension (parkedcalls,s,1) exited non-zero on 'Parked/Local/100@start-00000000;2' [Jan 10 16:26:58] DEBUG[15292] channel.c: Soft-Hanging up channel 'Parked/Local/100@start-00000000;2' [Jan 10 16:26:58] DEBUG[15292] channel.c: Hanging up zombie 'Parked/Local/100@start-00000000;2' [Jan 10 16:26:58] DEBUG[15292] cdr.c: Dropping CDR ! [Jan 10 16:26:58] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for Parked - Local/100@start [Jan 10 16:26:58] DEBUG[15088] devicestate.c: Changing state for Parked/Local/100@start - state 4 (Invalid) [Jan 10 16:26:58] DEBUG[15088] devicestate.c: device 'Parked/Local/100@start' state '4' [Jan 10 16:26:58] DEBUG[15097] app_queue.c: Device 'Parked/Local/100@start' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jan 10 16:26:58] DEBUG[15090] channel.c: Set channel Local/100@start-00000000;2 to write format slin [Jan 10 16:26:58] DEBUG[15090] res_musiconhold.c: Local/100@start-00000000;2 Opened file 7 '/var/lib/asterisk/moh//Brother_mark' [Jan 10 16:27:00] DEBUG[15289] res_rtp_asterisk.c: Got RTCP report of 72 bytes [Jan 10 16:27:00] DEBUG[15291] res_rtp_asterisk.c: Got RTCP report of 72 bytes [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 0 [ 40]: INVITE sip:228@192.168.13.1:5060 SIP/2.0 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 1 [ 60]: Via: SIP/2.0/UDP 192.168.13.113:5062;branch=z9hG4bK496498689 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 2 [ 50]: From: ;tag=1844667989 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 3 [ 56]: To: "tiptel-ip280" ;tag=as08287b1f [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 4 [ 59]: Call-ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 5 [ 16]: CSeq: 103 INVITE [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 6 [ 38]: Contact: [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 7 [ 29]: Content-Type: application/sdp [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 8 [115]: Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 10 [ 38]: User-Agent: Yealink SIP-T20P 9.70.13.9 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 11 [ 51]: Allow-Events: talk,hold,conference,refer,check-sync [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 12 [ 19]: Content-Length: 395 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 13 [ 0]: [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 0 [ 3]: v=0 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 1 [ 37]: o=- 20009 20010 IN IP4 192.168.13.113 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 2 [ 10]: s=SDP data [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.13.113 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 4 [ 5]: t=0 0 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 5 [ 34]: m=audio 11794 RTP/AVP 0 8 18 9 101 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 8 [ 21]: a=rtpmap:18 G729/8000 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 9 [ 19]: a=fmtp:18 annexb=no [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 10 [ 20]: a=rtpmap:9 G722/8000 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 11 [ 15]: a=fmtp:101 0-15 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 12 [ 33]: a=rtpmap:101 telephone-event/8000 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 13 [ 10]: a=ptime:20 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 14 [ 10]: a=sendonly [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 15 [ 23]: m=video 0 RTP/AVP 34 99 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 16 [ 22]: a=rtpmap:34 H263/90000 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 17 [ 22]: a=rtpmap:99 H264/90000 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Body 18 [ 10]: a=sendrecv [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: = Looking for Call ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 (Checking From) --From tag 1844667989 --To-tag as08287b1f [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Jan 10 16:27:00] DEBUG[15086] netsock2.c: Splitting '192.168.13.113:5062' into... [Jan 10 16:27:00] DEBUG[15086] netsock2.c: ...host '192.168.13.113' and port '5062'. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Initializing initreq for method INVITE - callid 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing session-level SDP o=- 20009 20010 IN IP4 192.168.13.113... OK. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing session-level SDP s=SDP data... UNSUPPORTED OR FAILED. [Jan 10 16:27:00] DEBUG[15086] netsock2.c: Splitting '192.168.13.113' into... [Jan 10 16:27:00] DEBUG[15086] netsock2.c: ...host '192.168.13.113' and port ''. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.13.113... OK. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Setting payload 0 based on m type on 0x7f8003d2e030 [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Setting payload 8 based on m type on 0x7f8003d2e030 [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Setting payload 18 based on m type on 0x7f8003d2e030 [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Setting payload 9 based on m type on 0x7f8003d2e030 [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Setting payload 101 based on m type on 0x7f8003d2e030 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED OR FAILED. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Processing media-level (audio) SDP a=sendonly... OK. [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Ignoring video media offer because port number is zero [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Incorporating payload 0 on 0x7f8003d2e030 [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Incorporating payload 8 on 0x7f8003d2e030 [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Incorporating payload 9 on 0x7f8003d2e030 [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Incorporating payload 18 on 0x7f8003d2e030 [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Incorporating payload 101 on 0x7f8003d2e030 [Jan 10 16:27:00] DEBUG[15086] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xfff148' [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Copying payload 0 from 0x7f8003d2e030 to 0xfff310 [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Copying payload 8 from 0x7f8003d2e030 to 0xfff310 [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Copying payload 9 from 0x7f8003d2e030 to 0xfff310 [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Copying payload 18 from 0x7f8003d2e030 to 0xfff310 [Jan 10 16:27:00] DEBUG[15086] rtp_engine.c: Copying payload 101 from 0x7f8003d2e030 to 0xfff310 [Jan 10 16:27:00] DEBUG[15086] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0xfff148' [Jan 10 16:27:00] DEBUG[15086] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x100b468' [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: We have an owner, now see if we need to change this call [Jan 10 16:27:00] DEBUG[15086] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xfff148' [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Got a SIP re-invite for call 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: SIP/226-00000001: This call is UP.... [Jan 10 16:27:00] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 226 [Jan 10 16:27:00] DEBUG[15088] chan_sip.c: Checking device state for peer 226 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.13.113:5062 [Jan 10 16:27:00] DEBUG[15088] devicestate.c: Changing state for SIP/226 - state 8 (On Hold) [Jan 10 16:27:00] DEBUG[15088] devicestate.c: device 'SIP/226' state '8' [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Setting framing from config on incoming call [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: ** Our capability: 0x8 (alaw) Video flag: True Text flag: True [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: -- Done with adding codecs to SDP [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Done building SDP. Settling with this capability: 0x8 (alaw) [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #58 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.13.113:5062 [Jan 10 16:27:00] DEBUG[15097] app_queue.c: Device 'SIP/226' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. [Jan 10 16:27:00] DEBUG[15289] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jan 10 16:27:00] DEBUG[15289] channel.c: Got a FRAME_CONTROL (31) frame on channel SIP/226-00000001 [Jan 10 16:27:00] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:27:00] DEBUG[15289] channel.c: Bridge stops bridging channels SIP/226-00000001 and Local/100@start-00000000;1 [Jan 10 16:27:00] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:27:00] DEBUG[15289] channel.c: Set channel Local/100@start-00000000;1 to write format slin [Jan 10 16:27:00] DEBUG[15289] res_musiconhold.c: Local/100@start-00000000;1 Opened file 2 '/var/lib/asterisk/moh//Deadmau5 - 10 - Storbe' [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 0 [ 37]: ACK sip:228@192.168.13.1:5060 SIP/2.0 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 1 [ 60]: Via: SIP/2.0/UDP 192.168.13.113:5062;branch=z9hG4bK517778823 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 2 [ 50]: From: ;tag=1844667989 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 3 [ 56]: To: "tiptel-ip280" ;tag=as08287b1f [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 4 [ 59]: Call-ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 5 [ 13]: CSeq: 103 ACK [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 6 [ 38]: Contact: [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 8 [ 38]: User-Agent: Yealink SIP-T20P 9.70.13.9 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: = Looking for Call ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 (Checking From) --From tag 1844667989 --To-tag as08287b1f [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #58 [Jan 10 16:27:00] DEBUG[15086] chan_sip.c: Stopping retransmission on '6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060' of Response 103: Match Found [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 0 [ 39]: REFER sip:228@192.168.13.1:5060 SIP/2.0 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 1 [ 61]: Via: SIP/2.0/UDP 192.168.13.113:5062;branch=z9hG4bK1011600420 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 2 [ 50]: From: ;tag=1844667989 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 3 [ 56]: To: "tiptel-ip280" ;tag=as08287b1f [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 4 [ 59]: Call-ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 5 [ 15]: CSeq: 104 REFER [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 6 [ 38]: Contact: [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 8 [ 38]: User-Agent: Yealink SIP-T20P 9.70.13.9 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 9 [ 32]: Refer-To: [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 10 [ 42]: Referred-By: [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 11 [ 12]: Event: refer [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: = Looking for Call ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 (Checking From) --From tag 1844667989 --To-tag as08287b1f [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: **** Received REFER (9) - Command in SIP REFER [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: SIP blind transfer: Transferer channel SIP/226-00000001, transferee channel Local/100@start-00000000;1 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Got SIP transfer, applying to bridged peer 'Local/100@start-00000000;1' [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Trying to put 'SIP/2.0 202' onto UDP socket destined for 192.168.13.113:5062 [Jan 10 16:27:01] DEBUG[15086] features.c: Checking if 101@start is a parking exten [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: chan1->name: SIP/226-00000001 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Strict routing enforced for session 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:01] DEBUG[15086] netsock2.c: Splitting '192.168.13.113:5062' into... [Jan 10 16:27:01] DEBUG[15086] netsock2.c: ...host '192.168.13.113' and port '5062'. [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #59 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 192.168.13.113:5062 [Jan 10 16:27:01] DEBUG[15086] channel.c: Set channel Local/100@start-00000000;1 to write format alaw [Jan 10 16:27:01] DEBUG[15086] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:27:01] DEBUG[15086] channel.c: Planning to masquerade channel Local/100@start-00000000;1 into the structure of AsyncGoto/Local/100@start-00000000;1 [Jan 10 16:27:01] DEBUG[15086] channel.c: Done planning to masquerade channel Local/100@start-00000000;1 into the structure of AsyncGoto/Local/100@start-00000000;1 [Jan 10 16:27:01] DEBUG[15086] channel.c: Actually Masquerading Local/100@start-00000000;1(6) into the structure of AsyncGoto/Local/100@start-00000000;1(6) [Jan 10 16:27:01] DEBUG[15086] channel.c: Putting channel Local/100@start-00000000;1 in alaw/alaw formats [Jan 10 16:27:01] DEBUG[15086] channel.c: Done Masquerading Local/100@start-00000000;1 (6) [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Blind transfer succeeded. Telling transferer. [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Strict routing enforced for session 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:01] DEBUG[15086] netsock2.c: Splitting '192.168.13.113:5062' into... [Jan 10 16:27:01] DEBUG[15086] netsock2.c: ...host '192.168.13.113' and port '5062'. [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #60 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 192.168.13.113:5062 [Jan 10 16:27:01] DEBUG[15289] channel.c: Bridge stops because we're zombie or need a soft hangup: c0=SIP/226-00000001, c1=AsyncGoto/Local/100@start-00000000;1, flags: No,No,Yes,Yes [Jan 10 16:27:01] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:27:01] DEBUG[15289] channel.c: Bridge stops bridging channels SIP/226-00000001 and AsyncGoto/Local/100@start-00000000;1 [Jan 10 16:27:01] DEBUG[15289] channel.c: Hanging up zombie 'AsyncGoto/Local/100@start-00000000;1' [Jan 10 16:27:01] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for AsyncGoto - Local/100@start [Jan 10 16:27:01] DEBUG[15088] devicestate.c: Changing state for AsyncGoto/Local/100@start - state 4 (Invalid) [Jan 10 16:27:01] DEBUG[15088] devicestate.c: device 'AsyncGoto/Local/100@start' state '4' [Jan 10 16:27:01] DEBUG[15097] app_queue.c: Device 'AsyncGoto/Local/100@start' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jan 10 16:27:01] DEBUG[15289] channel.c: Set channel SIP/226-00000001 to write format gsm [Jan 10 16:27:01] DEBUG[15293] pbx.c: Launching 'Goto' [Jan 10 16:27:01] DEBUG[15289] res_rtp_asterisk.c: No remote address on RTP instance '0xfff148' so dropping frame [Jan 10 16:27:01] DEBUG[15289] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jan 10 16:27:01] DEBUG[15293] pbx.c: Launching 'ParkedCall' [Jan 10 16:27:01] DEBUG[15293] features.c: Found Parking lot: default [Jan 10 16:27:01] DEBUG[15293] features.c: Notification of state change to metermaids 101@parkedcalls to state 'Not in use'[Jan 10 16:27:01] DEBUG[15293] devicestate.c: device 'park:101@parkedcalls' state '1' [Jan 10 16:27:01] DEBUG[15097] app_queue.c: Device 'park:101@parkedcalls' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jan 10 16:27:01] DEBUG[15293] channel.c: Set channel Local/100@start-00000000;2 to write format alaw [Jan 10 16:27:01] DEBUG[15293] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:27:01] DEBUG[15293] features.c: Multiparking: default refcount now 2 [Jan 10 16:27:01] DEBUG[15293] channel.c: Set channel Local/100@start-00000000;1 to write format gsm [Jan 10 16:27:01] DEBUG[15293] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jan 10 16:27:01] DEBUG[15289] res_rtp_asterisk.c: No remote address on RTP instance '0xfff148' so dropping frame [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK78506cc8 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 2 [ 58]: From: "tiptel-ip280" ;tag=as08287b1f [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 3 [ 48]: To: ;tag=1844667989 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 4 [ 59]: Call-ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 5 [ 16]: CSeq: 103 NOTIFY [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 6 [ 38]: Contact: [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 7 [ 38]: User-Agent: Yealink SIP-T20P 9.70.13.9 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: = Looking for Call ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 (Checking To) --From tag as08287b1f --To-tag 1844667989 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #59 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Stopping retransmission on '6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060' of Request 103: Match Found [Jan 10 16:27:01] DEBUG[15289] res_rtp_asterisk.c: No remote address on RTP instance '0xfff148' so dropping frame [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK79527155 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 2 [ 58]: From: "tiptel-ip280" ;tag=as08287b1f [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 3 [ 48]: To: ;tag=1844667989 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 4 [ 59]: Call-ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 5 [ 16]: CSeq: 104 NOTIFY [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 6 [ 38]: Contact: [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 7 [ 38]: User-Agent: Yealink SIP-T20P 9.70.13.9 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: = Looking for Call ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 (Checking To) --From tag as08287b1f --To-tag 1844667989 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #60 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Stopping retransmission on '6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060' of Request 104: Match Found [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 0 [ 37]: BYE sip:228@192.168.13.1:5060 SIP/2.0 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 1 [ 61]: Via: SIP/2.0/UDP 192.168.13.113:5062;branch=z9hG4bK1542134391 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 2 [ 50]: From: ;tag=1844667989 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 3 [ 56]: To: "tiptel-ip280" ;tag=as08287b1f [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 4 [ 59]: Call-ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 5 [ 13]: CSeq: 105 BYE [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 6 [ 38]: Contact: [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 8 [ 38]: User-Agent: Yealink SIP-T20P 9.70.13.9 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: = Looking for Call ID: 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 (Checking From) --From tag 1844667989 --To-tag as08287b1f [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Initializing initreq for method BYE - callid 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:01] DEBUG[15086] netsock2.c: Splitting '192.168.13.113:5062' into... [Jan 10 16:27:01] DEBUG[15086] netsock2.c: ...host '192.168.13.113' and port '5062'. [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Setting SIP_ALREADYGONE on dialog 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:01] DEBUG[15086] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xfff148' [Jan 10 16:27:01] DEBUG[15086] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x100b468' [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Received bye, issuing owner hangup [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.13.113:5062 [Jan 10 16:27:01] DEBUG[15289] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jan 10 16:27:01] DEBUG[15289] channel.c: Set channel SIP/228-00000000 to write format alaw [Jan 10 16:27:01] DEBUG[15289] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:27:01] DEBUG[15289] cdr.c: Dropping CDR ! [Jan 10 16:27:01] DEBUG[15289] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:27:01] DEBUG[15289] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:27:01] DEBUG[15289] channel.c: Hanging up channel 'SIP/226-00000001' [Jan 10 16:27:01] DEBUG[15289] chan_sip.c: update_call_counter(226) - decrement call limit counter on hangup [Jan 10 16:27:01] DEBUG[15289] chan_sip.c: Updating call counter for outgoing call [Jan 10 16:27:01] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 226 [Jan 10 16:27:01] DEBUG[15088] chan_sip.c: Checking device state for peer 226 [Jan 10 16:27:01] DEBUG[15088] devicestate.c: Changing state for SIP/226 - state 1 (Not in use) [Jan 10 16:27:01] DEBUG[15088] devicestate.c: device 'SIP/226' state '1' [Jan 10 16:27:01] DEBUG[15289] chan_sip.c: Call to peer '226' removed from call limit 2 [Jan 10 16:27:01] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 226 [Jan 10 16:27:01] DEBUG[15088] chan_sip.c: Checking device state for peer 226 [Jan 10 16:27:01] DEBUG[15088] devicestate.c: Changing state for SIP/226 - state 1 (Not in use) [Jan 10 16:27:01] DEBUG[15088] devicestate.c: device 'SIP/226' state '1' [Jan 10 16:27:01] DEBUG[15289] chan_sip.c: SIP Transfer: Not hanging up right now... Rescheduling hangup for 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060. [Jan 10 16:27:01] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 226 [Jan 10 16:27:01] DEBUG[15088] chan_sip.c: Checking device state for peer 226 [Jan 10 16:27:01] DEBUG[15088] devicestate.c: Changing state for SIP/226 - state 1 (Not in use) [Jan 10 16:27:01] DEBUG[15088] devicestate.c: device 'SIP/226' state '1' [Jan 10 16:27:01] DEBUG[15097] app_queue.c: Device 'SIP/226' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jan 10 16:27:01] DEBUG[15097] app_queue.c: Device 'SIP/226' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jan 10 16:27:01] DEBUG[15289] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Jan 10 16:27:01] DEBUG[15097] app_queue.c: Device 'SIP/226' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jan 10 16:27:01] DEBUG[15289] pbx.c: Spawn extension (start,226,1) exited non-zero on 'SIP/228-00000000' [Jan 10 16:27:01] DEBUG[15289] channel.c: Soft-Hanging up channel 'SIP/228-00000000' [Jan 10 16:27:01] DEBUG[15289] channel.c: Hanging up channel 'SIP/228-00000000' [Jan 10 16:27:01] DEBUG[15289] chan_sip.c: Hangup call SIP/228-00000000, SIP callid 1215291252 [Jan 10 16:27:01] DEBUG[15289] chan_sip.c: update_call_counter(228) - decrement call limit counter on hangup [Jan 10 16:27:01] DEBUG[15289] chan_sip.c: Updating call counter for incoming call [Jan 10 16:27:01] DEBUG[15289] chan_sip.c: Call from peer '228' removed from call limit 2 [Jan 10 16:27:01] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 228 [Jan 10 16:27:01] DEBUG[15088] chan_sip.c: Checking device state for peer 228 [Jan 10 16:27:01] DEBUG[15088] devicestate.c: Changing state for SIP/228 - state 1 (Not in use) [Jan 10 16:27:01] DEBUG[15088] devicestate.c: device 'SIP/228' state '1' [Jan 10 16:27:01] DEBUG[15097] app_queue.c: Device 'SIP/228' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jan 10 16:27:01] DEBUG[15289] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x10050a8' [Jan 10 16:27:01] DEBUG[15289] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f7ffc0b78e8' [Jan 10 16:27:01] DEBUG[15289] chan_sip.c: Strict routing enforced for session 1215291252 [Jan 10 16:27:01] DEBUG[15289] netsock2.c: Splitting '192.168.13.115:5062' into... [Jan 10 16:27:01] DEBUG[15289] netsock2.c: ...host '192.168.13.115' and port '5062'. [Jan 10 16:27:01] DEBUG[15289] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #63 [Jan 10 16:27:01] DEBUG[15289] chan_sip.c: Trying to put 'BYE sip:228' onto UDP socket destined for 192.168.13.115:5062 [Jan 10 16:27:01] DEBUG[15088] devicestate.c: No provider found, checking channel drivers for SIP - 228 [Jan 10 16:27:01] DEBUG[15088] chan_sip.c: Checking device state for peer 228 [Jan 10 16:27:01] DEBUG[15088] devicestate.c: Changing state for SIP/228 - state 1 (Not in use) [Jan 10 16:27:01] DEBUG[15088] devicestate.c: device 'SIP/228' state '1' [Jan 10 16:27:01] DEBUG[15097] app_queue.c: Device 'SIP/228' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.13.1:5060;branch=z9hG4bK364d5434 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 2 [ 43]: From: ;tag=as46d06b94 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 3 [ 56]: To: "tiptel-ip280" ;tag=2140902273 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 4 [ 19]: Call-ID: 1215291252 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 5 [ 13]: CSeq: 102 BYE [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 6 [ 49]: User-Agent: Tiptel IP 280 9.70.13.16 00156522c75f [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: = Looking for Call ID: 1215291252 (Checking To) --From tag as46d06b94 --To-tag 2140902273 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #63 [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Stopping retransmission on '1215291252' of Request 102: Match Found [Jan 10 16:27:01] DEBUG[15086] chan_sip.c: Destroying SIP dialog 1215291252 [Jan 10 16:27:01] DEBUG[15086] rtp_engine.c: Destroyed RTP instance '0x10050a8' [Jan 10 16:27:01] DEBUG[15086] rtp_engine.c: Destroyed RTP instance '0x7f7ffc0b78e8' [Jan 10 16:27:02] DEBUG[15293] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:27:02] DEBUG[15293] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:27:02] DEBUG[15293] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jan 10 16:27:02] DEBUG[15293] channel.c: Set channel Local/100@start-00000000;1 to write format alaw [Jan 10 16:27:02] DEBUG[15293] features.c: bridge answer set, chan answer set [Jan 10 16:27:08] DEBUG[15086] chan_sip.c: Auto destroying SIP dialog '6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060' [Jan 10 16:27:08] DEBUG[15086] chan_sip.c: Destroying SIP dialog 6be2eb160ac27bdc24a048fe20d1cb2e@192.168.13.1:5060 [Jan 10 16:27:08] DEBUG[15086] rtp_engine.c: Destroyed RTP instance '0xfff148' [Jan 10 16:27:08] DEBUG[15086] rtp_engine.c: Destroyed RTP instance '0x100b468'