[Aug 30 13:27:09] DEBUG[27930] pbx.c: Launching 'Dial' [Aug 30 13:27:09] VERBOSE[27930] logger.c: -- Executing [501@context_502:2] Dial("SIP/502-081c6668", "SIP/501|30") in new stack [Aug 30 13:27:09] DEBUG[27930] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Aug 30 13:27:09] DEBUG[27930] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Aug 30 13:27:09] DEBUG[27930] chan_sip.c: Setting NAT on RTP to Off [Aug 30 13:27:09] DEBUG[27930] channel.c: Not copying variable STACK-context_502-501-2. [Aug 30 13:27:09] DEBUG[27930] channel.c: Not copying variable MACRO_DEPTH. [Aug 30 13:27:09] DEBUG[27930] channel.c: Not copying variable STACK-macro-jumpcallerid-502-1. [Aug 30 13:27:09] DEBUG[27930] channel.c: Not copying variable STACK-macro-jumpcallerid-s-1. [Aug 30 13:27:09] DEBUG[27930] channel.c: Not copying variable STACK-context_502-501-1. [Aug 30 13:27:09] DEBUG[27930] channel.c: Not copying variable SIPCALLID. [Aug 30 13:27:09] DEBUG[27930] channel.c: Not copying variable SIPUSERAGENT. [Aug 30 13:27:09] DEBUG[27930] channel.c: Not copying variable SIPDOMAIN. [Aug 30 13:27:09] DEBUG[27930] channel.c: Not copying variable SIPURI. [Aug 30 13:27:09] DEBUG[27930] chan_sip.c: Outgoing Call for 501 [Aug 30 13:27:09] VERBOSE[27930] logger.c: Audio is at 192.168.0.13 port 13644 [Aug 30 13:27:09] VERBOSE[27930] logger.c: Adding codec 0x4 (ulaw) to SDP [Aug 30 13:27:09] VERBOSE[27930] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 30 13:27:09] VERBOSE[27930] logger.c: Reliably Transmitting (no NAT) to 192.168.0.16:5060: INVITE sip:501@192.168.0.16 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.13:5060;branch=z9hG4bK354f270a;rport From: "five o two (502)" ;tag=as1e70c9c4 To: Contact: Call-ID: 25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 30 Aug 2007 12:27:09 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 240 v=0 o=root 27822 27822 IN IP4 192.168.0.13 s=session c=IN IP4 192.168.0.13 t=0 0 m=audio 13644 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 --- [Aug 30 13:27:09] VERBOSE[27930] logger.c: -- Called 501 [Aug 30 13:27:09] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> SIP/2.0 100 Trying Via:SIP/2.0/UDP 192.168.0.13:5060;rport=5060;received=192.168.0.13;branch=z9hG4bK354f270a From:"five o two (502)" ;tag=as1e70c9c4 To:;tag=46d67f7a-22a-5ddf4f7f CSeq:102 INVITE User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Call-ID:25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 Content-Length:0 <-------------> [Aug 30 13:27:09] VERBOSE[27842] logger.c: --- (8 headers 0 lines) --- [Aug 30 13:27:09] DEBUG[27842] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13' Request 102: Found [Aug 30 13:27:09] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> SIP/2.0 180 Ringing Via:SIP/2.0/UDP 192.168.0.13:5060;rport=5060;received=192.168.0.13;branch=z9hG4bK354f270a From:"five o two (502)" ;tag=as1e70c9c4 To:;tag=46d67f7a-22a-5ddf4f7f CSeq:102 INVITE User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Call-ID:25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 Allow-Events:talk,hold,conference Content-Length:0 <-------------> [Aug 30 13:27:09] VERBOSE[27842] logger.c: --- (9 headers 0 lines) --- [Aug 30 13:27:09] DEBUG[27842] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13' Request 102: Found [Aug 30 13:27:09] VERBOSE[27930] logger.c: -- SIP/501-b6d00928 is ringing [Aug 30 13:27:10] DEBUG[27930] chan_sip.c: Setting framing from config on incoming call [Aug 30 13:27:10] DEBUG[27930] rtp.c: Ooh, format changed from unknown to ulaw [Aug 30 13:27:10] DEBUG[27930] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Aug 30 13:27:10] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> SIP/2.0 200 OK Via:SIP/2.0/UDP 192.168.0.13:5060;rport=5060;received=192.168.0.13;branch=z9hG4bK354f270a From:"five o two (502)" ;tag=as1e70c9c4 To:;tag=46d67f7a-22a-5ddf4f7f CSeq:102 INVITE User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Call-ID:25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 Contact:"501" Allow-Events:talk,hold,conference Allow:INVITE,ACK,CANCEL,BYE,OPTIONS,REFER,NOTIFY,PRACK,UPDATE Supported:timer,100rel,replaces Content-Type:application/sdp Content-Length:182 v=0 o=501 1188463304 1188463303 IN IP4 192.168.0.16 s=SIP Call c=IN IP4 192.168.0.16 t=0 0 m=audio 20002 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 <-------------> [Aug 30 13:27:10] VERBOSE[27842] logger.c: --- (13 headers 8 lines) --- [Aug 30 13:27:10] DEBUG[27842] chan_sip.c: Acked pending invite 102 [Aug 30 13:27:10] DEBUG[27842] chan_sip.c: Stopping retransmission on '25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13' of Request 102: Match Not Found [Aug 30 13:27:10] VERBOSE[27842] logger.c: Found RTP audio format 0 [Aug 30 13:27:10] VERBOSE[27842] logger.c: Found RTP audio format 101 [Aug 30 13:27:10] VERBOSE[27842] logger.c: Peer audio RTP is at port 192.168.0.16:20002 [Aug 30 13:27:10] VERBOSE[27842] logger.c: Found description format PCMU for ID 0 [Aug 30 13:27:10] VERBOSE[27842] logger.c: Found description format telephone-event for ID 101 [Aug 30 13:27:10] VERBOSE[27842] logger.c: Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Aug 30 13:27:10] VERBOSE[27842] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Aug 30 13:27:10] VERBOSE[27842] logger.c: Peer audio RTP is at port 192.168.0.16:20002 [Aug 30 13:27:10] VERBOSE[27842] logger.c: list_route: hop: [Aug 30 13:27:10] DEBUG[27842] chan_sip.c: Strict routing enforced for session 25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 [Aug 30 13:27:10] VERBOSE[27842] logger.c: set_destination: Parsing for address/port to send to [Aug 30 13:27:10] VERBOSE[27842] logger.c: set_destination: set destination to 192.168.0.16, port 5060 [Aug 30 13:27:10] VERBOSE[27842] logger.c: Transmitting (no NAT) to 192.168.0.16:5060: ACK sip:501@192.168.0.16 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.13:5060;branch=z9hG4bK2c46c642;rport From: "five o two (502)" ;tag=as1e70c9c4 To: ;tag=46d67f7a-22a-5ddf4f7f Contact: Call-ID: 25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Aug 30 13:27:10] VERBOSE[27930] logger.c: -- SIP/501-b6d00928 answered SIP/502-081c6668 [Aug 30 13:27:10] DEBUG[27930] chan_sip.c: SIP answering channel: SIP/502-081c6668 [Aug 30 13:27:10] DEBUG[27930] chan_sip.c: Setting framing from config on incoming call [Aug 30 13:27:10] VERBOSE[27930] logger.c: -- Packet2Packet bridging SIP/502-081c6668 and SIP/501-b6d00928 [Aug 30 13:27:10] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> SUBSCRIBE sip:192.168.0.13 SIP/2.0 Via:SIP/2.0/UDP 192.168.0.16:5060;rport;branch=z9hG4bK7f7b0005 From:;tag=46d67f7b-3a0-7bc8afc4 To: Contact: Call-ID:7f7b0000-44b97313@192.168.0.16 CSeq:2 SUBSCRIBE Expires: 7200 User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Event: message-summary Max-Forwards:70 Accept:application/simple-message-summary Content-Length:0 <-------------> [Aug 30 13:27:10] VERBOSE[27842] logger.c: --- (13 headers 0 lines) --- [Aug 30 13:27:10] DEBUG[27842] chan_sip.c: Allocating new SIP dialog for 7f7b0000-44b97313@192.168.0.16 - SUBSCRIBE (No RTP) [Aug 30 13:27:10] VERBOSE[27842] logger.c: Creating new subscription [Aug 30 13:27:10] VERBOSE[27842] logger.c: Sending to 192.168.0.16 : 5060 (NAT) [Aug 30 13:27:10] VERBOSE[27842] logger.c: Found peer '501' [Aug 30 13:27:10] VERBOSE[27842] logger.c: Looking for s in context_501 (domain 192.168.0.13) [Aug 30 13:27:10] VERBOSE[27842] logger.c: <--- Transmitting (no NAT) to 192.168.0.16:5060 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 192.168.0.16:5060;branch=z9hG4bK7f7b0005;received=192.168.0.16;rport=5060 From: ;tag=46d67f7b-3a0-7bc8afc4 To: ;tag=as67a5a5ca Call-ID: 7f7b0000-44b97313@192.168.0.16 CSeq: 2 SUBSCRIBE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Aug 30 13:27:10] VERBOSE[27842] logger.c: Really destroying SIP dialog '7f7b0000-44b97313@192.168.0.16' Method: SUBSCRIBE [Aug 30 13:27:10] DEBUG[27842] chan_sip.c: Stopping retransmission on 'c5ca0000-7cee94b1@192.168.0.13' of Response 673416698: Match Not Found [Aug 30 13:27:11] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> INVITE sip:5555@192.168.0.13 SIP/2.0 Via:SIP/2.0/UDP 192.168.0.16:5060;rport;branch=z9hG4bK7f7d0006 From:;tag=46d67f7a-22a-5ddf4f7f To:"five o two (502)" ;tag=as1e70c9c4 Contact:"501" Call-ID:25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 CSeq:103 INVITE User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Allow:INVITE,ACK,CANCEL,BYE,OPTIONS,REFER,NOTIFY,PRACK,UPDATE Allow-Events:talk,hold,conference Supported:timer,100rel,replaces Max-Forwards:70 Content-Type:application/sdp Content-Length:194 v=0 o=501 1188463305 1188463304 IN IP4 192.168.0.16 s=SIP Call c=IN IP4 192.168.0.16 t=0 0 a=sendonly m=audio 20002 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 <-------------> [Aug 30 13:27:11] VERBOSE[27842] logger.c: --- (14 headers 9 lines) --- [Aug 30 13:27:11] VERBOSE[27842] logger.c: Sending to 192.168.0.16 : 5060 (NAT) [Aug 30 13:27:11] VERBOSE[27842] logger.c: Found RTP audio format 0 [Aug 30 13:27:11] VERBOSE[27842] logger.c: Found RTP audio format 101 [Aug 30 13:27:11] VERBOSE[27842] logger.c: Peer audio RTP is at port 192.168.0.16:20002 [Aug 30 13:27:11] VERBOSE[27842] logger.c: Found description format PCMU for ID 0 [Aug 30 13:27:11] VERBOSE[27842] logger.c: Found description format telephone-event for ID 101 [Aug 30 13:27:11] VERBOSE[27842] logger.c: Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Aug 30 13:27:11] VERBOSE[27842] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Aug 30 13:27:11] VERBOSE[27842] logger.c: Peer audio RTP is at port 192.168.0.16:20002 [Aug 30 13:27:11] DEBUG[27842] chan_sip.c: Setting framing from config on incoming call [Aug 30 13:27:11] VERBOSE[27842] logger.c: Audio is at 192.168.0.13 port 13644 [Aug 30 13:27:11] VERBOSE[27842] logger.c: Adding codec 0x4 (ulaw) to SDP [Aug 30 13:27:11] VERBOSE[27842] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 30 13:27:11] VERBOSE[27842] logger.c: <--- Transmitting (NAT) to 192.168.0.16:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.16:5060;branch=z9hG4bK7f7d0006;received=192.168.0.16;rport=5060 From: ;tag=46d67f7a-22a-5ddf4f7f To: "five o two (502)" ;tag=as1e70c9c4 Call-ID: 25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 CSeq: 103 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 240 v=0 o=root 27822 27823 IN IP4 192.168.0.13 s=session c=IN IP4 192.168.0.13 t=0 0 m=audio 13644 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=recvonly <------------> [Aug 30 13:27:11] VERBOSE[27930] logger.c: -- Started music on hold, class 'default', on SIP/502-081c6668 [Aug 30 13:27:11] DEBUG[27930] channel.c: Scheduling timer at 160 sample intervals [Aug 30 13:27:11] DEBUG[27930] channel.c: Scheduling timer at 0 sample intervals [Aug 30 13:27:11] WARNING[27930] file.c: File /var/lib/asterisk/mohmp3//fpm-world-mix does not exist in any format [Aug 30 13:27:11] WARNING[27930] res_musiconhold.c: Unable to open file '/var/lib/asterisk/mohmp3//fpm-world-mix': No such file or directory [Aug 30 13:27:11] VERBOSE[27930] logger.c: -- Stopped music on hold on SIP/502-081c6668 [Aug 30 13:27:11] DEBUG[27930] channel.c: Scheduling timer at 0 sample intervals [Aug 30 13:27:11] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> ACK sip:5555@192.168.0.13 SIP/2.0 Via:SIP/2.0/UDP 192.168.0.16:5060;rport;branch=z9hG4bK7f7d0007 From:;tag=46d67f7a-22a-5ddf4f7f To:"five o two (502)" ;tag=as1e70c9c4 Contact:"501" Call-ID:25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 CSeq:103 ACK User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Max-Forwards:70 Content-Length:0 <-------------> [Aug 30 13:27:11] VERBOSE[27842] logger.c: --- (10 headers 0 lines) --- [Aug 30 13:27:11] DEBUG[27842] chan_sip.c: Stopping retransmission on '25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13' of Response 103: Match Found [Aug 30 13:27:14] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> INVITE sip:503@192.168.0.13 SIP/2.0 Via:SIP/2.0/UDP 192.168.0.16:5060;rport;branch=z9hG4bK7f7f0008 From:"501" ;tag=46d67f7f-297-7033472b To: Contact:"501" Call-ID:7f7f0000-1247106c@192.168.0.13 Subject:sip phone call CSeq:178822075 INVITE User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Allow:INVITE,ACK,CANCEL,BYE,OPTIONS,REFER,NOTIFY,PRACK,UPDATE Allow-Events:talk,hold,conference Supported:timer,100rel,replaces Session-Expires: 1800 Min-SE: 90 Max-Forwards:70 Content-Type:application/sdp Content-Length:244 v=0 o=501 1188463131 1188463130 IN IP4 192.168.0.16 s=SIP Call c=IN IP4 192.168.0.16 t=0 0 a=sendrecv m=audio 20004 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 <-------------> [Aug 30 13:27:14] VERBOSE[27842] logger.c: --- (17 headers 11 lines) --- [Aug 30 13:27:14] DEBUG[27842] chan_sip.c: Setting NAT on RTP to Off [Aug 30 13:27:14] DEBUG[27842] chan_sip.c: Allocating new SIP dialog for 7f7f0000-1247106c@192.168.0.13 - INVITE (With RTP) [Aug 30 13:27:14] VERBOSE[27842] logger.c: Sending to 192.168.0.16 : 5060 (NAT) [Aug 30 13:27:14] VERBOSE[27842] logger.c: Using INVITE request as basis request - 7f7f0000-1247106c@192.168.0.13 [Aug 30 13:27:14] DEBUG[27842] chan_sip.c: Setting NAT on RTP to Off [Aug 30 13:27:14] VERBOSE[27842] logger.c: Found user '501' [Aug 30 13:27:14] VERBOSE[27842] logger.c: Found RTP audio format 0 [Aug 30 13:27:14] VERBOSE[27842] logger.c: Found RTP audio format 8 [Aug 30 13:27:14] VERBOSE[27842] logger.c: Found RTP audio format 18 [Aug 30 13:27:14] VERBOSE[27842] logger.c: Found RTP audio format 101 [Aug 30 13:27:14] VERBOSE[27842] logger.c: Peer audio RTP is at port 192.168.0.16:20004 [Aug 30 13:27:14] VERBOSE[27842] logger.c: Found description format PCMU for ID 0 [Aug 30 13:27:14] VERBOSE[27842] logger.c: Found description format PCMA for ID 8 [Aug 30 13:27:14] VERBOSE[27842] logger.c: Found description format G729 for ID 18 [Aug 30 13:27:14] VERBOSE[27842] logger.c: Found description format telephone-event for ID 101 [Aug 30 13:27:14] VERBOSE[27842] logger.c: Capabilities: us - 0x4 (ulaw), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x4 (ulaw) [Aug 30 13:27:14] VERBOSE[27842] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Aug 30 13:27:14] VERBOSE[27842] logger.c: Peer audio RTP is at port 192.168.0.16:20004 [Aug 30 13:27:14] DEBUG[27842] chan_sip.c: Checking SIP call limits for device 501 [Aug 30 13:27:14] VERBOSE[27842] logger.c: Looking for 503 in context_501 (domain 192.168.0.13) [Aug 30 13:27:14] VERBOSE[27842] logger.c: list_route: hop: [Aug 30 13:27:14] VERBOSE[27842] logger.c: <--- Transmitting (no NAT) to 192.168.0.16:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.16:5060;branch=z9hG4bK7f7f0008;received=192.168.0.16;rport=5060 From: "501" ;tag=46d67f7f-297-7033472b To: Call-ID: 7f7f0000-1247106c@192.168.0.13 CSeq: 178822075 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Aug 30 13:27:14] DEBUG[27937] pbx.c: Function result is 'five o one (501)' [Aug 30 13:27:14] DEBUG[27937] pbx.c: Function result is '501' [Aug 30 13:27:14] DEBUG[27937] pbx.c: Launching 'Set' [Aug 30 13:27:14] VERBOSE[27937] logger.c: -- Executing [503@context_501:1] Set("SIP/501-081f0d10", "CALLERID(all)=five o one (501)<01>") in new stack [Aug 30 13:27:14] DEBUG[27937] pbx.c: Launching 'Dial' [Aug 30 13:27:14] VERBOSE[27937] logger.c: -- Executing [503@context_501:2] Dial("SIP/501-081f0d10", "SIP/503|30|wW") in new stack [Aug 30 13:27:14] DEBUG[27937] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Aug 30 13:27:14] DEBUG[27937] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Aug 30 13:27:14] DEBUG[27937] chan_sip.c: Setting NAT on RTP to Off [Aug 30 13:27:14] DEBUG[27937] channel.c: Not copying variable STACK-context_501-503-2. [Aug 30 13:27:14] DEBUG[27937] channel.c: Not copying variable STACK-context_501-503-1. [Aug 30 13:27:14] DEBUG[27937] channel.c: Not copying variable SIPCALLID. [Aug 30 13:27:14] DEBUG[27937] channel.c: Not copying variable SIPUSERAGENT. [Aug 30 13:27:14] DEBUG[27937] channel.c: Not copying variable SIPDOMAIN. [Aug 30 13:27:14] DEBUG[27937] channel.c: Not copying variable SIPURI. [Aug 30 13:27:14] DEBUG[27937] chan_sip.c: Outgoing Call for 503 [Aug 30 13:27:14] VERBOSE[27937] logger.c: -- Called 503 [Aug 30 13:27:14] DEBUG[27842] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '490743753757935372eeef8b5d4e48b9@192.168.0.13' Request 102: Found [Aug 30 13:27:14] DEBUG[27842] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '490743753757935372eeef8b5d4e48b9@192.168.0.13' Request 102: Found [Aug 30 13:27:14] VERBOSE[27937] logger.c: -- SIP/503-081f7d88 is ringing [Aug 30 13:27:14] VERBOSE[27937] logger.c: <--- Transmitting (no NAT) to 192.168.0.16:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.16:5060;branch=z9hG4bK7f7f0008;received=192.168.0.16;rport=5060 From: "501" ;tag=46d67f7f-297-7033472b To: ;tag=as47aa1963 Call-ID: 7f7f0000-1247106c@192.168.0.13 CSeq: 178822075 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Aug 30 13:27:15] DEBUG[27937] chan_sip.c: Setting framing from config on incoming call [Aug 30 13:27:15] VERBOSE[27937] logger.c: Audio is at 192.168.0.13 port 11954 [Aug 30 13:27:15] VERBOSE[27937] logger.c: Adding codec 0x4 (ulaw) to SDP [Aug 30 13:27:15] VERBOSE[27937] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 30 13:27:15] VERBOSE[27937] logger.c: <--- Transmitting (no NAT) to 192.168.0.16:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 192.168.0.16:5060;branch=z9hG4bK7f7f0008;received=192.168.0.16;rport=5060 From: "501" ;tag=46d67f7f-297-7033472b To: ;tag=as47aa1963 Call-ID: 7f7f0000-1247106c@192.168.0.13 CSeq: 178822075 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 240 v=0 o=root 27822 27822 IN IP4 192.168.0.13 s=session c=IN IP4 192.168.0.13 t=0 0 m=audio 11954 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 <------------> [Aug 30 13:27:15] DEBUG[27937] rtp.c: Ooh, format changed from unknown to ulaw [Aug 30 13:27:15] DEBUG[27937] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Aug 30 13:27:15] DEBUG[27842] chan_sip.c: Acked pending invite 102 [Aug 30 13:27:15] DEBUG[27842] chan_sip.c: Stopping retransmission on '490743753757935372eeef8b5d4e48b9@192.168.0.13' of Request 102: Match Not Found [Aug 30 13:27:15] DEBUG[27842] chan_sip.c: Strict routing enforced for session 490743753757935372eeef8b5d4e48b9@192.168.0.13 [Aug 30 13:27:15] VERBOSE[27937] logger.c: -- SIP/503-081f7d88 answered SIP/501-081f0d10 [Aug 30 13:27:15] DEBUG[27937] chan_sip.c: SIP answering channel: SIP/501-081f0d10 [Aug 30 13:27:15] DEBUG[27937] chan_sip.c: Setting framing from config on incoming call [Aug 30 13:27:15] VERBOSE[27937] logger.c: Audio is at 192.168.0.13 port 11954 [Aug 30 13:27:15] VERBOSE[27937] logger.c: Adding codec 0x4 (ulaw) to SDP [Aug 30 13:27:15] VERBOSE[27937] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 30 13:27:15] VERBOSE[27937] logger.c: <--- Reliably Transmitting (no NAT) to 192.168.0.16:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.16:5060;branch=z9hG4bK7f7f0008;received=192.168.0.16;rport=5060 From: "501" ;tag=46d67f7f-297-7033472b To: ;tag=as47aa1963 Call-ID: 7f7f0000-1247106c@192.168.0.13 CSeq: 178822075 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 240 v=0 o=root 27822 27823 IN IP4 192.168.0.13 s=session c=IN IP4 192.168.0.13 t=0 0 m=audio 11954 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 <------------> [Aug 30 13:27:15] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:15] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> ACK sip:503@192.168.0.13 SIP/2.0 Via:SIP/2.0/UDP 192.168.0.16:5060;rport;branch=z9hG4bK7f800009 From:"501" ;tag=46d67f7f-297-7033472b To:;tag=as47aa1963 Contact:"501" Call-ID:7f7f0000-1247106c@192.168.0.13 CSeq:178822075 ACK User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Max-Forwards:70 Content-Length:0 <-------------> [Aug 30 13:27:15] VERBOSE[27842] logger.c: --- (10 headers 0 lines) --- [Aug 30 13:27:15] DEBUG[27842] chan_sip.c: Stopping retransmission on '7f7f0000-1247106c@192.168.0.13' of Response 178822075: Match Not Found [Aug 30 13:27:17] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> INVITE sip:503@192.168.0.13 SIP/2.0 Via:SIP/2.0/UDP 192.168.0.16:5060;rport;branch=z9hG4bK7f82000a From:"501" ;tag=46d67f7f-297-7033472b To:;tag=as47aa1963 Contact:"501" Call-ID:7f7f0000-1247106c@192.168.0.13 Subject:sip phone call CSeq:178822076 INVITE User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Allow:INVITE,ACK,CANCEL,BYE,OPTIONS,REFER,NOTIFY,PRACK,UPDATE Allow-Events:talk,hold,conference Supported:timer,100rel,replaces Session-Expires: 1800 Min-SE: 90 Max-Forwards:70 Content-Type:application/sdp Content-Length:244 v=0 o=501 1188463132 1188463131 IN IP4 192.168.0.16 s=SIP Call c=IN IP4 192.168.0.16 t=0 0 a=sendonly m=audio 20004 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 <-------------> [Aug 30 13:27:17] VERBOSE[27842] logger.c: --- (17 headers 11 lines) --- [Aug 30 13:27:17] VERBOSE[27842] logger.c: Sending to 192.168.0.16 : 5060 (NAT) [Aug 30 13:27:17] VERBOSE[27842] logger.c: Found RTP audio format 0 [Aug 30 13:27:17] VERBOSE[27842] logger.c: Found RTP audio format 8 [Aug 30 13:27:17] VERBOSE[27842] logger.c: Found RTP audio format 18 [Aug 30 13:27:17] VERBOSE[27842] logger.c: Found RTP audio format 101 [Aug 30 13:27:17] VERBOSE[27842] logger.c: Peer audio RTP is at port 192.168.0.16:20004 [Aug 30 13:27:17] VERBOSE[27842] logger.c: Found description format PCMU for ID 0 [Aug 30 13:27:17] VERBOSE[27842] logger.c: Found description format PCMA for ID 8 [Aug 30 13:27:17] VERBOSE[27842] logger.c: Found description format G729 for ID 18 [Aug 30 13:27:17] VERBOSE[27842] logger.c: Found description format telephone-event for ID 101 [Aug 30 13:27:17] VERBOSE[27842] logger.c: Capabilities: us - 0x4 (ulaw), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x4 (ulaw) [Aug 30 13:27:17] VERBOSE[27842] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Aug 30 13:27:17] VERBOSE[27842] logger.c: Peer audio RTP is at port 192.168.0.16:20004 [Aug 30 13:27:17] DEBUG[27842] chan_sip.c: Setting framing from config on incoming call [Aug 30 13:27:17] VERBOSE[27842] logger.c: Audio is at 192.168.0.13 port 11954 [Aug 30 13:27:17] VERBOSE[27842] logger.c: Adding codec 0x4 (ulaw) to SDP [Aug 30 13:27:17] VERBOSE[27842] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 30 13:27:17] VERBOSE[27842] logger.c: <--- Transmitting (NAT) to 192.168.0.16:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.16:5060;branch=z9hG4bK7f82000a;received=192.168.0.16;rport=5060 From: "501" ;tag=46d67f7f-297-7033472b To: ;tag=as47aa1963 Call-ID: 7f7f0000-1247106c@192.168.0.13 CSeq: 178822076 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 240 v=0 o=root 27822 27824 IN IP4 192.168.0.13 s=session c=IN IP4 192.168.0.13 t=0 0 m=audio 11954 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=recvonly <------------> [Aug 30 13:27:17] VERBOSE[27937] logger.c: -- Started music on hold, class 'default', on SIP/503-081f7d88 [Aug 30 13:27:17] DEBUG[27937] channel.c: Scheduling timer at 160 sample intervals [Aug 30 13:27:17] DEBUG[27937] channel.c: Scheduling timer at 0 sample intervals [Aug 30 13:27:17] WARNING[27937] file.c: File /var/lib/asterisk/mohmp3//fpm-world-mix does not exist in any format [Aug 30 13:27:17] WARNING[27937] res_musiconhold.c: Unable to open file '/var/lib/asterisk/mohmp3//fpm-world-mix': No such file or directory [Aug 30 13:27:17] VERBOSE[27937] logger.c: -- Stopped music on hold on SIP/503-081f7d88 [Aug 30 13:27:17] DEBUG[27937] channel.c: Scheduling timer at 0 sample intervals [Aug 30 13:27:17] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> ACK sip:503@192.168.0.13 SIP/2.0 Via:SIP/2.0/UDP 192.168.0.16:5060;rport;branch=z9hG4bK7f82000b From:"501" ;tag=46d67f7f-297-7033472b To:;tag=as47aa1963 Contact:"501" Call-ID:7f7f0000-1247106c@192.168.0.13 CSeq:178822076 ACK User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Max-Forwards:70 Content-Length:0 <-------------> [Aug 30 13:27:17] VERBOSE[27842] logger.c: --- (10 headers 0 lines) --- [Aug 30 13:27:17] DEBUG[27842] chan_sip.c: Stopping retransmission on '7f7f0000-1247106c@192.168.0.13' of Response 178822076: Match Found [Aug 30 13:27:18] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> INVITE sip:5555@192.168.0.13 SIP/2.0 Via:SIP/2.0/UDP 192.168.0.16:5060;rport;branch=z9hG4bK7f83000c From:;tag=46d67f7a-22a-5ddf4f7f To:"five o two (502)" ;tag=as1e70c9c4 Contact:"501" Call-ID:25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 CSeq:104 INVITE User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Allow:INVITE,ACK,CANCEL,BYE,OPTIONS,REFER,NOTIFY,PRACK,UPDATE Allow-Events:talk,hold,conference Supported:timer,100rel,replaces Max-Forwards:70 Content-Type:application/sdp Content-Length:244 v=0 o=501 1188463307 1188463306 IN IP4 192.168.0.16 s=SIP Call c=IN IP4 192.168.0.16 t=0 0 a=sendrecv m=audio 20002 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 <-------------> [Aug 30 13:27:18] VERBOSE[27842] logger.c: --- (14 headers 11 lines) --- [Aug 30 13:27:18] VERBOSE[27842] logger.c: Sending to 192.168.0.16 : 5060 (NAT) [Aug 30 13:27:18] VERBOSE[27842] logger.c: Found RTP audio format 0 [Aug 30 13:27:18] VERBOSE[27842] logger.c: Found RTP audio format 8 [Aug 30 13:27:18] VERBOSE[27842] logger.c: Found RTP audio format 18 [Aug 30 13:27:18] VERBOSE[27842] logger.c: Found RTP audio format 101 [Aug 30 13:27:18] VERBOSE[27842] logger.c: Peer audio RTP is at port 192.168.0.16:20002 [Aug 30 13:27:18] VERBOSE[27842] logger.c: Found description format PCMU for ID 0 [Aug 30 13:27:18] VERBOSE[27842] logger.c: Found description format PCMA for ID 8 [Aug 30 13:27:18] VERBOSE[27842] logger.c: Found description format G729 for ID 18 [Aug 30 13:27:18] VERBOSE[27842] logger.c: Found description format telephone-event for ID 101 [Aug 30 13:27:18] VERBOSE[27842] logger.c: Capabilities: us - 0x4 (ulaw), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x4 (ulaw) [Aug 30 13:27:18] VERBOSE[27842] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Aug 30 13:27:18] VERBOSE[27842] logger.c: Peer audio RTP is at port 192.168.0.16:20002 [Aug 30 13:27:18] DEBUG[27842] chan_sip.c: Setting framing from config on incoming call [Aug 30 13:27:18] VERBOSE[27842] logger.c: Audio is at 192.168.0.13 port 13644 [Aug 30 13:27:18] VERBOSE[27842] logger.c: Adding codec 0x4 (ulaw) to SDP [Aug 30 13:27:18] VERBOSE[27842] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 30 13:27:18] VERBOSE[27842] logger.c: <--- Transmitting (NAT) to 192.168.0.16:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.16:5060;branch=z9hG4bK7f83000c;received=192.168.0.16;rport=5060 From: ;tag=46d67f7a-22a-5ddf4f7f To: "five o two (502)" ;tag=as1e70c9c4 Call-ID: 25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 CSeq: 104 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 240 v=0 o=root 27822 27824 IN IP4 192.168.0.13 s=session c=IN IP4 192.168.0.13 t=0 0 m=audio 13644 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 <------------> [Aug 30 13:27:18] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> ACK sip:5555@192.168.0.13 SIP/2.0 Via:SIP/2.0/UDP 192.168.0.16:5060;rport;branch=z9hG4bK7f83000d From:;tag=46d67f7a-22a-5ddf4f7f To:"five o two (502)" ;tag=as1e70c9c4 Contact:"501" Call-ID:25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 CSeq:104 ACK User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Max-Forwards:70 Content-Length:0 <-------------> [Aug 30 13:27:18] VERBOSE[27842] logger.c: --- (10 headers 0 lines) --- [Aug 30 13:27:18] DEBUG[27842] chan_sip.c: Stopping retransmission on '25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13' of Response 104: Match Found [Aug 30 13:27:21] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> REFER sip:503@192.168.0.13 SIP/2.0 Via:SIP/2.0/UDP 192.168.0.16:5060;rport;branch=z9hG4bK7f86000e From:"501" ;tag=46d67f7f-297-7033472b To:;tag=as47aa1963 Contact:"501" Call-ID:7f7f0000-1247106c@192.168.0.13 CSeq:178822077 REFER User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Referred-By:"501" Refer-To: Accept-Contact: Supported:timer,100rel,replaces Max-Forwards:70 Content-Length:0 <-------------> [Aug 30 13:27:21] VERBOSE[27842] logger.c: --- (14 headers 0 lines) --- [Aug 30 13:27:21] VERBOSE[27842] logger.c: Call 7f7f0000-1247106c@192.168.0.13 got a SIP call transfer from caller: (REFER)! [Aug 30 13:27:21] VERBOSE[27842] logger.c: SIP transfer to extension 5555@context_501 by 501@192.168.0.13 [Aug 30 13:27:21] VERBOSE[27842] logger.c: <--- Transmitting (NAT) to 192.168.0.16:5060 ---> SIP/2.0 202 Accepted Via: SIP/2.0/UDP 192.168.0.16:5060;branch=z9hG4bK7f86000e;received=192.168.0.16;rport=5060 From: "501" ;tag=46d67f7f-297-7033472b To: ;tag=as47aa1963 Call-ID: 7f7f0000-1247106c@192.168.0.13 CSeq: 178822077 REFER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Aug 30 13:27:21] DEBUG[27842] channel.c: Planning to masquerade channel SIP/503-081f7d88 into the structure of SIP/501-b6d00928 [Aug 30 13:27:21] DEBUG[27842] channel.c: Done planning to masquerade channel SIP/503-081f7d88 into the structure of SIP/501-b6d00928 [Aug 30 13:27:21] DEBUG[27842] chan_sip.c: SIP transfer: Succeeded to masquerade channels. [Aug 30 13:27:21] DEBUG[27842] chan_sip.c: Strict routing enforced for session 7f7f0000-1247106c@192.168.0.13 [Aug 30 13:27:21] VERBOSE[27842] logger.c: set_destination: Parsing for address/port to send to [Aug 30 13:27:21] VERBOSE[27842] logger.c: set_destination: set destination to 192.168.0.16, port 5060 [Aug 30 13:27:21] VERBOSE[27842] logger.c: Reliably Transmitting (NAT) to 192.168.0.16:5060: NOTIFY sip:501@192.168.0.16 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.13:5060;branch=z9hG4bK184b955f;rport From: ;tag=as47aa1963 To: "501" ;tag=46d67f7f-297-7033472b Contact: Call-ID: 7f7f0000-1247106c@192.168.0.13 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=178822077 Subscription-state: terminated;reason=noresource Content-Type: message/sipfrag;version=2.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 16 SIP/2.0 200 OK --- [Aug 30 13:27:21] DEBUG[27842] chan_sip.c: SIP attended transfer: Unlocking channel SIP/501-b6d00928 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] VERBOSE[27937] logger.c: -- Packet2Packet bridging SIP/501-081f0d10 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] DEBUG[27930] chan_sip.c: Hangup call SIP/503-081f7d88, SIP callid 25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13) [Aug 30 13:27:21] VERBOSE[27930] logger.c: Scheduling destruction of SIP dialog '25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13' in 32000 ms (Method: ACK) [Aug 30 13:27:21] DEBUG[27930] chan_sip.c: Strict routing enforced for session 25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 [Aug 30 13:27:21] VERBOSE[27930] logger.c: set_destination: Parsing for address/port to send to [Aug 30 13:27:21] VERBOSE[27930] logger.c: set_destination: set destination to 192.168.0.16, port 5060 [Aug 30 13:27:21] VERBOSE[27930] logger.c: Reliably Transmitting (NAT) to 192.168.0.16:5060: BYE sip:501@192.168.0.16 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.13:5060;branch=z9hG4bK65182121;rport From: "five o two (502)" ;tag=as1e70c9c4 To: ;tag=46d67f7a-22a-5ddf4f7f Call-ID: 25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Aug 30 13:27:21] DEBUG[27930] channel.c: Putting channel SIP/503-081f7d88 in 4/4 formats [Aug 30 13:27:21] DEBUG[27930] channel.c: Released clone lock on 'SIP/501-b6d00928' [Aug 30 13:27:21] DEBUG[27937] channel.c: Bridge stops because we're zombie or need a soft hangup: c0=SIP/501-081f0d10, c1=SIP/501-b6d00928, flags: No,No,Yes,Yes [Aug 30 13:27:21] DEBUG[27930] channel.c: Done Masquerading SIP/503-081f7d88 (6) [Aug 30 13:27:21] DEBUG[27937] channel.c: Bridge stops bridging channels SIP/501-081f0d10 and SIP/501-b6d00928 [Aug 30 13:27:21] DEBUG[27930] rtp.c: Oooh, something is weird, backing out [Aug 30 13:27:21] DEBUG[27937] channel.c: Hanging up zombie 'SIP/501-b6d00928' [Aug 30 13:27:21] VERBOSE[27930] logger.c: -- Packet2Packet bridging SIP/502-081c6668 and SIP/503-081f7d88 [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '502' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '502' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 's' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'context_503' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'SIP/501-b6d00928' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'SIP/501-081f0d10' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '2007-08-30 13:27:09' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '2007-08-30 13:27:10' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '2007-08-30 13:27:21' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '12' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '11' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'ANSWERED' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'DOCUMENTATION' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '1188476834.3' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'SIP/501-b6d00928' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '"five o one (501)" <01>' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '01' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '503' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'context_501' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'SIP/501-081f0d10' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'SIP/501-081f0d10' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'Dial' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'SIP/503|30|wW' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '2007-08-30 13:27:14' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '2007-08-30 13:27:15' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '2007-08-30 13:27:21' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '7' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '6' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'ANSWERED' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'DOCUMENTATION' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '1188476834.2' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'SIP/501-081f0d10' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '01' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '01' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 's' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'context_503' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'SIP/503-081f7d88' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'SIP/501-081f0d10' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '2007-08-30 13:27:14' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '2007-08-30 13:27:15' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '2007-08-30 13:27:21' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '7' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '6' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'ANSWERED' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'DOCUMENTATION' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '1188476834.3' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is '' [Aug 30 13:27:21] DEBUG[27937] pbx.c: Function result is 'SIP/503-081f7d88' [Aug 30 13:27:21] DEBUG[27937] rtp.c: Channel '' has no RTP, not doing anything [Aug 30 13:27:21] DEBUG[27937] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Aug 30 13:27:21] DEBUG[27937] pbx.c: Spawn extension (context_501,503,2) exited non-zero on 'SIP/501-081f0d10' [Aug 30 13:27:21] VERBOSE[27937] logger.c: == Spawn extension (context_501, 503, 2) exited non-zero on 'SIP/501-081f0d10' [Aug 30 13:27:21] DEBUG[27937] channel.c: Hanging up channel 'SIP/501-081f0d10' [Aug 30 13:27:21] VERBOSE[27937] logger.c: Scheduling destruction of SIP dialog '7f7f0000-1247106c@192.168.0.13' in 32000 ms (Method: REFER) [Aug 30 13:27:21] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> SIP/2.0 200 OK Via:SIP/2.0/UDP 192.168.0.13:5060;rport=5060;received=192.168.0.13;branch=z9hG4bK184b955f From:;tag=as47aa1963 To:"501" ;tag=46d67f7f-297-7033472b CSeq:102 NOTIFY User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Call-ID:7f7f0000-1247106c@192.168.0.13 Contact:"501" Allow:INVITE,ACK,CANCEL,BYE,OPTIONS,REFER,NOTIFY,PRACK,UPDATE Supported:timer,100rel,replaces Content-Length:0 <-------------> [Aug 30 13:27:21] VERBOSE[27842] logger.c: --- (11 headers 0 lines) --- [Aug 30 13:27:21] DEBUG[27842] chan_sip.c: Stopping retransmission on '7f7f0000-1247106c@192.168.0.13' of Request 102: Match Not Found [Aug 30 13:27:21] VERBOSE[27842] logger.c: SIP Response message for INCOMING dialog NOTIFY arrived [Aug 30 13:27:21] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> SIP/2.0 200 OK Via:SIP/2.0/UDP 192.168.0.13:5060;rport=5060;received=192.168.0.13;branch=z9hG4bK65182121 From:"five o two (502)" ;tag=as1e70c9c4 To:;tag=46d67f7a-22a-5ddf4f7f CSeq:103 BYE User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Call-ID:25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13 Contact:"501" Allow:INVITE,ACK,CANCEL,BYE,OPTIONS,REFER,NOTIFY,PRACK,UPDATE Supported:timer,100rel,replaces Content-Length:0 <-------------> [Aug 30 13:27:21] VERBOSE[27842] logger.c: --- (11 headers 0 lines) --- [Aug 30 13:27:21] DEBUG[27842] chan_sip.c: Stopping retransmission on '25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13' of Request 103: Match Not Found [Aug 30 13:27:21] VERBOSE[27842] logger.c: SIP Response message for INCOMING dialog BYE arrived [Aug 30 13:27:21] VERBOSE[27842] logger.c: Really destroying SIP dialog '25a3d2fb5f16c9ab76fb550c6cfd53ee@192.168.0.13' Method: ACK [Aug 30 13:27:21] VERBOSE[27842] logger.c: <--- SIP read from 192.168.0.16:5060 ---> BYE sip:503@192.168.0.13 SIP/2.0 Via:SIP/2.0/UDP 192.168.0.16:5060;rport;branch=z9hG4bK7f86000f From:"501" ;tag=46d67f7f-297-7033472b To:;tag=as47aa1963 Contact:"501" Call-ID:7f7f0000-1247106c@192.168.0.13 CSeq:178822078 BYE User-Agent:Mitel-5215-SIP-Phone 07.00.00.08 08000F1610EB Supported:timer,100rel,replaces Max-Forwards:70 Content-Length:0 <-------------> [Aug 30 13:27:21] VERBOSE[27842] logger.c: --- (11 headers 0 lines) --- [Aug 30 13:27:21] VERBOSE[27842] logger.c: Sending to 192.168.0.16 : 5060 (NAT) [Aug 30 13:27:21] VERBOSE[27842] logger.c: Scheduling destruction of SIP dialog '7f7f0000-1247106c@192.168.0.13' in 32000 ms (Method: BYE) [Aug 30 13:27:21] VERBOSE[27842] logger.c: <--- Transmitting (NAT) to 192.168.0.16:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.16:5060;branch=z9hG4bK7f86000f;received=192.168.0.16;rport=5060 From: "501" ;tag=46d67f7f-297-7033472b To: ;tag=as47aa1963 Call-ID: 7f7f0000-1247106c@192.168.0.13 CSeq: 178822078 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Aug 30 13:27:37] DEBUG[27930] rtp.c: Oooh, got a hangup [Aug 30 13:27:37] DEBUG[27930] channel.c: Returning from native bridge, channels: SIP/502-081c6668, SIP/503-081f7d88 [Aug 30 13:27:37] DEBUG[27930] channel.c: Hanging up channel 'SIP/503-081f7d88' [Aug 30 13:27:37] DEBUG[27930] chan_sip.c: Hangup call SIP/503-081f7d88, SIP callid 490743753757935372eeef8b5d4e48b9@192.168.0.13) [Aug 30 13:27:37] DEBUG[27930] chan_sip.c: Strict routing enforced for session 490743753757935372eeef8b5d4e48b9@192.168.0.13 [Aug 30 13:27:37] DEBUG[27930] rtp.c: Channel '' has no RTP, not doing anything [Aug 30 13:27:37] DEBUG[27930] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Aug 30 13:27:37] DEBUG[27930] pbx.c: Spawn extension (context_502,501,2) exited non-zero on 'SIP/502-081c6668' [Aug 30 13:27:37] VERBOSE[27930] logger.c: == Spawn extension (context_502, 501, 2) exited non-zero on 'SIP/502-081c6668' [Aug 30 13:27:37] DEBUG[27930] channel.c: Hanging up channel 'SIP/502-081c6668' [Aug 30 13:27:37] DEBUG[27930] chan_sip.c: Hangup call SIP/502-081c6668, SIP callid c5ca0000-7cee94b1@192.168.0.13) [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is '"five o two (502)" <502>' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is '502' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is '501' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is 'context_502' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is 'SIP/502-081c6668' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is 'SIP/501-b6d00928' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is 'Dial' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is 'SIP/501|30' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is '2007-08-30 13:27:09' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is '2007-08-30 13:27:10' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is '2007-08-30 13:27:37' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is '28' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is '27' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is 'ANSWERED' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is 'DOCUMENTATION' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is '' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is '1188476829.0' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is '' [Aug 30 13:27:37] DEBUG[27930] pbx.c: Function result is 'SIP/502-081c6668' [Aug 30 13:27:37] DEBUG[27842] chan_sip.c: Stopping retransmission on '490743753757935372eeef8b5d4e48b9@192.168.0.13' of Request 103: Match Not Found [Aug 30 13:27:46] VERBOSE[27822] logger.c: Beginning asterisk shutdown.... [Aug 30 13:27:46] VERBOSE[27822] logger.c: Executing last minute cleanups [Aug 30 13:27:46] VERBOSE[27822] logger.c: == Destroying musiconhold processes [Aug 30 13:27:46] VERBOSE[27822] logger.c: Asterisk cleanly ending (0). [Aug 30 13:27:46] DEBUG[27822] asterisk.c: Asterisk ending (0).