[Nov 29 14:01:53] VERBOSE[16005] config.c: == Parsing '/etc/asterisk/logger.conf': [Nov 29 14:01:53] DEBUG[16005] config.c: Parsing /etc/asterisk/logger.conf [Nov 29 14:01:53] VERBOSE[16005] config.c: == Found [Nov 29 14:01:53] VERBOSE[16005] logger.c: Asterisk Queue Logger restarted [Nov 29 14:02:39] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> <-------------> [Nov 29 14:02:39] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:02:48] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> <-------------> [Nov 29 14:02:48] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:03:09] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> <-------------> [Nov 29 14:03:09] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:03:18] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> <-------------> [Nov 29 14:03:18] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:03:39] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> <-------------> [Nov 29 14:03:39] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:03:48] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> <-------------> [Nov 29 14:03:48] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:04:01] VERBOSE[16005] config.c: == Parsing '/etc/asterisk/logger.conf': [Nov 29 14:04:01] DEBUG[16005] config.c: Parsing /etc/asterisk/logger.conf [Nov 29 14:04:01] VERBOSE[16005] config.c: == Found [Nov 29 14:04:01] VERBOSE[16005] logger.c: Asterisk Queue Logger restarted [Nov 29 14:04:09] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> <-------------> [Nov 29 14:04:09] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.207:5060 ---> INVITE sip:6001@192.168.10.193 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-a7d26c5f46297407-1---d8754z-;rport Max-Forwards: 70 Contact: To: From: "6000";tag=f53346dc Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. CSeq: 1 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp Supported: replaces User-Agent: X-Lite release 5.0.0 stamp 67284 Content-Length: 215 v=0 o=- 12998671450862060 1 IN IP4 192.168.10.207 s=CounterPath X-Lite 5.0.0 c=IN IP4 192.168.10.207 b=AS:4096 t=0 0 m=audio 5062 RTP/AVP 0 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 0 [ 38]: INVITE sip:6001@192.168.10.193 SIP/2.0 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 1 [ 93]: Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-a7d26c5f46297407-1---d8754z-;rport [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 3 [ 39]: Contact: [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 4 [ 29]: To: [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 5 [ 50]: From: "6000";tag=f53346dc [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 6 [ 53]: Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 7 [ 14]: CSeq: 1 INVITE [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 8 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 10 [ 19]: Supported: replaces [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 11 [ 44]: User-Agent: X-Lite release 5.0.0 stamp 67284 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 12 [ 19]: Content-Length: 215 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 13 [ 0]: [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 0 [ 3]: v=0 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 1 [ 45]: o=- 12998671450862060 1 IN IP4 192.168.10.207 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 2 [ 26]: s=CounterPath X-Lite 5.0.0 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.10.207 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 4 [ 9]: b=AS:4096 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 5 [ 5]: t=0 0 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 6 [ 26]: m=audio 5062 RTP/AVP 0 101 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-15 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 9 [ 10]: a=sendrecv [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: --- (13 headers 10 lines) --- [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: = Looking for Call ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. (Checking From) --From tag f53346dc --To-tag [Nov 29 14:04:12] DEBUG[2142] acl.c: For destination '192.168.10.207', our source address is '192.168.10.193'. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.10.193:5060 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Allocating new SIP dialog for N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. - INVITE (No RTP) [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Nov 29 14:04:12] DEBUG[2142] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces" [Nov 29 14:04:12] DEBUG[2142] sip/reqresp_parser.c: Found SIP option: -replaces- [Nov 29 14:04:12] DEBUG[2142] sip/reqresp_parser.c: Matched SIP option: replaces [Nov 29 14:04:12] DEBUG[2142] netsock2.c: Splitting '192.168.10.207:5060' into... [Nov 29 14:04:12] DEBUG[2142] netsock2.c: ...host '192.168.10.207' and port '5060'. [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Sending to 192.168.10.207:5060 (NAT) [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Initializing initreq for method INVITE - callid N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Using INVITE request as basis request - N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. [Nov 29 14:04:12] DEBUG[2142] netsock2.c: Splitting '192.168.10.193' into... [Nov 29 14:04:12] DEBUG[2142] netsock2.c: ...host '192.168.10.193' and port ''. [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Found peer '6000' for '6000' from 192.168.10.207:5060 [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: <--- Reliably Transmitting (no NAT) to 192.168.10.207:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-a7d26c5f46297407-1---d8754z-;received=192.168.10.207;rport=5060 From: "6000";tag=f53346dc To: ;tag=as6ae37a43 Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. CSeq: 1 INVITE Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="616acadb" Content-Length: 0 <------------> [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #13 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.10.207:5060 [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Scheduling destruction of SIP dialog 'N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU.' in 32000 ms (Method: INVITE) [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.207:5060 ---> ACK sip:6001@192.168.10.193 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-a7d26c5f46297407-1---d8754z-;rport Max-Forwards: 70 To: ;tag=as6ae37a43 From: "6000";tag=f53346dc Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. CSeq: 1 ACK Content-Length: 0 <-------------> [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 0 [ 35]: ACK sip:6001@192.168.10.193 SIP/2.0 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 1 [ 93]: Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-a7d26c5f46297407-1---d8754z-;rport [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 3 [ 44]: To: ;tag=as6ae37a43 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 4 [ 50]: From: "6000";tag=f53346dc [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 5 [ 53]: Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 6 [ 11]: CSeq: 1 ACK [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: --- (8 headers 0 lines) --- [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: = Looking for Call ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. (Checking From) --From tag f53346dc --To-tag as6ae37a43 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #13 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Stopping retransmission on 'N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU.' of Response 1: Match Found [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.207:5060 ---> INVITE sip:6001@192.168.10.193 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-b6859760b639c709-1---d8754z-;rport Max-Forwards: 70 Contact: To: From: "6000";tag=f53346dc Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp Supported: replaces User-Agent: X-Lite release 5.0.0 stamp 67284 Authorization: Digest username="6000",realm="asterisk",nonce="616acadb",uri="sip:6001@192.168.10.193",response="e1b67df78ddaa05ab074c22d8f8deabe",algorithm=MD5 Content-Length: 215 v=0 o=- 12998671450862060 1 IN IP4 192.168.10.207 s=CounterPath X-Lite 5.0.0 c=IN IP4 192.168.10.207 b=AS:4096 t=0 0 m=audio 5062 RTP/AVP 0 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 0 [ 38]: INVITE sip:6001@192.168.10.193 SIP/2.0 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 1 [ 93]: Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-b6859760b639c709-1---d8754z-;rport [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 3 [ 39]: Contact: [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 4 [ 29]: To: [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 5 [ 50]: From: "6000";tag=f53346dc [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 6 [ 53]: Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 7 [ 14]: CSeq: 2 INVITE [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 8 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 10 [ 19]: Supported: replaces [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 11 [ 44]: User-Agent: X-Lite release 5.0.0 stamp 67284 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 12 [159]: Authorization: Digest username="6000",realm="asterisk",nonce="616acadb",uri="sip:6001@192.168.10.193",response="e1b67df78ddaa05ab074c22d8f8deabe",algorithm=MD5 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 13 [ 19]: Content-Length: 215 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Header 14 [ 0]: [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 0 [ 3]: v=0 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 1 [ 45]: o=- 12998671450862060 1 IN IP4 192.168.10.207 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 2 [ 26]: s=CounterPath X-Lite 5.0.0 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.10.207 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 4 [ 9]: b=AS:4096 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 5 [ 5]: t=0 0 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 6 [ 26]: m=audio 5062 RTP/AVP 0 101 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-15 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Body 9 [ 10]: a=sendrecv [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: --- (14 headers 10 lines) --- [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: = Looking for Call ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. (Checking From) --From tag f53346dc --To-tag [Nov 29 14:04:12] DEBUG[2142] netsock2.c: Splitting '192.168.10.193' into... [Nov 29 14:04:12] DEBUG[2142] netsock2.c: ...host '192.168.10.193' and port ''. [Nov 29 14:04:12] DEBUG[2142] netsock2.c: Splitting '192.168.10.193' into... [Nov 29 14:04:12] DEBUG[2142] netsock2.c: ...host '192.168.10.193' and port ''. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Nov 29 14:04:12] DEBUG[2142] netsock2.c: Splitting '192.168.10.207:5060' into... [Nov 29 14:04:12] DEBUG[2142] netsock2.c: ...host '192.168.10.207' and port '5060'. [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Sending to 192.168.10.207:5060 (no NAT) [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Initializing initreq for method INVITE - callid N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Using INVITE request as basis request - N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. [Nov 29 14:04:12] DEBUG[2142] netsock2.c: Splitting '192.168.10.193' into... [Nov 29 14:04:12] DEBUG[2142] netsock2.c: ...host '192.168.10.193' and port ''. [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Found peer '6000' for '6000' from 192.168.10.207:5060 [Nov 29 14:04:12] DEBUG[2142] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x982ff40' [Nov 29 14:04:12] DEBUG[2142] res_rtp_asterisk.c: Allocated port 19890 for RTP instance '0x982ff40' [Nov 29 14:04:12] DEBUG[2142] rtp_engine.c: RTP instance '0x982ff40' is setup and ready to go [Nov 29 14:04:12] DEBUG[2142] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x982ff40' [Nov 29 14:04:12] VERBOSE[2142] netsock2.c: == Using SIP RTP CoS mark 5 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Setting NAT on RTP to Off [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Processing session-level SDP o=- 12998671450862060 1 IN IP4 192.168.10.207... UNSUPPORTED OR FAILED. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Processing session-level SDP s=CounterPath X-Lite 5.0.0... UNSUPPORTED OR FAILED. [Nov 29 14:04:12] DEBUG[2142] netsock2.c: Splitting '192.168.10.207' into... [Nov 29 14:04:12] DEBUG[2142] netsock2.c: ...host '192.168.10.207' and port ''. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.10.207... OK. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Processing session-level SDP b=AS:4096... UNSUPPORTED OR FAILED. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Found RTP audio format 0 [Nov 29 14:04:12] DEBUG[2142] rtp_engine.c: Setting payload 0 based on m type on 0xb69e5df4 [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Found RTP audio format 101 [Nov 29 14:04:12] DEBUG[2142] rtp_engine.c: Setting payload 101 based on m type on 0xb69e5df4 [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Found audio description format telephone-event for ID 101 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Nov 29 14:04:12] DEBUG[2142] rtp_engine.c: Incorporating payload 0 on 0xb69e5df4 [Nov 29 14:04:12] DEBUG[2142] rtp_engine.c: Incorporating payload 101 on 0xb69e5df4 [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Capabilities: us - 0x90d (g723|ulaw|alaw|g726|g729), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw) [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Nov 29 14:04:12] DEBUG[2142] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x982ff40' [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Peer audio RTP is at port 192.168.10.207:5062 [Nov 29 14:04:12] DEBUG[2142] rtp_engine.c: Copying payload 0 from 0xb69e5df4 to 0x98300ec [Nov 29 14:04:12] DEBUG[2142] rtp_engine.c: Copying payload 101 from 0xb69e5df4 to 0x98300ec [Nov 29 14:04:12] DEBUG[2142] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x982ff40' [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Checking SIP call limits for device 6000 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Updating call counter for incoming call [Nov 29 14:04:12] DEBUG[2142] netsock2.c: Splitting '192.168.10.193' into... [Nov 29 14:04:12] DEBUG[2142] netsock2.c: ...host '192.168.10.193' and port ''. [Nov 29 14:04:12] DEBUG[2142] netsock2.c: Splitting '192.168.10.193' into... [Nov 29 14:04:12] DEBUG[2142] netsock2.c: ...host '192.168.10.193' and port ''. [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Looking for 6001 in sip-6000 (domain 192.168.10.193) [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: *** Our capabilities are 0x90d (g723|ulaw|alaw|g726|g729) [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: This channel will not be able to handle video. [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: build_route: Contact hop: [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: list_route: hop: [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: SIP/6000-00000000: New call is still down.... Trying... [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: <--- Transmitting (no NAT) to 192.168.10.207:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-b6859760b639c709-1---d8754z-;received=192.168.10.207;rport=5060 From: "6000";tag=f53346dc To: Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. CSeq: 2 INVITE Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.10.207:5060 [Nov 29 14:04:12] DEBUG[2129] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Nov 29 14:04:12] DEBUG[2129] chan_sip.c: Checking device state for peer 6000 [Nov 29 14:04:12] DEBUG[2129] devicestate.c: Changing state for SIP/6000 - state 1 (Not in use) [Nov 29 14:04:12] DEBUG[2129] devicestate.c: device 'SIP/6000' state '1' [Nov 29 14:04:12] WARNING[16029] db.c: Unable to open Asterisk database '/usr/lib/asterisk/astdb': Permission denied [Nov 29 14:04:12] WARNING[16029] db.c: Unable to open Asterisk database '/usr/lib/asterisk/astdb': Permission denied [Nov 29 14:04:12] DEBUG[16029] pbx.c: Function result is '0' [Nov 29 14:04:12] DEBUG[16029] pbx.c: Expression result is '0' [Nov 29 14:04:12] DEBUG[16029] pbx.c: Launching 'GotoIf' [Nov 29 14:04:12] VERBOSE[16029] pbx.c: -- Executing [6001@sip-6000:1] GotoIf("SIP/6000-00000000", "0?blacklisted:dial") in new stack [Nov 29 14:04:12] VERBOSE[16029] pbx.c: -- Goto (sip-6000,6001,6) [Nov 29 14:04:12] DEBUG[16029] pbx.c: Result of 'EXTEN' is '6001' [Nov 29 14:04:12] DEBUG[16029] pbx.c: Launching 'Goto' [Nov 29 14:04:12] VERBOSE[16029] pbx.c: -- Executing [6001@sip-6000:6] Goto("SIP/6000-00000000", "sip-6000-dial,6001,1") in new stack [Nov 29 14:04:12] VERBOSE[16029] pbx.c: -- Goto (sip-6000-dial,6001,1) [Nov 29 14:04:12] DEBUG[16029] pbx.c: Launching 'NoOp' [Nov 29 14:04:12] VERBOSE[16029] pbx.c: -- Executing [6001@sip-6000-dial:1] NoOp("SIP/6000-00000000", "") in new stack [Nov 29 14:04:12] DEBUG[16029] pbx.c: Result of 'RINGTIME' is '30' [Nov 29 14:04:12] DEBUG[16029] pbx.c: Launching 'Dial' [Nov 29 14:04:12] VERBOSE[16029] pbx.c: -- Executing [6001@sip-6000-dial:2] Dial("SIP/6000-00000000", "SIP/6001, 30, kKtT") in new stack [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Allocating new SIP dialog for 7af4017e19e7527c0da2e8f6476b0666@127.0.1.1:5060 - INVITE (No RTP) [Nov 29 14:04:12] DEBUG[16029] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x987fff8' [Nov 29 14:04:12] DEBUG[16029] res_rtp_asterisk.c: Allocated port 19878 for RTP instance '0x987fff8' [Nov 29 14:04:12] DEBUG[16029] rtp_engine.c: RTP instance '0x987fff8' is setup and ready to go [Nov 29 14:04:12] DEBUG[16029] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x987fff8' [Nov 29 14:04:12] VERBOSE[16029] netsock2.c: == Using SIP RTP CoS mark 5 [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Setting NAT on RTP to Off [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Nov 29 14:04:12] DEBUG[16029] acl.c: For destination '192.168.10.187', our source address is '192.168.10.193'. [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.10.193:5060 [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: *** Our capabilities are 0x90d (g723|ulaw|alaw|g726|g729) [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: This channel will not be able to handle video. [Nov 29 14:04:12] DEBUG[16029] rtp_engine.c: Seeded SDP of 'SIP/6001-00000001' with that of 'SIP/6000-00000000' [Nov 29 14:04:12] DEBUG[16029] channel.c: Not copying variable DIALEDTIME. [Nov 29 14:04:12] DEBUG[16029] channel.c: Not copying variable ANSWEREDTIME. [Nov 29 14:04:12] DEBUG[16029] channel.c: Not copying variable DIALEDPEERNAME. [Nov 29 14:04:12] DEBUG[16029] channel.c: Not copying variable DIALEDPEERNUMBER. [Nov 29 14:04:12] DEBUG[16029] channel.c: Not copying variable DIALSTATUS. [Nov 29 14:04:12] DEBUG[16029] channel.c: Not copying variable SIPCALLID. [Nov 29 14:04:12] DEBUG[16029] channel.c: Not copying variable SIPDOMAIN. [Nov 29 14:04:12] DEBUG[16029] channel.c: Not copying variable SIPURI. [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Outgoing Call for 6001 [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Updating call counter for outgoing call [Nov 29 14:04:12] WARNING[16029] chan_sip.c: before xmitres = transmit_invite [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: ** Our capability: 0x80c (ulaw|alaw|g726) Video flag: False Text flag: False [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Nov 29 14:04:12] VERBOSE[16029] chan_sip.c: Audio is at 19878 [Nov 29 14:04:12] VERBOSE[16029] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Nov 29 14:04:12] VERBOSE[16029] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Nov 29 14:04:12] VERBOSE[16029] chan_sip.c: Adding codec 0x800 (g726) to SDP [Nov 29 14:04:12] VERBOSE[16029] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: -- Done with adding codecs to SDP [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Done building SDP. Settling with this capability: 0x80c (ulaw|alaw|g726) [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Initializing initreq for method INVITE - callid 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 0 [ 70]: INVITE sip:6001@192.168.10.187:5060;rinstance=cfacc6a0bc8a83b3 SIP/2.0 [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK63fa523e [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 3 [ 53]: From: "6000" ;tag=as19bb85ac [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 4 [ 61]: To: [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 5 [ 39]: Contact: [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 6 [ 61]: Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 8 [ 15]: User-Agent: PBX [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 9 [ 35]: Date: Thu, 29 Nov 2012 14:04:12 GMT [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Nov 29 14:04:12] VERBOSE[16029] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.10.187:5060: INVITE sip:6001@192.168.10.187:5060;rinstance=cfacc6a0bc8a83b3 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK63fa523e Max-Forwards: 70 From: "6000" ;tag=as19bb85ac To: Contact: Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 CSeq: 102 INVITE User-Agent: PBX Date: Thu, 29 Nov 2012 14:04:12 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 323 v=0 o=root 1249783405 1249783405 IN IP4 192.168.10.193 s=Asterisk PBX 1.8.16.0 c=IN IP4 192.168.10.193 t=0 0 m=audio 19878 RTP/AVP 0 8 111 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #16 [Nov 29 14:04:12] DEBUG[16029] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.10.187:5060 [Nov 29 14:04:12] WARNING[16029] chan_sip.c: after xmitres = transmit_invite [Nov 29 14:04:12] WARNING[16029] chan_sip.c: before return [Nov 29 14:04:12] VERBOSE[16029] app_dial.c: -- Called SIP/6001 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: SIP TIMER: Rescheduling retransmission #16 (1) INVITE - 5 [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #16)) [Nov 29 14:04:12] VERBOSE[2142] chan_sip.c: Retransmitting #1 (no NAT) to 192.168.10.187:5060: INVITE sip:6001@192.168.10.187:5060;rinstance=cfacc6a0bc8a83b3 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK63fa523e Max-Forwards: 70 From: "6000" ;tag=as19bb85ac To: Contact: Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 CSeq: 102 INVITE User-Agent: PBX Date: Thu, 29 Nov 2012 14:04:12 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 323 v=0 o=root 1249783405 1249783405 IN IP4 192.168.10.193 s=Asterisk PBX 1.8.16.0 c=IN IP4 192.168.10.193 t=0 0 m=audio 19878 RTP/AVP 0 8 111 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Nov 29 14:04:12] DEBUG[2142] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.10.187:5060 [Nov 29 14:04:13] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK63fa523e To: From: "6000" ;tag=as19bb85ac Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 CSeq: 102 INVITE Content-Length: 0 <-------------> [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK63fa523e [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 2 [ 61]: To: [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 3 [ 53]: From: "6000" ;tag=as19bb85ac [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 4 [ 61]: Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Nov 29 14:04:13] VERBOSE[2142] chan_sip.c: --- (7 headers 0 lines) --- [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: = Looking for Call ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 (Checking To) --From tag as19bb85ac --To-tag [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: *** SIP TIMER: Cancelling retransmission #16 - INVITE (got response) [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060' Request 102: Found [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: SIP response 100 to standard invite [Nov 29 14:04:13] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK63fa523e Contact: To: ;tag=34536a04 From: "6000";tag=as19bb85ac Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 CSeq: 102 INVITE User-Agent: X-Lite release 5.0.0 stamp 67284 Content-Length: 0 <-------------> [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK63fa523e [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 2 [ 66]: Contact: [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 3 [ 74]: To: ;tag=34536a04 [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 4 [ 52]: From: "6000";tag=as19bb85ac [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 5 [ 61]: Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 7 [ 44]: User-Agent: X-Lite release 5.0.0 stamp 67284 [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Nov 29 14:04:13] VERBOSE[2142] chan_sip.c: --- (9 headers 0 lines) --- [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: = Looking for Call ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 (Checking To) --From tag as19bb85ac --To-tag 34536a04 [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060' Request 102: Found [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: SIP response 180 to standard invite [Nov 29 14:04:13] WARNING[2142] chan_sip.c: build_route 180-182 Ok reinvite:0 [Nov 29 14:04:13] DEBUG[2142] chan_sip.c: build_route: Contact hop: [Nov 29 14:04:13] VERBOSE[2142] chan_sip.c: list_route: hop: [Nov 29 14:04:13] DEBUG[2129] devicestate.c: No provider found, checking channel drivers for SIP - 6001 [Nov 29 14:04:13] VERBOSE[16029] app_dial.c: -- SIP/6001-00000001 is ringing [Nov 29 14:04:13] DEBUG[2129] chan_sip.c: Checking device state for peer 6001 [Nov 29 14:04:13] DEBUG[16029] rtp_engine.c: Setting early bridge SDP of 'SIP/6000-00000000' with that of 'SIP/6001-00000001' [Nov 29 14:04:13] DEBUG[2129] devicestate.c: Changing state for SIP/6001 - state 1 (Not in use) [Nov 29 14:04:13] DEBUG[2129] devicestate.c: device 'SIP/6001' state '1' [Nov 29 14:04:13] VERBOSE[16029] chan_sip.c: <--- Transmitting (no NAT) to 192.168.10.207:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-b6859760b639c709-1---d8754z-;received=192.168.10.207;rport=5060 From: "6000";tag=f53346dc To: ;tag=as3abea8d1 Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. CSeq: 2 INVITE Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Nov 29 14:04:13] DEBUG[16029] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 192.168.10.207:5060 [Nov 29 14:04:13] DEBUG[16029] channel.c: Driver for channel 'SIP/6000-00000000' does not support indication 3, emulating it [Nov 29 14:04:13] DEBUG[16029] channel.c: Set channel SIP/6000-00000000 to write format slin [Nov 29 14:04:13] DEBUG[16029] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Nov 29 14:04:13] DEBUG[16029] channel.c: Prodding channel 'SIP/6000-00000000' [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Received frame with no data for RTP instance '0x982ff40' so dropping frame [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x982ff40' [Nov 29 14:04:13] DEBUG[16029] res_timing_timerfd.c: Expected to acknowledge 1 ticks but got 3 instead [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:13] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:14] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:15] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:16] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Got RTCP report of 132 bytes [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK63fa523e Contact: To: ;tag=34536a04 From: "6000";tag=as19bb85ac Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 CSeq: 102 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp Supported: replaces User-Agent: X-Lite release 5.0.0 stamp 67284 Content-Length: 215 v=0 o=- 12998675054433129 1 IN IP4 192.168.10.187 s=CounterPath X-Lite 5.0.0 c=IN IP4 192.168.10.187 b=AS:1638 t=0 0 m=audio 5062 RTP/AVP 0 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK63fa523e [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 2 [ 66]: Contact: [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 3 [ 74]: To: ;tag=34536a04 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 4 [ 52]: From: "6000";tag=as19bb85ac [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 5 [ 61]: Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 7 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 8 [ 29]: Content-Type: application/sdp [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 9 [ 19]: Supported: replaces [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 10 [ 44]: User-Agent: X-Lite release 5.0.0 stamp 67284 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 11 [ 19]: Content-Length: 215 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 12 [ 0]: [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Body 0 [ 3]: v=0 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Body 1 [ 45]: o=- 12998675054433129 1 IN IP4 192.168.10.187 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Body 2 [ 26]: s=CounterPath X-Lite 5.0.0 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.10.187 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Body 4 [ 9]: b=AS:1638 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Body 5 [ 5]: t=0 0 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Body 6 [ 26]: m=audio 5062 RTP/AVP 0 101 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-15 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Body 9 [ 10]: a=sendrecv [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: --- (12 headers 10 lines) --- [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: = Looking for Call ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 (Checking To) --From tag as19bb85ac --To-tag 34536a04 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Acked pending invite 102 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Stopping retransmission on '2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060' of Request 102: Match Found [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: SIP response 200 to standard invite [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Processing session-level SDP o=- 12998675054433129 1 IN IP4 192.168.10.187... UNSUPPORTED OR FAILED. [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Processing session-level SDP s=CounterPath X-Lite 5.0.0... UNSUPPORTED OR FAILED. [Nov 29 14:04:17] DEBUG[2142] netsock2.c: Splitting '192.168.10.187' into... [Nov 29 14:04:17] DEBUG[2142] netsock2.c: ...host '192.168.10.187' and port ''. [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.10.187... OK. [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Processing session-level SDP b=AS:1638... UNSUPPORTED OR FAILED. [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: Found RTP audio format 0 [Nov 29 14:04:17] DEBUG[2142] rtp_engine.c: Setting payload 0 based on m type on 0xb69e5eb4 [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: Found RTP audio format 101 [Nov 29 14:04:17] DEBUG[2142] rtp_engine.c: Setting payload 101 based on m type on 0xb69e5eb4 [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: Found audio description format telephone-event for ID 101 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Nov 29 14:04:17] DEBUG[2142] rtp_engine.c: Incorporating payload 0 on 0xb69e5eb4 [Nov 29 14:04:17] DEBUG[2142] rtp_engine.c: Incorporating payload 101 on 0xb69e5eb4 [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: Capabilities: us - 0x90d (g723|ulaw|alaw|g726|g729), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw) [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Nov 29 14:04:17] DEBUG[2142] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x987fff8' [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: Peer audio RTP is at port 192.168.10.187:5062 [Nov 29 14:04:17] DEBUG[2142] rtp_engine.c: Copying payload 0 from 0xb69e5eb4 to 0x98801a4 [Nov 29 14:04:17] DEBUG[2142] rtp_engine.c: Copying payload 101 from 0xb69e5eb4 to 0x98801a4 [Nov 29 14:04:17] DEBUG[2142] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x987fff8' [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: We have an owner, now see if we need to change this call [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Updating call counter for outgoing call [Nov 29 14:04:17] WARNING[2142] chan_sip.c: build_route 200 Ok [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: build_route: Contact hop: [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: list_route: hop: [Nov 29 14:04:17] DEBUG[2142] netsock2.c: Splitting '192.168.10.187:5060' into... [Nov 29 14:04:17] DEBUG[2142] netsock2.c: ...host '192.168.10.187' and port '5060'. [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Strict routing enforced for session 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: set_destination: Parsing for address/port to send to [Nov 29 14:04:17] DEBUG[2142] netsock2.c: Splitting '192.168.10.187:5060' into... [Nov 29 14:04:17] DEBUG[2142] netsock2.c: ...host '192.168.10.187' and port '5060'. [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: set_destination: set destination to 192.168.10.187:5060 [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: Transmitting (no NAT) to 192.168.10.187:5060: ACK sip:6001@192.168.10.187:5060;rinstance=cfacc6a0bc8a83b3 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK6cb5ecfd Max-Forwards: 70 From: "6000" ;tag=as19bb85ac To: ;tag=34536a04 Contact: Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 CSeq: 102 ACK User-Agent: PBX Content-Length: 0 --- [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Trying to put 'ACK sip:600' onto UDP socket destined for 192.168.10.187:5060 [Nov 29 14:04:17] VERBOSE[16029] app_dial.c: -- SIP/6001-00000001 answered SIP/6000-00000000 [Nov 29 14:04:17] DEBUG[2129] devicestate.c: No provider found, checking channel drivers for SIP - 6001 [Nov 29 14:04:17] DEBUG[2129] chan_sip.c: Checking device state for peer 6001 [Nov 29 14:04:17] DEBUG[2129] devicestate.c: Changing state for SIP/6001 - state 1 (Not in use) [Nov 29 14:04:17] DEBUG[2129] devicestate.c: device 'SIP/6001' state '1' [Nov 29 14:04:17] DEBUG[16029] channel.c: Set channel SIP/6000-00000000 to write format ulaw [Nov 29 14:04:17] DEBUG[16029] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 29 14:04:17] DEBUG[16029] chan_sip.c: SIP answering channel: SIP/6000-00000000 [Nov 29 14:04:17] DEBUG[2129] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[2129] chan_sip.c: Checking device state for peer 6000 [Nov 29 14:04:17] DEBUG[2129] devicestate.c: Changing state for SIP/6000 - state 1 (Not in use) [Nov 29 14:04:17] DEBUG[2129] devicestate.c: device 'SIP/6000' state '1' [Nov 29 14:04:17] DEBUG[16029] chan_sip.c: Setting framing from config on incoming call [Nov 29 14:04:17] DEBUG[16029] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: True Text flag: True [Nov 29 14:04:17] DEBUG[16029] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Nov 29 14:04:17] VERBOSE[16029] chan_sip.c: Audio is at 19890 [Nov 29 14:04:17] VERBOSE[16029] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Nov 29 14:04:17] VERBOSE[16029] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Nov 29 14:04:17] DEBUG[16029] chan_sip.c: -- Done with adding codecs to SDP [Nov 29 14:04:17] DEBUG[16029] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [Nov 29 14:04:17] VERBOSE[16029] chan_sip.c: <--- Reliably Transmitting (no NAT) to 192.168.10.207:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-b6859760b639c709-1---d8754z-;received=192.168.10.207;rport=5060 From: "6000";tag=f53346dc To: ;tag=as3abea8d1 Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. CSeq: 2 INVITE Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 266 v=0 o=root 892881156 892881156 IN IP4 192.168.10.193 s=Asterisk PBX 1.8.16.0 c=IN IP4 192.168.10.193 t=0 0 m=audio 19890 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Nov 29 14:04:17] DEBUG[16029] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #20 [Nov 29 14:04:17] DEBUG[16029] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.10.207:5060 [Nov 29 14:04:17] DEBUG[16029] features.c: bridge answer set, chan answer set [Nov 29 14:04:17] DEBUG[16029] features.c: Removing dialed interfaces datastore on SIP/6001-00000001 since we're bridging [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.207:5060 ---> ACK sip:6001@192.168.10.193:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-b4d6a6cdd7829968-1---d8754z-;rport Max-Forwards: 70 Contact: To: ;tag=as3abea8d1 From: "6000";tag=f53346dc Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. CSeq: 2 ACK User-Agent: X-Lite release 5.0.0 stamp 67284 Authorization: Digest username="6000",realm="asterisk",nonce="616acadb",uri="sip:6001@192.168.10.193",response="e1b67df78ddaa05ab074c22d8f8deabe",algorithm=MD5 Content-Length: 0 <-------------> [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 0 [ 40]: ACK sip:6001@192.168.10.193:5060 SIP/2.0 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 1 [ 93]: Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-b4d6a6cdd7829968-1---d8754z-;rport [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 3 [ 39]: Contact: [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 4 [ 44]: To: ;tag=as3abea8d1 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 5 [ 50]: From: "6000";tag=f53346dc [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 6 [ 53]: Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 7 [ 11]: CSeq: 2 ACK [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 8 [ 44]: User-Agent: X-Lite release 5.0.0 stamp 67284 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 9 [159]: Authorization: Digest username="6000",realm="asterisk",nonce="616acadb",uri="sip:6001@192.168.10.193",response="e1b67df78ddaa05ab074c22d8f8deabe",algorithm=MD5 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Nov 29 14:04:17] VERBOSE[2142] chan_sip.c: --- (11 headers 0 lines) --- [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: = Looking for Call ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. (Checking From) --From tag f53346dc --To-tag as3abea8d1 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #20 [Nov 29 14:04:17] DEBUG[2142] chan_sip.c: Stopping retransmission on 'N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU.' of Response 2: Match Found [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [Nov 29 14:04:17] DEBUG[16029] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [Nov 29 14:04:18] DEBUG[16029] res_rtp_asterisk.c: Got RTCP report of 176 bytes [Nov 29 14:04:18] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> <-------------> [Nov 29 14:04:18] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Got RTCP report of 176 bytes [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 42 (*), at 192.168.10.187:5062 [Nov 29 14:04:21] DTMF[16029] channel.c: DTMF begin '*' received on SIP/6001-00000001 [Nov 29 14:04:21] DTMF[16029] channel.c: DTMF begin passthrough '*' on SIP/6001-00000001 [Nov 29 14:04:21] DEBUG[16029] channel.c: Got DTMF begin on channel (SIP/6001-00000001) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] channel.c: Bridge stops bridging channels SIP/6000-00000000 and SIP/6001-00000001 [Nov 29 14:04:21] DEBUG[16029] features.c: Not passing DTMF through, since it may be a feature code [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Got RTCP report of 176 bytes [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Creating END DTMF Frame: 42 (*), at 192.168.10.187:5062 [Nov 29 14:04:21] DTMF[16029] channel.c: DTMF end '*' received on SIP/6001-00000001, duration 160 ms [Nov 29 14:04:21] DTMF[16029] channel.c: DTMF end accepted with begin '*' on SIP/6001-00000001 [Nov 29 14:04:21] DTMF[16029] channel.c: DTMF end passthrough '*' on SIP/6001-00000001 [Nov 29 14:04:21] DEBUG[16029] channel.c: Got DTMF end on channel (SIP/6001-00000001) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] channel.c: Bridge stops bridging channels SIP/6000-00000000 and SIP/6001-00000001 [Nov 29 14:04:21] DEBUG[16029] features.c: Feature interpret: chan=SIP/6000-00000000, peer=SIP/6001-00000001, code=*, sense=2, features=34, dynamic=# [Nov 29 14:04:21] DEBUG[16029] features.c: Set feature timer to 1000 ms [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 0000000a (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 50 (2), at 192.168.10.187:5062 [Nov 29 14:04:21] DTMF[16029] channel.c: DTMF begin '2' received on SIP/6001-00000001 [Nov 29 14:04:21] DTMF[16029] channel.c: DTMF begin passthrough '2' on SIP/6001-00000001 [Nov 29 14:04:21] DEBUG[16029] channel.c: Got DTMF begin on channel (SIP/6001-00000001) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] channel.c: Bridge stops bridging channels SIP/6000-00000000 and SIP/6001-00000001 [Nov 29 14:04:21] DEBUG[16029] features.c: Not passing DTMF through, since it may be a feature code [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Creating END DTMF Frame: 50 (2), at 192.168.10.187:5062 [Nov 29 14:04:21] DTMF[16029] channel.c: DTMF end '2' received on SIP/6001-00000001, duration 100 ms [Nov 29 14:04:21] DTMF[16029] channel.c: DTMF end accepted with begin '2' on SIP/6001-00000001 [Nov 29 14:04:21] DTMF[16029] channel.c: DTMF end passthrough '2' on SIP/6001-00000001 [Nov 29 14:04:21] DEBUG[16029] channel.c: Got DTMF end on channel (SIP/6001-00000001) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] DEBUG[16029] channel.c: Bridge stops bridging channels SIP/6000-00000000 and SIP/6001-00000001 [Nov 29 14:04:21] DEBUG[16029] features.c: Feature interpret: chan=SIP/6000-00000000, peer=SIP/6001-00000001, code=*2, sense=2, features=34, dynamic=# [Nov 29 14:04:21] DEBUG[16029] features.c: Feature detected: fname=Attended Transfer sname=atxfer exten=*2 [Nov 29 14:04:21] DEBUG[16029] features.c: Executing Attended Transfer SIP/6000-00000000, SIP/6001-00000001 (sense=2) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: Setting the marker bit due to a source update [Nov 29 14:04:21] VERBOSE[16029] channel.c: -- Music class default requested but no musiconhold loaded. [Nov 29 14:04:21] DEBUG[16029] channel.c: Set channel SIP/6001-00000001 to write format slin [Nov 29 14:04:21] DEBUG[16029] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Nov 29 14:04:21] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000002 (len = 4) [Nov 29 14:04:21] DEBUG[16029] channel.c: Generator got voice, switching to phase locked mode [Nov 29 14:04:21] DEBUG[16029] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 54 (6), at 192.168.10.187:5062 [Nov 29 14:04:23] DTMF[16029] channel.c: DTMF begin '6' received on SIP/6001-00000001 [Nov 29 14:04:23] DTMF[16029] channel.c: DTMF begin ignored '6' on SIP/6001-00000001 [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: Creating END DTMF Frame: 54 (6), at 192.168.10.187:5062 [Nov 29 14:04:23] DTMF[16029] channel.c: DTMF end '6' received on SIP/6001-00000001, duration 180 ms [Nov 29 14:04:23] DTMF[16029] channel.c: DTMF end passthrough '6' on SIP/6001-00000001 [Nov 29 14:04:23] DEBUG[16029] channel.c: Set channel SIP/6001-00000001 to write format ulaw [Nov 29 14:04:23] DEBUG[16029] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000006 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 48 (0), at 192.168.10.187:5062 [Nov 29 14:04:23] DTMF[16029] channel.c: DTMF begin '0' received on SIP/6001-00000001 [Nov 29 14:04:23] DTMF[16029] channel.c: DTMF begin ignored '0' on SIP/6001-00000001 [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: Creating END DTMF Frame: 48 (0), at 192.168.10.187:5062 [Nov 29 14:04:23] DTMF[16029] channel.c: DTMF end '0' received on SIP/6001-00000001, duration 80 ms [Nov 29 14:04:23] DTMF[16029] channel.c: DTMF end passthrough '0' on SIP/6001-00000001 [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 48 (0), at 192.168.10.187:5062 [Nov 29 14:04:23] DTMF[16029] channel.c: DTMF begin '0' received on SIP/6001-00000001 [Nov 29 14:04:23] DTMF[16029] channel.c: DTMF begin ignored '0' on SIP/6001-00000001 [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: Creating END DTMF Frame: 48 (0), at 192.168.10.187:5062 [Nov 29 14:04:23] DTMF[16029] channel.c: DTMF end '0' received on SIP/6001-00000001, duration 120 ms [Nov 29 14:04:23] DTMF[16029] channel.c: DTMF end passthrough '0' on SIP/6001-00000001 [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:23] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000000 (len = 4) [Nov 29 14:04:24] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Nov 29 14:04:24] DEBUG[16029] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 51 (3), at 192.168.10.187:5062 [Nov 29 14:04:24] DTMF[16029] channel.c: DTMF begin '3' received on SIP/6001-00000001 [Nov 29 14:04:24] DTMF[16029] channel.c: DTMF begin ignored '3' on SIP/6001-00000001 [Nov 29 14:04:24] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Nov 29 14:04:24] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Nov 29 14:04:24] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Nov 29 14:04:24] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Nov 29 14:04:24] DEBUG[16030] res_rtp_asterisk.c: Got RTCP report of 176 bytes [Nov 29 14:04:24] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Nov 29 14:04:24] DEBUG[16029] res_rtp_asterisk.c: Creating END DTMF Frame: 51 (3), at 192.168.10.187:5062 [Nov 29 14:04:24] DTMF[16029] channel.c: DTMF end '3' received on SIP/6001-00000001, duration 80 ms [Nov 29 14:04:24] DTMF[16029] channel.c: DTMF end passthrough '3' on SIP/6001-00000001 [Nov 29 14:04:24] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Nov 29 14:04:24] DEBUG[16029] res_rtp_asterisk.c: - RTP 2833 Event: 00000003 (len = 4) [Nov 29 14:04:24] DEBUG[16029] res_rtp_asterisk.c: Got RTCP report of 176 bytes [Nov 29 14:04:27] DEBUG[16030] res_rtp_asterisk.c: Got RTCP report of 176 bytes [Nov 29 14:04:27] DEBUG[16029] features.c: Checking if 6003@sip-6001 is a parking exten [Nov 29 14:04:27] DEBUG[16029] channel.c: Not copying variable BRIDGEPVTCALLID. [Nov 29 14:04:27] DEBUG[16029] channel.c: Not copying variable BRIDGEPEER. [Nov 29 14:04:27] DEBUG[16029] channel.c: Not copying variable DIALEDPEERNUMBER. [Nov 29 14:04:27] DEBUG[16029] channel.c: Not copying variable SIPCALLID. [Nov 29 14:04:27] WARNING[16029] features.c: after ast_call [Nov 29 14:04:27] WARNING[16031] db.c: Unable to open Asterisk database '/usr/lib/asterisk/astdb': Permission denied [Nov 29 14:04:27] WARNING[16031] db.c: Unable to open Asterisk database '/usr/lib/asterisk/astdb': Permission denied [Nov 29 14:04:27] DEBUG[16031] pbx.c: Function result is '0' [Nov 29 14:04:27] DEBUG[16031] pbx.c: Expression result is '0' [Nov 29 14:04:27] DEBUG[16031] pbx.c: Launching 'GotoIf' [Nov 29 14:04:27] VERBOSE[16031] pbx.c: -- Executing [6003@sip-6001:1] GotoIf("Local/6003@sip-6001-e24d;2", "0?blacklisted:dial") in new stack [Nov 29 14:04:27] VERBOSE[16031] pbx.c: -- Goto (sip-6001,6003,6) [Nov 29 14:04:27] DEBUG[16031] pbx.c: Result of 'EXTEN' is '6003' [Nov 29 14:04:27] DEBUG[16031] pbx.c: Launching 'Goto' [Nov 29 14:04:27] VERBOSE[16031] pbx.c: -- Executing [6003@sip-6001:6] Goto("Local/6003@sip-6001-e24d;2", "sip-6001-dial,6003,1") in new stack [Nov 29 14:04:27] VERBOSE[16031] pbx.c: -- Goto (sip-6001-dial,6003,1) [Nov 29 14:04:27] DEBUG[16031] pbx.c: Launching 'NoOp' [Nov 29 14:04:27] VERBOSE[16031] pbx.c: -- Executing [6003@sip-6001-dial:1] NoOp("Local/6003@sip-6001-e24d;2", "") in new stack [Nov 29 14:04:27] DEBUG[16031] pbx.c: Result of 'RINGTIME' is '30' [Nov 29 14:04:27] DEBUG[16031] pbx.c: Launching 'Dial' [Nov 29 14:04:27] VERBOSE[16031] pbx.c: -- Executing [6003@sip-6001-dial:2] Dial("Local/6003@sip-6001-e24d;2", "SIP/6003, 30, kKtT") in new stack [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Allocating new SIP dialog for 5c0c0eb8545df42d5c9d730011a93565@127.0.1.1:5060 - INVITE (No RTP) [Nov 29 14:04:27] DEBUG[16031] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x9884238' [Nov 29 14:04:27] DEBUG[16031] res_rtp_asterisk.c: Allocated port 19892 for RTP instance '0x9884238' [Nov 29 14:04:27] DEBUG[16031] rtp_engine.c: RTP instance '0x9884238' is setup and ready to go [Nov 29 14:04:27] DEBUG[16031] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x9884238' [Nov 29 14:04:27] VERBOSE[16031] netsock2.c: == Using SIP RTP CoS mark 5 [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Setting NAT on RTP to Off [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Nov 29 14:04:27] DEBUG[16031] acl.c: For destination '192.168.10.85', our source address is '192.168.10.193'. [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.10.193:5060 [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: *** Our capabilities are 0x90d (g723|ulaw|alaw|g726|g729) [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: This channel will not be able to handle video. [Nov 29 14:04:27] DEBUG[16031] rtp_engine.c: Can't find native functions for channel 'Local/6003@sip-6001-e24d;2' [Nov 29 14:04:27] DEBUG[16031] rtp_engine.c: Seeded SDP of 'SIP/6003-00000002' with that of 'Local/6003@sip-6001-e24d;2' [Nov 29 14:04:27] DEBUG[16031] channel.c: Not copying variable DIALEDTIME. [Nov 29 14:04:27] DEBUG[16031] channel.c: Not copying variable ANSWEREDTIME. [Nov 29 14:04:27] DEBUG[16031] channel.c: Not copying variable DIALEDPEERNAME. [Nov 29 14:04:27] DEBUG[16031] channel.c: Not copying variable DIALEDPEERNUMBER. [Nov 29 14:04:27] DEBUG[16031] channel.c: Not copying variable DIALSTATUS. [Nov 29 14:04:27] DEBUG[16031] channel.c: Not copying variable TRANSFERERNAME. [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Outgoing Call for 6003 [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Updating call counter for outgoing call [Nov 29 14:04:27] WARNING[16031] chan_sip.c: before xmitres = transmit_invite [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: ** Our capability: 0x80c (ulaw|alaw|g726) Video flag: False Text flag: False [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Nov 29 14:04:27] VERBOSE[16031] chan_sip.c: Audio is at 19892 [Nov 29 14:04:27] VERBOSE[16031] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Nov 29 14:04:27] VERBOSE[16031] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Nov 29 14:04:27] VERBOSE[16031] chan_sip.c: Adding codec 0x800 (g726) to SDP [Nov 29 14:04:27] VERBOSE[16031] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: -- Done with adding codecs to SDP [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Done building SDP. Settling with this capability: 0x80c (ulaw|alaw|g726) [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Initializing initreq for method INVITE - callid 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 0 [ 69]: INVITE sip:6003@192.168.10.85:5060;rinstance=2b4bdcd8252857e2 SIP/2.0 [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK260bd7c8 [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 3 [ 53]: From: "6001" ;tag=as48005683 [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 4 [ 60]: To: [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 5 [ 39]: Contact: [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 6 [ 61]: Call-ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 8 [ 15]: User-Agent: PBX [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 9 [ 35]: Date: Thu, 29 Nov 2012 14:04:27 GMT [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Nov 29 14:04:27] VERBOSE[16031] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.10.85:5060: INVITE sip:6003@192.168.10.85:5060;rinstance=2b4bdcd8252857e2 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK260bd7c8 Max-Forwards: 70 From: "6001" ;tag=as48005683 To: Contact: Call-ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 CSeq: 102 INVITE User-Agent: PBX Date: Thu, 29 Nov 2012 14:04:27 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 321 v=0 o=root 794529009 794529009 IN IP4 192.168.10.193 s=Asterisk PBX 1.8.16.0 c=IN IP4 192.168.10.193 t=0 0 m=audio 19892 RTP/AVP 0 8 111 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #22 [Nov 29 14:04:27] DEBUG[16031] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.10.85:5060 [Nov 29 14:04:27] WARNING[16031] chan_sip.c: after xmitres = transmit_invite [Nov 29 14:04:27] WARNING[16031] chan_sip.c: before return [Nov 29 14:04:27] VERBOSE[16031] app_dial.c: -- Called SIP/6003 [Nov 29 14:04:27] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK260bd7c8 To: From: "6001" ;tag=as48005683 Call-ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 CSeq: 102 INVITE Content-Length: 0 <-------------> [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK260bd7c8 [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 2 [ 60]: To: [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 3 [ 53]: From: "6001" ;tag=as48005683 [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 4 [ 61]: Call-ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Nov 29 14:04:27] VERBOSE[2142] chan_sip.c: --- (7 headers 0 lines) --- [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: = Looking for Call ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 (Checking To) --From tag as48005683 --To-tag [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: *** SIP TIMER: Cancelling retransmission #22 - INVITE (got response) [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060' Request 102: Found [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: SIP response 100 to standard invite [Nov 29 14:04:27] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK260bd7c8 Contact: To: ;tag=280cc372 From: "6001";tag=as48005683 Call-ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 CSeq: 102 INVITE User-Agent: X-Lite release 5.0.0 stamp 67284 Content-Length: 0 <-------------> [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK260bd7c8 [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 2 [ 65]: Contact: [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 3 [ 73]: To: ;tag=280cc372 [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 4 [ 52]: From: "6001";tag=as48005683 [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 5 [ 61]: Call-ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 7 [ 44]: User-Agent: X-Lite release 5.0.0 stamp 67284 [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Nov 29 14:04:27] VERBOSE[2142] chan_sip.c: --- (9 headers 0 lines) --- [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: = Looking for Call ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 (Checking To) --From tag as48005683 --To-tag 280cc372 [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060' Request 102: Found [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: SIP response 180 to standard invite [Nov 29 14:04:27] WARNING[2142] chan_sip.c: build_route 180-182 Ok reinvite:0 [Nov 29 14:04:27] DEBUG[2142] chan_sip.c: build_route: Contact hop: [Nov 29 14:04:27] VERBOSE[2142] chan_sip.c: list_route: hop: [Nov 29 14:04:27] DEBUG[2129] devicestate.c: No provider found, checking channel drivers for SIP - 6003 [Nov 29 14:04:27] DEBUG[2129] chan_sip.c: Checking device state for peer 6003 [Nov 29 14:04:27] DEBUG[2129] devicestate.c: Changing state for SIP/6003 - state 1 (Not in use) [Nov 29 14:04:27] DEBUG[2129] devicestate.c: device 'SIP/6003' state '1' [Nov 29 14:04:36] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK260bd7c8 Contact: To: ;tag=280cc372 From: "6001";tag=as48005683 Call-ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 CSeq: 102 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp Supported: replaces User-Agent: X-Lite release 5.0.0 stamp 67284 Content-Length: 213 v=0 o=- 12998671475695514 1 IN IP4 192.168.10.85 s=CounterPath X-Lite 5.0.0 c=IN IP4 192.168.10.85 b=AS:1638 t=0 0 m=audio 5062 RTP/AVP 0 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK260bd7c8 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 2 [ 65]: Contact: [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 3 [ 73]: To: ;tag=280cc372 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 4 [ 52]: From: "6001";tag=as48005683 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 5 [ 61]: Call-ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 7 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 8 [ 29]: Content-Type: application/sdp [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 9 [ 19]: Supported: replaces [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 10 [ 44]: User-Agent: X-Lite release 5.0.0 stamp 67284 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 11 [ 19]: Content-Length: 213 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Header 12 [ 0]: [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Body 0 [ 3]: v=0 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Body 1 [ 44]: o=- 12998671475695514 1 IN IP4 192.168.10.85 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Body 2 [ 26]: s=CounterPath X-Lite 5.0.0 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Body 3 [ 22]: c=IN IP4 192.168.10.85 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Body 4 [ 9]: b=AS:1638 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Body 5 [ 5]: t=0 0 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Body 6 [ 26]: m=audio 5062 RTP/AVP 0 101 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-15 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Body 9 [ 10]: a=sendrecv [Nov 29 14:04:36] VERBOSE[2142] chan_sip.c: --- (12 headers 10 lines) --- [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: = Looking for Call ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 (Checking To) --From tag as48005683 --To-tag 280cc372 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Acked pending invite 102 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Stopping retransmission on '77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060' of Request 102: Match Found [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: SIP response 200 to standard invite [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Processing session-level SDP o=- 12998671475695514 1 IN IP4 192.168.10.85... UNSUPPORTED OR FAILED. [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Processing session-level SDP s=CounterPath X-Lite 5.0.0... UNSUPPORTED OR FAILED. [Nov 29 14:04:36] DEBUG[2142] netsock2.c: Splitting '192.168.10.85' into... [Nov 29 14:04:36] DEBUG[2142] netsock2.c: ...host '192.168.10.85' and port ''. [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.10.85... OK. [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Processing session-level SDP b=AS:1638... UNSUPPORTED OR FAILED. [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Nov 29 14:04:36] VERBOSE[2142] chan_sip.c: Found RTP audio format 0 [Nov 29 14:04:36] DEBUG[2142] rtp_engine.c: Setting payload 0 based on m type on 0xb69e5eb4 [Nov 29 14:04:36] VERBOSE[2142] chan_sip.c: Found RTP audio format 101 [Nov 29 14:04:36] DEBUG[2142] rtp_engine.c: Setting payload 101 based on m type on 0xb69e5eb4 [Nov 29 14:04:36] VERBOSE[2142] chan_sip.c: Found audio description format telephone-event for ID 101 [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Nov 29 14:04:36] DEBUG[2142] rtp_engine.c: Incorporating payload 0 on 0xb69e5eb4 [Nov 29 14:04:36] DEBUG[2142] rtp_engine.c: Incorporating payload 101 on 0xb69e5eb4 [Nov 29 14:04:36] VERBOSE[2142] chan_sip.c: Capabilities: us - 0x90d (g723|ulaw|alaw|g726|g729), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw) [Nov 29 14:04:36] VERBOSE[2142] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Nov 29 14:04:36] DEBUG[2142] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9884238' [Nov 29 14:04:36] VERBOSE[2142] chan_sip.c: Peer audio RTP is at port 192.168.10.85:5062 [Nov 29 14:04:36] DEBUG[2142] rtp_engine.c: Copying payload 0 from 0xb69e5eb4 to 0x98843e4 [Nov 29 14:04:36] DEBUG[2142] rtp_engine.c: Copying payload 101 from 0xb69e5eb4 to 0x98843e4 [Nov 29 14:04:36] DEBUG[2142] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x9884238' [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: We have an owner, now see if we need to change this call [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Updating call counter for outgoing call [Nov 29 14:04:36] WARNING[2142] chan_sip.c: build_route 200 Ok [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: build_route: Contact hop: [Nov 29 14:04:36] VERBOSE[2142] chan_sip.c: list_route: hop: [Nov 29 14:04:36] DEBUG[2142] netsock2.c: Splitting '192.168.10.85:5060' into... [Nov 29 14:04:36] DEBUG[2142] netsock2.c: ...host '192.168.10.85' and port '5060'. [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Strict routing enforced for session 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 [Nov 29 14:04:36] VERBOSE[2142] chan_sip.c: set_destination: Parsing for address/port to send to [Nov 29 14:04:36] DEBUG[2142] netsock2.c: Splitting '192.168.10.85:5060' into... [Nov 29 14:04:36] DEBUG[2142] netsock2.c: ...host '192.168.10.85' and port '5060'. [Nov 29 14:04:36] VERBOSE[2142] chan_sip.c: set_destination: set destination to 192.168.10.85:5060 [Nov 29 14:04:36] VERBOSE[2142] chan_sip.c: Transmitting (no NAT) to 192.168.10.85:5060: ACK sip:6003@192.168.10.85:5060;rinstance=2b4bdcd8252857e2 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.193:5060;branch=z9hG4bK34d37669 Max-Forwards: 70 From: "6001" ;tag=as48005683 To: ;tag=280cc372 Contact: Call-ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 CSeq: 102 ACK User-Agent: PBX Content-Length: 0 --- [Nov 29 14:04:36] DEBUG[2142] chan_sip.c: Trying to put 'ACK sip:600' onto UDP socket destined for 192.168.10.85:5060 [Nov 29 14:04:39] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> <-------------> [Nov 29 14:04:39] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:04:44] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> BYE sip:6001@192.168.10.193:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.187:5060;branch=z9hG4bK-d8754z-a261ee283cfee48e-1---d8754z-;rport Max-Forwards: 70 Contact: To: "6000";tag=as19bb85ac From: ;tag=34536a04 Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 CSeq: 2 BYE User-Agent: X-Lite release 5.0.0 stamp 67284 Content-Length: 0 <-------------> [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Header 0 [ 40]: BYE sip:6001@192.168.10.193:5060 SIP/2.0 [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Header 1 [ 93]: Via: SIP/2.0/UDP 192.168.10.187:5060;branch=z9hG4bK-d8754z-a261ee283cfee48e-1---d8754z-;rport [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Header 3 [ 66]: Contact: [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Header 4 [ 50]: To: "6000";tag=as19bb85ac [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Header 5 [ 76]: From: ;tag=34536a04 [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Header 6 [ 61]: Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Header 7 [ 11]: CSeq: 2 BYE [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Header 8 [ 44]: User-Agent: X-Lite release 5.0.0 stamp 67284 [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Nov 29 14:04:44] VERBOSE[2142] chan_sip.c: --- (10 headers 0 lines) --- [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: = Looking for Call ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 (Checking From) --From tag 34536a04 --To-tag as19bb85ac [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Initializing initreq for method BYE - callid 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 [Nov 29 14:04:44] DEBUG[2142] netsock2.c: Splitting '192.168.10.187:5060' into... [Nov 29 14:04:44] DEBUG[2142] netsock2.c: ...host '192.168.10.187' and port '5060'. [Nov 29 14:04:44] VERBOSE[2142] chan_sip.c: Sending to 192.168.10.187:5060 (no NAT) [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Setting SIP_ALREADYGONE on dialog 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 [Nov 29 14:04:44] DEBUG[2142] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x987fff8' [Nov 29 14:04:44] VERBOSE[2142] chan_sip.c: Scheduling destruction of SIP dialog '2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060' in 32000 ms (Method: BYE) [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Received bye, issuing owner hangup [Nov 29 14:04:44] VERBOSE[2142] chan_sip.c: <--- Transmitting (no NAT) to 192.168.10.187:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.187:5060;branch=z9hG4bK-d8754z-a261ee283cfee48e-1---d8754z-;received=192.168.10.187;rport=5060 From: ;tag=34536a04 To: "6000";tag=as19bb85ac Call-ID: 2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060 CSeq: 2 BYE Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [Nov 29 14:04:44] DEBUG[2142] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.10.187:5060 [Nov 29 14:04:48] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> <-------------> [Nov 29 14:04:48] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:04:51] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> BYE sip:6003@192.168.10.193:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.85:5060;branch=z9hG4bK-d8754z-297f7179acd70218-1---d8754z-;rport Max-Forwards: 70 Contact: To: "6001";tag=as48005683 From: ;tag=280cc372 Call-ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 CSeq: 2 BYE User-Agent: X-Lite release 5.0.0 stamp 67284 Content-Length: 0 <-------------> [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Header 0 [ 40]: BYE sip:6003@192.168.10.193:5060 SIP/2.0 [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/UDP 192.168.10.85:5060;branch=z9hG4bK-d8754z-297f7179acd70218-1---d8754z-;rport [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Header 3 [ 65]: Contact: [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Header 4 [ 50]: To: "6001";tag=as48005683 [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Header 5 [ 75]: From: ;tag=280cc372 [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Header 6 [ 61]: Call-ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Header 7 [ 11]: CSeq: 2 BYE [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Header 8 [ 44]: User-Agent: X-Lite release 5.0.0 stamp 67284 [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Nov 29 14:04:51] VERBOSE[2142] chan_sip.c: --- (10 headers 0 lines) --- [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: = Looking for Call ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 (Checking From) --From tag 280cc372 --To-tag as48005683 [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Initializing initreq for method BYE - callid 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 [Nov 29 14:04:51] DEBUG[2142] netsock2.c: Splitting '192.168.10.85:5060' into... [Nov 29 14:04:51] DEBUG[2142] netsock2.c: ...host '192.168.10.85' and port '5060'. [Nov 29 14:04:51] VERBOSE[2142] chan_sip.c: Sending to 192.168.10.85:5060 (no NAT) [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Setting SIP_ALREADYGONE on dialog 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 [Nov 29 14:04:51] DEBUG[2142] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9884238' [Nov 29 14:04:51] VERBOSE[2142] chan_sip.c: Scheduling destruction of SIP dialog '77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060' in 32000 ms (Method: BYE) [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Received bye, issuing owner hangup [Nov 29 14:04:51] VERBOSE[2142] chan_sip.c: <--- Transmitting (no NAT) to 192.168.10.85:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.85:5060;branch=z9hG4bK-d8754z-297f7179acd70218-1---d8754z-;received=192.168.10.85;rport=5060 From: ;tag=280cc372 To: "6001";tag=as48005683 Call-ID: 77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060 CSeq: 2 BYE Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [Nov 29 14:04:51] DEBUG[2142] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.10.85:5060 [Nov 29 14:04:54] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.207:5060 ---> BYE sip:6001@192.168.10.193:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-888221dc66ee3369-1---d8754z-;rport Max-Forwards: 70 Contact: To: ;tag=as3abea8d1 From: "6000";tag=f53346dc Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. CSeq: 3 BYE User-Agent: X-Lite release 5.0.0 stamp 67284 Authorization: Digest username="6000",realm="asterisk",nonce="616acadb",uri="sip:6001@192.168.10.193:5060",response="2001ff9091c983694bd6014914761e08",algorithm=MD5 Content-Length: 0 <-------------> [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Header 0 [ 40]: BYE sip:6001@192.168.10.193:5060 SIP/2.0 [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Header 1 [ 93]: Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-888221dc66ee3369-1---d8754z-;rport [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Header 3 [ 39]: Contact: [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Header 4 [ 44]: To: ;tag=as3abea8d1 [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Header 5 [ 50]: From: "6000";tag=f53346dc [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Header 6 [ 53]: Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Header 7 [ 11]: CSeq: 3 BYE [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Header 8 [ 44]: User-Agent: X-Lite release 5.0.0 stamp 67284 [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Header 9 [164]: Authorization: Digest username="6000",realm="asterisk",nonce="616acadb",uri="sip:6001@192.168.10.193:5060",response="2001ff9091c983694bd6014914761e08",algorithm=MD5 [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Nov 29 14:04:54] VERBOSE[2142] chan_sip.c: --- (11 headers 0 lines) --- [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: = Looking for Call ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. (Checking From) --From tag f53346dc --To-tag as3abea8d1 [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Initializing initreq for method BYE - callid N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. [Nov 29 14:04:54] DEBUG[2142] netsock2.c: Splitting '192.168.10.207:5060' into... [Nov 29 14:04:54] DEBUG[2142] netsock2.c: ...host '192.168.10.207' and port '5060'. [Nov 29 14:04:54] VERBOSE[2142] chan_sip.c: Sending to 192.168.10.207:5060 (no NAT) [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Setting SIP_ALREADYGONE on dialog N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. [Nov 29 14:04:54] DEBUG[2142] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x982ff40' [Nov 29 14:04:54] VERBOSE[2142] chan_sip.c: Scheduling destruction of SIP dialog 'N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU.' in 32000 ms (Method: BYE) [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Received bye, issuing owner hangup [Nov 29 14:04:54] VERBOSE[2142] chan_sip.c: <--- Transmitting (no NAT) to 192.168.10.207:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bK-d8754z-888221dc66ee3369-1---d8754z-;received=192.168.10.207;rport=5060 From: "6000";tag=f53346dc To: ;tag=as3abea8d1 Call-ID: N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU. CSeq: 3 BYE Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [Nov 29 14:04:54] DEBUG[2142] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.10.207:5060 [Nov 29 14:05:09] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> <-------------> [Nov 29 14:05:09] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:05:16] WARNING[2142] chan_sip.c: Autodestruct on dialog '2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms [Nov 29 14:05:18] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> <-------------> [Nov 29 14:05:18] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:05:23] WARNING[2142] chan_sip.c: Autodestruct on dialog '77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms [Nov 29 14:05:26] WARNING[2142] chan_sip.c: Autodestruct on dialog 'N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU.' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms [Nov 29 14:05:39] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> <-------------> [Nov 29 14:05:39] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:05:48] WARNING[2142] chan_sip.c: Autodestruct on dialog '2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms [Nov 29 14:05:48] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> <-------------> [Nov 29 14:05:48] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:05:55] WARNING[2142] chan_sip.c: Autodestruct on dialog '77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms [Nov 29 14:05:58] WARNING[2142] chan_sip.c: Autodestruct on dialog 'N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU.' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms [Nov 29 14:06:09] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> <-------------> [Nov 29 14:06:09] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:06:18] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> <-------------> [Nov 29 14:06:18] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:06:20] WARNING[2142] chan_sip.c: Autodestruct on dialog '2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms [Nov 29 14:06:27] WARNING[2142] chan_sip.c: Autodestruct on dialog '77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms [Nov 29 14:06:30] WARNING[2142] chan_sip.c: Autodestruct on dialog 'N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU.' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms [Nov 29 14:06:39] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> <-------------> [Nov 29 14:06:39] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:06:48] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> <-------------> [Nov 29 14:06:48] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:06:52] WARNING[2142] chan_sip.c: Autodestruct on dialog '2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms [Nov 29 14:06:59] WARNING[2142] chan_sip.c: Autodestruct on dialog '77c653b72cfbb73d1f921fa97c1cbb5d@192.168.10.193:5060' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms [Nov 29 14:07:02] WARNING[2142] chan_sip.c: Autodestruct on dialog 'N2MwMjRjNjUyYmI3MzM5YmYzMDc1ODE5NGVlMGNlZmU.' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms [Nov 29 14:07:09] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.187:5060 ---> <-------------> [Nov 29 14:07:09] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:07:18] VERBOSE[2142] chan_sip.c: <--- SIP read from UDP:192.168.10.85:5060 ---> <-------------> [Nov 29 14:07:18] DEBUG[2142] chan_sip.c: Header 0 [ 0]: [Nov 29 14:07:24] WARNING[2142] chan_sip.c: Autodestruct on dialog '2112629f345d2bc27876a4af6a8525c5@192.168.10.193:5060' with owner in place (Method: BYE). Rescheduling destruction for 10000 ms