[2012-07-20 11:37:16] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> INVITE sip:083414166950@10.252.0.254 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK02d1a99d;rport Max-Forwards: 70 From: "3412539603" ;tag=as2b2e1a57 To: Contact: Call-ID: 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 CSeq: 102 INVITE User-Agent: Cisco-SIPGateway/IOS-12.x Date: Fri, 20 Jul 2012 07:37:16 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 256 v=0 o=root 327140458 327140458 IN IP4 10.252.0.246 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.246 t=0 0 m=audio 17680 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <-------------> [2012-07-20 11:37:16] VERBOSE[9911] chan_sip.c: --- (16 headers 12 lines) --- [2012-07-20 11:37:16] DEBUG[9911] chan_sip.c: Allocating new SIP dialog for 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 - INVITE (No RTP) [2012-07-20 11:37:16] VERBOSE[9911] chan_sip.c: Sending to 10.252.0.246:5060 (NAT) [2012-07-20 11:37:16] DEBUG[9911] chan_sip.c: Initializing initreq for method INVITE - callid 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 [2012-07-20 11:37:16] VERBOSE[9911] chan_sip.c: Using INVITE request as basis request - 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 [2012-07-20 11:37:16] VERBOSE[9911] chan_sip.c: Found peer 'office-gag' for '3412539603' from 10.252.0.246:5060 [2012-07-20 11:37:16] VERBOSE[9911] chan_sip.c: <--- Reliably Transmitting (NAT) to 10.252.0.246:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK02d1a99d;received=10.252.0.246;rport=5060 From: "3412539603" ;tag=as2b2e1a57 To: ;tag=as441b12cc Call-ID: 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 CSeq: 102 INVITE Server: Asterisk PBX 10.6.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="73ea4dc9" Content-Length: 0 <------------> [2012-07-20 11:37:16] DEBUG[9911] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.252.0.246:5060 [2012-07-20 11:37:16] VERBOSE[9911] chan_sip.c: Scheduling destruction of SIP dialog '57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060' in 6400 ms (Method: INVITE) [2012-07-20 11:37:16] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> ACK sip:083414166950@10.252.0.254 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK02d1a99d;rport Max-Forwards: 70 From: "3412539603" ;tag=as2b2e1a57 To: ;tag=as441b12cc Contact: Call-ID: 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 CSeq: 102 ACK User-Agent: Cisco-SIPGateway/IOS-12.x Content-Length: 0 <-------------> [2012-07-20 11:37:16] VERBOSE[9911] chan_sip.c: --- (10 headers 0 lines) --- [2012-07-20 11:37:16] DEBUG[9911] chan_sip.c: Stopping retransmission on '57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060' of Response 102: Match Found [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> INVITE sip:083414166950@10.252.0.254 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK374ba994;rport Max-Forwards: 70 From: "3412539603" ;tag=as2b2e1a57 To: Contact: Call-ID: 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 CSeq: 103 INVITE User-Agent: Cisco-SIPGateway/IOS-12.x Authorization: Digest username="office-gag", realm="asterisk", algorithm=MD5, uri="sip:083414166950@10.252.0.254", nonce="73ea4dc9", response="57b5fd65460633f1a22df50450c1eefe" Date: Fri, 20 Jul 2012 07:37:16 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 256 v=0 o=root 327140458 327140459 IN IP4 10.252.0.246 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.246 t=0 0 m=audio 17680 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <-------------> [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: --- (17 headers 12 lines) --- [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Sending to 10.252.0.246:5060 (NAT) [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Initializing initreq for method INVITE - callid 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Using INVITE request as basis request - 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Found peer 'office-gag' for 'office-gag' from 10.252.0.246:5060 [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xf2eed40' [2012-07-20 11:37:17] DEBUG[9911] res_rtp_asterisk.c: Allocated port 10334 for RTP instance '0xf2eed40' [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: RTP instance '0xf2eed40' is setup and ready to go [2012-07-20 11:37:17] DEBUG[9911] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xf2eed40' [2012-07-20 11:37:17] VERBOSE[9911] netsock2.c: == Using SIP RTP CoS mark 5 [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Setting NAT on RTP to On [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Found RTP audio format 18 [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Setting payload 18 based on m type on 0xb6056dd8 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Found RTP audio format 101 [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Setting payload 101 based on m type on 0xb6056dd8 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Found audio description format G729 for ID 18 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Found audio description format telephone-event for ID 101 [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Incorporating payload 18 on 0xb6056dd8 [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Incorporating payload 101 on 0xb6056dd8 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Capabilities: us - (g729), peer - audio=(g729)/video=(nothing)/text=(nothing), combined - (g729) [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [2012-07-20 11:37:17] DEBUG[9911] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xf2eed40' [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Peer audio RTP is at port 10.252.0.246:17680 [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Copying payload 18 from 0xb6056dd8 to 0xf2eeeec [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Copying payload 101 from 0xb6056dd8 to 0xf2eeeec [2012-07-20 11:37:17] DEBUG[9911] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0xf2eed40' [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: We're settling with these formats: (g729) [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Checking SIP call limits for device office [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Looking for 083414166950 in from-gagarina-to-pesochnaya (domain 10.252.0.254) [2012-07-20 11:37:17] DEBUG[9911] res_fax.c: Attached T.38 gateway to channel SIP/office-gag-00000276. [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: build_route: Contact hop: [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: list_route: hop: [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Incoming INVITE with 'timer' option supported and "Session-Expires" header. [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Session-Expires: 600 [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Received Min-SE: 90 [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Session timer started: 34516 - 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: SIP/office-gag-00000276: New call is still down.... Trying... [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: <--- Transmitting (NAT) to 10.252.0.246:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK374ba994;received=10.252.0.246;rport=5060 From: "3412539603" ;tag=as2b2e1a57 To: Call-ID: 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 CSeq: 103 INVITE Server: Asterisk PBX 10.6.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Session-Expires: 600;refresher=uas Contact: Content-Length: 0 <------------> [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.252.0.246:5060 [2012-07-20 11:37:17] DEBUG[10287] pbx.c: Function result is '"3412539603" <3412539603>' [2012-07-20 11:37:17] DEBUG[10287] pbx.c: Launching 'NoOp' [2012-07-20 11:37:17] VERBOSE[10287] pbx.c: -- Executing [083414166950@from-gagarina-to-pesochnaya:1] NoOp("SIP/office-gag-00000276", "Call from ""3412539603" <3412539603>" to "083414166950"") in new stack [2012-07-20 11:37:17] DEBUG[10287] func_strings.c: Allowed: 0123456789 [2012-07-20 11:37:17] DEBUG[10287] pbx.c: Function result is '083414166950' [2012-07-20 11:37:17] DEBUG[10287] pbx.c: Launching 'Set' [2012-07-20 11:37:17] VERBOSE[10287] pbx.c: -- Executing [083414166950@from-gagarina-to-pesochnaya:2] Set("SIP/office-gag-00000276", "route=083414166950") in new stack [2012-07-20 11:37:17] DEBUG[10287] pbx.c: Launching 'Dial' [2012-07-20 11:37:17] VERBOSE[10287] pbx.c: -- Executing [083414166950@from-gagarina-to-pesochnaya:3] Dial("SIP/office-gag-00000276", "SIP/office/083414166950") in new stack [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: Asked to create a SIP channel with formats: (g729) [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: Allocating new SIP dialog for 64d66fa9414c8ed2392ad6b046df5edf@10.252.0.254:5060 - INVITE (No RTP) [2012-07-20 11:37:17] DEBUG[10287] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xf2d8e08' [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: Allocated port 15802 for RTP instance '0xf2d8e08' [2012-07-20 11:37:17] DEBUG[10287] rtp_engine.c: RTP instance '0xf2d8e08' is setup and ready to go [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xf2d8e08' [2012-07-20 11:37:17] VERBOSE[10287] netsock2.c: == Using SIP RTP CoS mark 5 [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: Setting NAT on RTP to On [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2012-07-20 11:37:17] DEBUG[10287] res_fax.c: Attached T.38 gateway to channel SIP/office-00000277. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable DIALEDTIME. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable ANSWEREDTIME. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable DIALEDPEERNAME. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable DIALEDPEERNUMBER. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable DIALSTATUS. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable route. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable FAXPAGES. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable FAXSTATUSSTRING. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable FAXERROR. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable FAXSTATUS. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable SIPCALLID. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable SIPDOMAIN. [2012-07-20 11:37:17] DEBUG[10287] channel.c: Not copying variable SIPURI. [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: Outgoing Call for 083414166950 [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: ** Our capability: (alaw) Video flag: False Text flag: False [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: ** Our prefcodec: (g729) [2012-07-20 11:37:17] VERBOSE[10287] chan_sip.c: Audio is at 15802 [2012-07-20 11:37:17] VERBOSE[10287] chan_sip.c: Adding codec 100004 (alaw) to SDP [2012-07-20 11:37:17] VERBOSE[10287] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: Initializing initreq for method INVITE - callid 55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060 [2012-07-20 11:37:17] VERBOSE[10287] chan_sip.c: Reliably Transmitting (NAT) to 193.227.252.70:5060: INVITE sip:083414166950@193.227.252.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK7b43cefc;rport Max-Forwards: 70 From: "3412539603" ;tag=as6300648a To: Contact: Call-ID: 55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060 CSeq: 102 INVITE User-Agent: Asterisk PBX 10.6.0 Date: Fri, 20 Jul 2012 07:37:17 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 235 v=0 o=root 1791534486 1791534486 IN IP4 10.252.0.254 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.254 t=0 0 m=audio 15802 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv --- [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 193.227.252.70:5060 [2012-07-20 11:37:17] VERBOSE[10287] app_dial.c: -- Called SIP/office/083414166950 [2012-07-20 11:37:17] DEBUG[10287] channel.c: Set channel SIP/office-00000277 to read format slin [2012-07-20 11:37:17] DEBUG[10287] channel.c: Set channel SIP/office-gag-00000276 to write format slin [2012-07-20 11:37:17] DEBUG[10287] channel.c: Set channel SIP/office-gag-00000276 to read format slin [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK7b43cefc;rport;received=10.252.0.254 From: "3412539603" ;tag=as6300648a To: ;tag=as0dcee222 Call-ID: 55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060 CSeq: 102 INVITE User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="73c092d9" Content-Length: 0 <-------------> [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: --- (11 headers 0 lines) --- [2012-07-20 11:37:17] DEBUG[10287] channel.c: Set channel SIP/office-00000277 to write format slin [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Acked pending invite 102 [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Stopping retransmission on '55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060' of Request 102: Match Found [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Transmitting (NAT) to 193.227.252.70:5060: ACK sip:083414166950@193.227.252.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK7b43cefc;rport Max-Forwards: 70 From: "3412539603" ;tag=as6300648a To: ;tag=as0dcee222 Contact: Call-ID: 55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060 CSeq: 102 ACK User-Agent: Asterisk PBX 10.6.0 Content-Length: 0 --- [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Trying to put 'ACK sip:083' onto UDP socket destined for 193.227.252.70:5060 [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Auth attempt 1 on INVITE [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: ** Our capability: (alaw) Video flag: False Text flag: False [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: ** Our prefcodec: (g729) [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Audio is at 15802 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Adding codec 100004 (alaw) to SDP [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Reliably Transmitting (NAT) to 193.227.252.70:5060: INVITE sip:083414166950@193.227.252.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK46329694;rport Max-Forwards: 70 From: "3412539603" ;tag=as6300648a To: Contact: Call-ID: 55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060 CSeq: 103 INVITE User-Agent: Asterisk PBX 10.6.0 Proxy-Authorization: Digest username="office", realm="asterisk", algorithm=MD5, uri="sip:083414166950@193.227.252.70", nonce="73c092d9", response="ed26dc07f1ced44dacfbddd30dc73c4c" Date: Fri, 20 Jul 2012 07:37:17 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 235 v=0 o=root 1791534486 1791534487 IN IP4 10.252.0.254 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.254 t=0 0 m=audio 15802 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv --- [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 193.227.252.70:5060 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK46329694;rport;received=10.252.0.254 From: "3412539603" ;tag=as6300648a To: Call-ID: 55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060 CSeq: 103 INVITE User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Contact: Content-Length: 0 <-------------> [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: --- (11 headers 0 lines) --- [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060' Request 103: Found [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK46329694;rport;received=10.252.0.254 From: "3412539603" ;tag=as6300648a To: ;tag=as06d9badf Call-ID: 55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060 CSeq: 103 INVITE User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Contact: Content-Length: 0 <-------------> [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: --- (11 headers 0 lines) --- [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060' Request 103: Found [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: build_route: Contact hop: [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: list_route: hop: [2012-07-20 11:37:17] VERBOSE[10287] app_dial.c: -- SIP/office-00000277 is ringing [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK46329694;rport;received=10.252.0.254 From: "3412539603" ;tag=as6300648a To: ;tag=as06d9badf Call-ID: 55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060 CSeq: 103 INVITE User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Contact: Content-Type: application/sdp Content-Length: 215 v=0 o=root 1098 1098 IN IP4 193.227.252.70 s=session c=IN IP4 193.227.252.70 t=0 0 m=audio 14856 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <-------------> [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: --- (12 headers 11 lines) --- [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060' Request 103: Found [2012-07-20 11:37:17] VERBOSE[10287] chan_sip.c: <--- Transmitting (NAT) to 10.252.0.246:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK374ba994;received=10.252.0.246;rport=5060 From: "3412539603" ;tag=as2b2e1a57 To: ;tag=as7371b9ef Call-ID: 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 CSeq: 103 INVITE Server: Asterisk PBX 10.6.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Session-Expires: 600;refresher=uas Contact: Content-Length: 0 <------------> [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: build_route: Contact hop: [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: list_route: hop: [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 10.252.0.246:5060 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Found RTP audio format 8 [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Setting payload 8 based on m type on 0xb6056ee8 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Found RTP audio format 101 [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Setting payload 101 based on m type on 0xb6056ee8 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Found audio description format PCMA for ID 8 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Found audio description format telephone-event for ID 101 [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Incorporating payload 8 on 0xb6056ee8 [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Incorporating payload 101 on 0xb6056ee8 [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Capabilities: us - (alaw), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw) [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [2012-07-20 11:37:17] DEBUG[9911] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xf2d8e08' [2012-07-20 11:37:17] VERBOSE[9911] chan_sip.c: Peer audio RTP is at port 193.227.252.70:14856 [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Copying payload 8 from 0xb6056ee8 to 0xf2d8fb4 [2012-07-20 11:37:17] DEBUG[9911] rtp_engine.c: Copying payload 101 from 0xb6056ee8 to 0xf2d8fb4 [2012-07-20 11:37:17] DEBUG[9911] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0xf2d8e08' [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: We're settling with these formats: (alaw) [2012-07-20 11:37:17] DEBUG[9911] chan_sip.c: Setting native formats after processing SDP. peer joint formats (alaw), old nativeformats (alaw) [2012-07-20 11:37:17] VERBOSE[10287] app_dial.c: -- SIP/office-00000277 is making progress passing it to SIP/office-gag-00000276 [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: Setting framing from config on incoming call [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: ** Our capability: (g729) Video flag: True Text flag: True [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: ** Our prefcodec: (nothing) [2012-07-20 11:37:17] VERBOSE[10287] chan_sip.c: Audio is at 10334 [2012-07-20 11:37:17] VERBOSE[10287] chan_sip.c: Adding codec 100008 (g729) to SDP [2012-07-20 11:37:17] VERBOSE[10287] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2012-07-20 11:37:17] VERBOSE[10287] chan_sip.c: <--- Transmitting (NAT) to 10.252.0.246:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK374ba994;received=10.252.0.246;rport=5060 From: "3412539603" ;tag=as2b2e1a57 To: ;tag=as7371b9ef Call-ID: 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 CSeq: 103 INVITE Server: Asterisk PBX 10.6.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Session-Expires: 600;refresher=uas Contact: Content-Type: application/sdp Content-Length: 256 v=0 o=root 728462413 728462413 IN IP4 10.252.0.254 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.254 t=0 0 m=audio 10334 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <------------> [2012-07-20 11:37:17] DEBUG[10287] chan_sip.c: Trying to put 'SIP/2.0 183' onto UDP socket destined for 10.252.0.246:5060 [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- start learning mode pass with addr = 193.227.252.70:14856 [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- probation = 4, seq = 65211 [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- Condition for learning hasn't exited, so reject the frame. [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: 0xf2b2e60 -- start learning mode pass with addr = 10.252.0.246:17680 [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: 0xf2b2e60 -- probation = 4, seq = 32658 [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: 0xf2b2e60 -- Condition for learning hasn't exited, so reject the frame. [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- start learning mode pass with addr = 193.227.252.70:14856 [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- probation = 3, seq = 65212 [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- Condition for learning hasn't exited, so reject the frame. [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: 0xf2b2e60 -- start learning mode pass with addr = 10.252.0.246:17680 [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: 0xf2b2e60 -- probation = 3, seq = 32659 [2012-07-20 11:37:17] DEBUG[10287] res_rtp_asterisk.c: 0xf2b2e60 -- Condition for learning hasn't exited, so reject the frame. [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- start learning mode pass with addr = 193.227.252.70:14856 [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- probation = 2, seq = 65213 [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- Condition for learning hasn't exited, so reject the frame. [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: 0xf2b2e60 -- start learning mode pass with addr = 10.252.0.246:17680 [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: 0xf2b2e60 -- probation = 2, seq = 32660 [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: 0xf2b2e60 -- Condition for learning hasn't exited, so reject the frame. [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- start learning mode pass with addr = 193.227.252.70:14856 [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- probation = 1, seq = 65214 [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- Probation Ended. Set strict_rtp_state to STRICT_RTP_CLOSED with address 193.227.252.70:14856 [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: Ooh, format changed from unknown to g729 [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: Created smoother: format: g729 ms: 20 len: 20 [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0xf2eed40' [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: 0xf2b2e60 -- start learning mode pass with addr = 10.252.0.246:17680 [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: 0xf2b2e60 -- probation = 1, seq = 32661 [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: 0xf2b2e60 -- Probation Ended. Set strict_rtp_state to STRICT_RTP_CLOSED with address 10.252.0.246:17680 [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: Ooh, format changed from unknown to alaw [2012-07-20 11:37:18] DEBUG[10287] res_rtp_asterisk.c: Created smoother: format: alaw ms: 20 len: 160 [2012-07-20 11:37:19] DEBUG[9911] chan_sip.c: Allocating new SIP dialog for 0d79ee2d6d7b3ac55d31a0dd357f31f3@10.252.0.254:5060 - OPTIONS (No RTP) [2012-07-20 11:37:19] DEBUG[9911] chan_sip.c: Initializing initreq for method OPTIONS - callid 7d4117af0de41b23089bd4a83a79aec4@10.252.0.254:5060 [2012-07-20 11:37:19] VERBOSE[9911] chan_sip.c: Reliably Transmitting (NAT) to 193.227.252.70:5060: OPTIONS sip:193.227.252.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK604230fb;rport Max-Forwards: 70 From: "asterisk" ;tag=as6bf73881 To: Contact: Call-ID: 7d4117af0de41b23089bd4a83a79aec4@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 10.6.0 Date: Fri, 20 Jul 2012 07:37:19 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2012-07-20 11:37:19] DEBUG[9911] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 193.227.252.70:5060 [2012-07-20 11:37:19] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK604230fb;rport;received=10.252.0.254 From: "asterisk" ;tag=as6bf73881 To: ;tag=as1ba6a152 Call-ID: 7d4117af0de41b23089bd4a83a79aec4@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <-------------> [2012-07-20 11:37:19] VERBOSE[9911] chan_sip.c: --- (12 headers 0 lines) --- [2012-07-20 11:37:19] DEBUG[9911] chan_sip.c: Stopping retransmission on '7d4117af0de41b23089bd4a83a79aec4@10.252.0.254:5060' of Request 102: Match Found [2012-07-20 11:37:19] DEBUG[9911] chan_sip.c: Session timer stopped: -1 - 7d4117af0de41b23089bd4a83a79aec4@10.252.0.254:5060 [2012-07-20 11:37:19] VERBOSE[9911] chan_sip.c: Really destroying SIP dialog '7d4117af0de41b23089bd4a83a79aec4@10.252.0.254:5060' Method: OPTIONS [2012-07-20 11:37:20] VERBOSE[9911] chan_sip.c: Really destroying SIP dialog '9yziw8@monitoring.udcom.ru' Method: OPTIONS [2012-07-20 11:37:20] VERBOSE[9911] chan_sip.c: Really destroying SIP dialog '6f867f8d2b0417d459a16ef3737e68cf@193.227.252.70' Method: OPTIONS [2012-07-20 11:37:22] DEBUG[10287] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-20 11:37:22] DEBUG[10287] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-20 11:37:27] NOTICE[9911] chan_sip.c: -- Re-registration for office-gag@office-gag [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: Allocating new SIP dialog for 112b01084f729b21514d594a4c193056@10.252.0.254 - REGISTER (No RTP) [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: Scheduled a registration timeout for office-gag id #34528 [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: >>> Re-using Auth data for office-gag@office-gag [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: Initializing initreq for method REGISTER - callid 112b01084f729b21514d594a4c193056@10.252.0.254 [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: REGISTER 11 headers, 0 lines [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: Reliably Transmitting (NAT) to 10.252.0.246:5060: REGISTER sip:office-gag SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK238b6add;rport Max-Forwards: 70 From: ;tag=as59b15394 To: Call-ID: 112b01084f729b21514d594a4c193056@10.252.0.254 CSeq: 1767 REGISTER User-Agent: Asterisk PBX 10.6.0 Authorization: Digest username="office-gag", realm="asterisk", algorithm=MD5, uri="sip:office-gag", nonce="621af9c5", response="0cfa6ec3fc21c6569525e22deeda9cdc" Expires: 120 Contact: Content-Length: 0 --- [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: Trying to put 'REGISTER si' onto UDP socket destined for 10.252.0.246:5060 [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK238b6add;received=10.252.0.254;rport=5060 From: ;tag=as59b15394 To: ;tag=as3d96d1a6 Call-ID: 112b01084f729b21514d594a4c193056@10.252.0.254 CSeq: 1767 REGISTER Server: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="699ef474" Content-Length: 0 <-------------> [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: --- (11 headers 0 lines) --- [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: Stopping retransmission on '112b01084f729b21514d594a4c193056@10.252.0.254' of Request 1767: Match Found [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: Responding to challenge, registration to domain/host name office-gag [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: Initializing already initialized SIP dialog 112b01084f729b21514d594a4c193056@10.252.0.254 (presumably reinvite) [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: REGISTER 11 headers, 0 lines [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: Reliably Transmitting (NAT) to 10.252.0.246:5060: REGISTER sip:office-gag SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK65e309ef;rport Max-Forwards: 70 From: ;tag=as7147692c To: Call-ID: 112b01084f729b21514d594a4c193056@10.252.0.254 CSeq: 1768 REGISTER User-Agent: Asterisk PBX 10.6.0 Authorization: Digest username="office-gag", realm="asterisk", algorithm=MD5, uri="sip:office-gag", nonce="699ef474", response="e3eaf4e428848f7fd618758033fab81a" Expires: 120 Contact: Content-Length: 0 --- [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: Trying to put 'REGISTER si' onto UDP socket destined for 10.252.0.246:5060 [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> OPTIONS sip:office-gag@10.252.0.254:5060 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK67b24b13;rport Max-Forwards: 70 From: "asterisk" ;tag=as17249007 To: Contact: Call-ID: 30bbf24d03266fbe4aabf7de6259f779@10.252.0.246:5060 CSeq: 102 OPTIONS User-Agent: Cisco-SIPGateway/IOS-12.x Date: Fri, 20 Jul 2012 07:37:27 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <-------------> [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: --- (15 headers 0 lines) --- [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: Allocating new SIP dialog for 30bbf24d03266fbe4aabf7de6259f779@10.252.0.246:5060 - OPTIONS (No RTP) [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: Looking for office-gag in default (domain 10.252.0.254) [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: <--- Transmitting (NAT) to 10.252.0.246:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK67b24b13;received=10.252.0.246;rport=5060 From: "asterisk" ;tag=as17249007 To: ;tag=as5f8996ec Call-ID: 30bbf24d03266fbe4aabf7de6259f779@10.252.0.246:5060 CSeq: 102 OPTIONS Server: Asterisk PBX 10.6.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <------------> [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.252.0.246:5060 [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: Scheduling destruction of SIP dialog '30bbf24d03266fbe4aabf7de6259f779@10.252.0.246:5060' in 32000 ms (Method: OPTIONS) [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK65e309ef;received=10.252.0.254;rport=5060 From: ;tag=as7147692c To: ;tag=as3d96d1a6 Call-ID: 112b01084f729b21514d594a4c193056@10.252.0.254 CSeq: 1768 REGISTER Server: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Expires: 120 Contact: ;expires=120 Date: Fri, 20 Jul 2012 07:37:27 GMT Content-Length: 0 <-------------> [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: --- (13 headers 0 lines) --- [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: Stopping retransmission on '112b01084f729b21514d594a4c193056@10.252.0.254' of Request 1768: Match Found [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: Registration successful [2012-07-20 11:37:27] DEBUG[9911] chan_sip.c: Cancelling timeout 34528 [2012-07-20 11:37:27] VERBOSE[9911] chan_sip.c: Scheduling destruction of SIP dialog '112b01084f729b21514d594a4c193056@10.252.0.254' in 6400 ms (Method: REGISTER) [2012-07-20 11:37:27] NOTICE[9911] chan_sip.c: Outbound Registration: Expiry for office-gag is 120 sec (Scheduling reregistration in 105 s) [2012-07-20 11:37:27] DEBUG[10287] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-20 11:37:27] DEBUG[10287] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-20 11:37:29] DEBUG[9911] chan_sip.c: Allocating new SIP dialog for 1960831276cd4408011a87ef118769f5@10.252.0.254:5060 - OPTIONS (No RTP) [2012-07-20 11:37:29] DEBUG[9911] chan_sip.c: Initializing initreq for method OPTIONS - callid 0a0d0671291efa2e66826ab63a2dbd23@10.252.0.254:5060 [2012-07-20 11:37:29] VERBOSE[9911] chan_sip.c: Reliably Transmitting (NAT) to 10.252.0.246:5060: OPTIONS sip:10.252.0.246 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK34ad4aa4;rport Max-Forwards: 70 From: "asterisk" ;tag=as499190ac To: Contact: Call-ID: 0a0d0671291efa2e66826ab63a2dbd23@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 10.6.0 Date: Fri, 20 Jul 2012 07:37:29 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2012-07-20 11:37:29] DEBUG[9911] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 10.252.0.246:5060 [2012-07-20 11:37:29] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK34ad4aa4;received=10.252.0.254;rport=5060 From: "asterisk" ;tag=as499190ac To: ;tag=as6d612a35 Call-ID: 0a0d0671291efa2e66826ab63a2dbd23@10.252.0.254:5060 CSeq: 102 OPTIONS Server: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <-------------> [2012-07-20 11:37:29] VERBOSE[9911] chan_sip.c: --- (12 headers 0 lines) --- [2012-07-20 11:37:29] DEBUG[9911] chan_sip.c: Stopping retransmission on '0a0d0671291efa2e66826ab63a2dbd23@10.252.0.254:5060' of Request 102: Match Found [2012-07-20 11:37:29] DEBUG[9911] chan_sip.c: Session timer stopped: -1 - 0a0d0671291efa2e66826ab63a2dbd23@10.252.0.254:5060 [2012-07-20 11:37:29] VERBOSE[9911] chan_sip.c: Really destroying SIP dialog '0a0d0671291efa2e66826ab63a2dbd23@10.252.0.254:5060' Method: OPTIONS [2012-07-20 11:37:32] DEBUG[10287] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-20 11:37:32] DEBUG[10287] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-20 11:37:33] VERBOSE[9911] chan_sip.c: Really destroying SIP dialog '112b01084f729b21514d594a4c193056@10.252.0.254' Method: REGISTER [2012-07-20 11:37:33] NOTICE[9911] chan_sip.c: -- Re-registration for office@office [2012-07-20 11:37:33] DEBUG[9911] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2012-07-20 11:37:33] DEBUG[9911] chan_sip.c: Allocating new SIP dialog for 2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254 - REGISTER (No RTP) [2012-07-20 11:37:33] DEBUG[9911] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2012-07-20 11:37:33] DEBUG[9911] chan_sip.c: Scheduled a registration timeout for office id #34537 [2012-07-20 11:37:33] DEBUG[9911] chan_sip.c: >>> Re-using Auth data for office@office [2012-07-20 11:37:33] DEBUG[9911] chan_sip.c: Initializing initreq for method REGISTER - callid 2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254 [2012-07-20 11:37:33] VERBOSE[9911] chan_sip.c: REGISTER 11 headers, 0 lines [2012-07-20 11:37:33] VERBOSE[9911] chan_sip.c: Reliably Transmitting (NAT) to 193.227.252.70:5060: REGISTER sip:office SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK67cadb33;rport Max-Forwards: 70 From: ;tag=as7319c363 To: Call-ID: 2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254 CSeq: 1766 REGISTER User-Agent: Asterisk PBX 10.6.0 Authorization: Digest username="office", realm="asterisk", algorithm=MD5, uri="sip:office", nonce="0029d407", response="a0e4c90b19b0c156b130efad20cdbde3" Expires: 120 Contact: Content-Length: 0 --- [2012-07-20 11:37:33] DEBUG[9911] chan_sip.c: Trying to put 'REGISTER si' onto UDP socket destined for 193.227.252.70:5060 [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK67cadb33;rport;received=10.252.0.254 From: ;tag=as7319c363 To: Call-ID: 2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254 CSeq: 1766 REGISTER User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Content-Length: 0 <-------------> [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: --- (10 headers 0 lines) --- [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK67cadb33;rport;received=10.252.0.254 From: ;tag=as7319c363 To: ;tag=as4fcb4d83 Call-ID: 2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254 CSeq: 1766 REGISTER User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="57749b89" Content-Length: 0 <-------------> [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: --- (11 headers 0 lines) --- [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Stopping retransmission on '2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254' of Request 1766: Match Found [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Responding to challenge, registration to domain/host name office [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Initializing already initialized SIP dialog 2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254 (presumably reinvite) [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: REGISTER 11 headers, 0 lines [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Reliably Transmitting (NAT) to 193.227.252.70:5060: REGISTER sip:office SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK1df26f76;rport Max-Forwards: 70 From: ;tag=as4ad9e432 To: Call-ID: 2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254 CSeq: 1767 REGISTER User-Agent: Asterisk PBX 10.6.0 Authorization: Digest username="office", realm="asterisk", algorithm=MD5, uri="sip:office", nonce="57749b89", response="0aae3732ab8b7a0f424a506466285368" Expires: 120 Contact: Content-Length: 0 --- [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Trying to put 'REGISTER si' onto UDP socket destined for 193.227.252.70:5060 [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK1df26f76;rport;received=10.252.0.254 From: ;tag=as4ad9e432 To: Call-ID: 2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254 CSeq: 1767 REGISTER User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Content-Length: 0 <-------------> [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: --- (10 headers 0 lines) --- [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:192.168.67.43:5060 ---> REGISTER sip:asterisk10 SIP/2.0 Via: SIP/2.0/UDP 192.168.67.43:5060;branch=z9hG4bK10b06fa6 From: ;tag=as10df41da To: Call-ID: 501acabf3bc605dc5dbfd65f2205c3e7@127.0.1.1 CSeq: 134 REGISTER User-Agent: Asterisk PBX Max-Forwards: 70 Authorization: Digest username="asterisk10", realm="asterisk", algorithm=MD5, uri="sip:asterisk10", nonce="00b0007d", response="d4340bf2d39a8cf5dc87477a0c7adaa3" Expires: 120 Contact: Event: registration Content-Length: 0 <-------------> [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: --- (13 headers 0 lines) --- [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Allocating new SIP dialog for 501acabf3bc605dc5dbfd65f2205c3e7@127.0.1.1 - REGISTER (No RTP) [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Sending to 192.168.67.43:5060 (NAT) [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- Transmitting (NAT) to 192.168.67.43:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.67.43:5060;branch=z9hG4bK10b06fa6;received=192.168.67.43;rport=5060 From: ;tag=as10df41da To: ;tag=as01d48b3b Call-ID: 501acabf3bc605dc5dbfd65f2205c3e7@127.0.1.1 CSeq: 134 REGISTER Server: Asterisk PBX 10.6.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42c654c2" Content-Length: 0 <------------> [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.67.43:5060 [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Scheduling destruction of SIP dialog '501acabf3bc605dc5dbfd65f2205c3e7@127.0.1.1' in 32000 ms (Method: REGISTER) [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> OPTIONS sip:office@10.252.0.254:5060 SIP/2.0 Via: SIP/2.0/UDP 193.227.252.70:5060;branch=z9hG4bK7ea9bf97 From: "asterisk" ;tag=as7091fd79 To: "" Contact: Call-ID: 13a2a32243b4a4664ead40573792363e@193.227.252.70 CSeq: 102 OPTIONS User-Agent: Cisco-SIPGateway/IOS-12.x Max-Forwards: 70 Date: Fri, 20 Jul 2012 07:37:34 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Content-Length: 0 <-------------> [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: --- (13 headers 0 lines) --- [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Allocating new SIP dialog for 13a2a32243b4a4664ead40573792363e@193.227.252.70 - OPTIONS (No RTP) [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Looking for office in default (domain 10.252.0.254) [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- Transmitting (NAT) to 193.227.252.70:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 193.227.252.70:5060;branch=z9hG4bK7ea9bf97;received=193.227.252.70;rport=5060 From: "asterisk" ;tag=as7091fd79 To: "" ;tag=as37ced651 Call-ID: 13a2a32243b4a4664ead40573792363e@193.227.252.70 CSeq: 102 OPTIONS Server: Asterisk PBX 10.6.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <------------> [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 193.227.252.70:5060 [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Scheduling destruction of SIP dialog '13a2a32243b4a4664ead40573792363e@193.227.252.70' in 32000 ms (Method: OPTIONS) [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK1df26f76;rport;received=10.252.0.254 From: ;tag=as4ad9e432 To: ;tag=as4fcb4d83 Call-ID: 2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254 CSeq: 1767 REGISTER User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Expires: 120 Contact: ;expires=120 Date: Fri, 20 Jul 2012 07:37:34 GMT Content-Length: 0 <-------------> [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: --- (13 headers 0 lines) --- [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Stopping retransmission on '2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254' of Request 1767: Match Found [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Registration successful [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Cancelling timeout 34537 [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Scheduling destruction of SIP dialog '2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254' in 6400 ms (Method: REGISTER) [2012-07-20 11:37:34] NOTICE[9911] chan_sip.c: Outbound Registration: Expiry for office is 120 sec (Scheduling reregistration in 105 s) [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:192.168.67.43:5060 ---> REGISTER sip:asterisk10 SIP/2.0 Via: SIP/2.0/UDP 192.168.67.43:5060;branch=z9hG4bK6cda586a From: ;tag=as179f46cd To: Call-ID: 501acabf3bc605dc5dbfd65f2205c3e7@127.0.1.1 CSeq: 135 REGISTER User-Agent: Asterisk PBX Max-Forwards: 70 Authorization: Digest username="asterisk10", realm="asterisk", algorithm=MD5, uri="sip:asterisk10", nonce="42c654c2", response="418334c3582ac2249a6d2af88fb8ebb1" Expires: 120 Contact: Event: registration Content-Length: 0 <-------------> [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: --- (13 headers 0 lines) --- [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Sending to 192.168.67.43:5060 (NAT) [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Store REGISTER's src-IP:port for call routing. [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Allocating new SIP dialog for 35c1b1f76b0893b811c738866ce7b38e@10.252.0.254:5060 - OPTIONS (No RTP) [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Initializing initreq for method OPTIONS - callid 43f7fade4bdc0a413bc65fd26d62b5d2@10.252.0.254:5060 [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Reliably Transmitting (NAT) to 192.168.67.43:5060: OPTIONS sip:asterisk10@192.168.67.43 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK5f7d01ec;rport Max-Forwards: 70 From: "asterisk" ;tag=as6fecae88 To: Contact: Call-ID: 43f7fade4bdc0a413bc65fd26d62b5d2@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 10.6.0 Date: Fri, 20 Jul 2012 07:37:34 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.67.43:5060 [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- Transmitting (NAT) to 192.168.67.43:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.67.43:5060;branch=z9hG4bK6cda586a;received=192.168.67.43;rport=5060 From: ;tag=as179f46cd To: ;tag=as01d48b3b Call-ID: 501acabf3bc605dc5dbfd65f2205c3e7@127.0.1.1 CSeq: 135 REGISTER Server: Asterisk PBX 10.6.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Expires: 120 Contact: ;expires=120 Date: Fri, 20 Jul 2012 07:37:34 GMT Content-Length: 0 <------------> [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.67.43:5060 [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Scheduling destruction of SIP dialog '501acabf3bc605dc5dbfd65f2205c3e7@127.0.1.1' in 32000 ms (Method: REGISTER) [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:192.168.67.43:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK5f7d01ec;rport;received=10.252.0.254 From: "asterisk" ;tag=as6fecae88 To: ;tag=as43671ad4 Call-ID: 43f7fade4bdc0a413bc65fd26d62b5d2@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <-------------> [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: --- (12 headers 0 lines) --- [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Stopping retransmission on '43f7fade4bdc0a413bc65fd26d62b5d2@10.252.0.254:5060' of Request 102: Match Found [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Session timer stopped: -1 - 43f7fade4bdc0a413bc65fd26d62b5d2@10.252.0.254:5060 [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Really destroying SIP dialog '43f7fade4bdc0a413bc65fd26d62b5d2@10.252.0.254:5060' Method: OPTIONS [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:192.168.67.43:5060 ---> OPTIONS sip:10.252.0.254 SIP/2.0 Via: SIP/2.0/UDP 192.168.67.43:5060;branch=z9hG4bK33fe6d3c From: "asterisk" ;tag=as2e9f59f5 To: "" Contact: Call-ID: 376def170bf72f661fec3ead329eaf48@192.168.67.43 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Fri, 20 Jul 2012 07:37:34 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Content-Length: 0 <-------------> [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: --- (13 headers 0 lines) --- [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Allocating new SIP dialog for 376def170bf72f661fec3ead329eaf48@192.168.67.43 - OPTIONS (No RTP) [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Looking for s in default (domain 10.252.0.254) [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: <--- Transmitting (NAT) to 192.168.67.43:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.67.43:5060;branch=z9hG4bK33fe6d3c;received=192.168.67.43;rport=5060 From: "asterisk" ;tag=as2e9f59f5 To: "" ;tag=as1982b107 Call-ID: 376def170bf72f661fec3ead329eaf48@192.168.67.43 CSeq: 102 OPTIONS Server: Asterisk PBX 10.6.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <------------> [2012-07-20 11:37:34] DEBUG[9911] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.67.43:5060 [2012-07-20 11:37:34] VERBOSE[9911] chan_sip.c: Scheduling destruction of SIP dialog '376def170bf72f661fec3ead329eaf48@192.168.67.43' in 32000 ms (Method: OPTIONS) [2012-07-20 11:37:36] DEBUG[9896] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [2012-07-20 11:37:36] DEBUG[9896] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [2012-07-20 11:37:36] VERBOSE[9896] sig_pri.c: -- Accepting overlap call from '3412600512' to '4' on channel 0/9, span 1 [2012-07-20 11:37:36] VERBOSE[10295] sig_pri.c: -- Starting simple switch on 'DAHDI/i1/3412600512-590' [2012-07-20 11:37:36] DTMF[10295] channel.c: DTMF end '8' received on DAHDI/i1/3412600512-590, duration 0 ms [2012-07-20 11:37:36] DTMF[10295] channel.c: DTMF end accepted without begin '8' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DTMF[10295] channel.c: DTMF end passthrough '8' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DEBUG[10295] chan_dahdi.c: Absorbing inband begin DTMF digit: 0x33 '3' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DEBUG[10295] chan_dahdi.c: Absorbing inband end DTMF digit: 0x33 '3' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DTMF[10295] channel.c: DTMF end '3' received on DAHDI/i1/3412600512-590, duration 0 ms [2012-07-20 11:37:36] DTMF[10295] channel.c: DTMF end accepted without begin '3' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DTMF[10295] channel.c: DTMF end passthrough '3' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DEBUG[10295] chan_dahdi.c: Absorbing inband begin DTMF digit: 0x33 '3' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DEBUG[10295] chan_dahdi.c: Absorbing inband end DTMF digit: 0x33 '3' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DTMF[10295] channel.c: DTMF end '3' received on DAHDI/i1/3412600512-590, duration 0 ms [2012-07-20 11:37:36] DTMF[10295] channel.c: DTMF end accepted without begin '3' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DTMF[10295] channel.c: DTMF end passthrough '3' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DEBUG[10295] chan_dahdi.c: Absorbing inband begin DTMF digit: 0x30 '0' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DEBUG[10295] chan_dahdi.c: Absorbing inband end DTMF digit: 0x30 '0' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DTMF[10295] channel.c: DTMF end '0' received on DAHDI/i1/3412600512-590, duration 0 ms [2012-07-20 11:37:36] DTMF[10295] channel.c: DTMF end accepted without begin '0' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DTMF[10295] channel.c: DTMF end passthrough '0' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:36] DEBUG[10295] chan_dahdi.c: Absorbing inband begin DTMF digit: 0x35 '5' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:37] DEBUG[10295] chan_dahdi.c: Absorbing inband end DTMF digit: 0x35 '5' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:37] DTMF[10295] channel.c: DTMF end '5' received on DAHDI/i1/3412600512-590, duration 0 ms [2012-07-20 11:37:37] DTMF[10295] channel.c: DTMF end accepted without begin '5' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:37] DTMF[10295] channel.c: DTMF end passthrough '5' on DAHDI/i1/3412600512-590 [2012-07-20 11:37:37] DEBUG[10295] chan_dahdi.c: Enabled echo cancellation on channel 9 [2012-07-20 11:37:37] DEBUG[10295] pbx.c: Launching 'Goto' [2012-07-20 11:37:37] VERBOSE[10295] pbx.c: -- Executing [483305@from-office:1] Goto("DAHDI/i1/3412600512-590", "from-office-filtered,483305,1") in new stack [2012-07-20 11:37:37] VERBOSE[10295] pbx.c: -- Goto (from-office-filtered,483305,1) [2012-07-20 11:37:37] DEBUG[10295] pbx.c: Function result is '"" <3412600512>' [2012-07-20 11:37:37] DEBUG[10295] pbx.c: Launching 'NoOp' [2012-07-20 11:37:37] VERBOSE[10295] pbx.c: -- Executing [483305@from-office-filtered:1] NoOp("DAHDI/i1/3412600512-590", "Call from '"" <3412600512>' to '483305'") in new stack [2012-07-20 11:37:37] DEBUG[10295] func_strings.c: Allowed: 0123456789 [2012-07-20 11:37:37] DEBUG[10295] pbx.c: Function result is '483305' [2012-07-20 11:37:37] DEBUG[10295] pbx.c: Launching 'Set' [2012-07-20 11:37:37] VERBOSE[10295] pbx.c: -- Executing [483305@from-office-filtered:2] Set("DAHDI/i1/3412600512-590", "route=483305") in new stack [2012-07-20 11:37:37] DEBUG[10295] pbx.c: Launching 'Dial' [2012-07-20 11:37:37] VERBOSE[10295] pbx.c: -- Executing [483305@from-office-filtered:3] Dial("DAHDI/i1/3412600512-590", "SIP/office/483305") in new stack [2012-07-20 11:37:37] DEBUG[10295] chan_sip.c: Asked to create a SIP channel with formats: (alaw) [2012-07-20 11:37:37] DEBUG[10295] chan_sip.c: Allocating new SIP dialog for 71f715ff2ce6c1a6458a91e9402ad372@10.252.0.254:5060 - INVITE (No RTP) [2012-07-20 11:37:37] DEBUG[10295] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xf4aea50' [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: Allocated port 11328 for RTP instance '0xf4aea50' [2012-07-20 11:37:37] DEBUG[10295] rtp_engine.c: RTP instance '0xf4aea50' is setup and ready to go [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xf4aea50' [2012-07-20 11:37:37] VERBOSE[10295] netsock2.c: == Using SIP RTP CoS mark 5 [2012-07-20 11:37:37] DEBUG[10295] chan_sip.c: Setting NAT on RTP to On [2012-07-20 11:37:37] DEBUG[10295] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2012-07-20 11:37:37] DEBUG[10295] res_fax.c: Attached T.38 gateway to channel SIP/office-00000278. [2012-07-20 11:37:37] DEBUG[10295] channel.c: Not copying variable DIALEDTIME. [2012-07-20 11:37:37] DEBUG[10295] channel.c: Not copying variable ANSWEREDTIME. [2012-07-20 11:37:37] DEBUG[10295] channel.c: Not copying variable DIALEDPEERNAME. [2012-07-20 11:37:37] DEBUG[10295] channel.c: Not copying variable DIALEDPEERNUMBER. [2012-07-20 11:37:37] DEBUG[10295] channel.c: Not copying variable DIALSTATUS. [2012-07-20 11:37:37] DEBUG[10295] channel.c: Not copying variable route. [2012-07-20 11:37:37] DEBUG[10295] channel.c: Not copying variable PRIREDIRECTREASON. [2012-07-20 11:37:37] DEBUG[10295] channel.c: Not copying variable CALLEDTON. [2012-07-20 11:37:37] DEBUG[10295] channel.c: Not copying variable ANI2. [2012-07-20 11:37:37] DEBUG[10295] channel.c: Not copying variable TRANSFERCAPABILITY. [2012-07-20 11:37:37] DEBUG[10295] chan_sip.c: Outgoing Call for 483305 [2012-07-20 11:37:37] DEBUG[10295] chan_sip.c: ** Our capability: (alaw) Video flag: False Text flag: False [2012-07-20 11:37:37] DEBUG[10295] chan_sip.c: ** Our prefcodec: (alaw) [2012-07-20 11:37:37] VERBOSE[10295] chan_sip.c: Audio is at 11328 [2012-07-20 11:37:37] VERBOSE[10295] chan_sip.c: Adding codec 100004 (alaw) to SDP [2012-07-20 11:37:37] VERBOSE[10295] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2012-07-20 11:37:37] DEBUG[10295] chan_sip.c: Initializing initreq for method INVITE - callid 0d54765120d28e2a6d18a5fb29ed6221@10.252.0.254:5060 [2012-07-20 11:37:37] VERBOSE[10295] chan_sip.c: Reliably Transmitting (NAT) to 193.227.252.70:5060: INVITE sip:483305@193.227.252.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK3abb2123;rport Max-Forwards: 70 From: "3412600512" ;tag=as3a44e145 To: Contact: Call-ID: 0d54765120d28e2a6d18a5fb29ed6221@10.252.0.254:5060 CSeq: 102 INVITE User-Agent: Asterisk PBX 10.6.0 Date: Fri, 20 Jul 2012 07:37:37 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 233 v=0 o=root 964351009 964351009 IN IP4 10.252.0.254 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.254 t=0 0 m=audio 11328 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv --- [2012-07-20 11:37:37] DEBUG[10295] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 193.227.252.70:5060 [2012-07-20 11:37:37] VERBOSE[10295] app_dial.c: -- Called SIP/office/483305 [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK3abb2123;rport;received=10.252.0.254 From: "3412600512" ;tag=as3a44e145 To: ;tag=as23e3175b Call-ID: 0d54765120d28e2a6d18a5fb29ed6221@10.252.0.254:5060 CSeq: 102 INVITE User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="0c30c369" Content-Length: 0 <-------------> [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: --- (11 headers 0 lines) --- [2012-07-20 11:37:37] DEBUG[9911] chan_sip.c: Acked pending invite 102 [2012-07-20 11:37:37] DEBUG[9911] chan_sip.c: Stopping retransmission on '0d54765120d28e2a6d18a5fb29ed6221@10.252.0.254:5060' of Request 102: Match Found [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: Transmitting (NAT) to 193.227.252.70:5060: ACK sip:483305@193.227.252.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK3abb2123;rport Max-Forwards: 70 From: "3412600512" ;tag=as3a44e145 To: ;tag=as23e3175b Contact: Call-ID: 0d54765120d28e2a6d18a5fb29ed6221@10.252.0.254:5060 CSeq: 102 ACK User-Agent: Asterisk PBX 10.6.0 Content-Length: 0 --- [2012-07-20 11:37:37] DEBUG[9911] chan_sip.c: Trying to put 'ACK sip:483' onto UDP socket destined for 193.227.252.70:5060 [2012-07-20 11:37:37] DEBUG[9911] chan_sip.c: Auth attempt 1 on INVITE [2012-07-20 11:37:37] DEBUG[9911] chan_sip.c: ** Our capability: (alaw) Video flag: False Text flag: False [2012-07-20 11:37:37] DEBUG[9911] chan_sip.c: ** Our prefcodec: (alaw) [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: Audio is at 11328 [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: Adding codec 100004 (alaw) to SDP [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: Reliably Transmitting (NAT) to 193.227.252.70:5060: INVITE sip:483305@193.227.252.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK36343f2b;rport Max-Forwards: 70 From: "3412600512" ;tag=as3a44e145 To: Contact: Call-ID: 0d54765120d28e2a6d18a5fb29ed6221@10.252.0.254:5060 CSeq: 103 INVITE User-Agent: Asterisk PBX 10.6.0 Proxy-Authorization: Digest username="office", realm="asterisk", algorithm=MD5, uri="sip:483305@193.227.252.70", nonce="0c30c369", response="7faf550f9f4bf026965e267c5cd8b3d6" Date: Fri, 20 Jul 2012 07:37:37 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 233 v=0 o=root 964351009 964351010 IN IP4 10.252.0.254 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.254 t=0 0 m=audio 11328 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv --- [2012-07-20 11:37:37] DEBUG[10295] channel.c: Deadlock avoided for write to channel 'SIP/office-00000278' [2012-07-20 11:37:37] DEBUG[9911] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 193.227.252.70:5060 [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK36343f2b;rport;received=10.252.0.254 From: "3412600512" ;tag=as3a44e145 To: Call-ID: 0d54765120d28e2a6d18a5fb29ed6221@10.252.0.254:5060 CSeq: 103 INVITE User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Contact: Content-Length: 0 <-------------> [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: --- (11 headers 0 lines) --- [2012-07-20 11:37:37] DEBUG[9911] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0d54765120d28e2a6d18a5fb29ed6221@10.252.0.254:5060' Request 103: Found [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] DEBUG[10287] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-20 11:37:37] DEBUG[10287] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: No remote address on RTP instance '0xf4aea50' so dropping frame [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK36343f2b;rport;received=10.252.0.254 From: "3412600512" ;tag=as3a44e145 To: ;tag=as01e2828b Call-ID: 0d54765120d28e2a6d18a5fb29ed6221@10.252.0.254:5060 CSeq: 103 INVITE User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Contact: Content-Type: application/sdp Content-Length: 215 v=0 o=root 1098 1098 IN IP4 193.227.252.70 s=session c=IN IP4 193.227.252.70 t=0 0 m=audio 10026 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <-------------> [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: --- (12 headers 11 lines) --- [2012-07-20 11:37:37] DEBUG[9911] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0d54765120d28e2a6d18a5fb29ed6221@10.252.0.254:5060' Request 103: Found [2012-07-20 11:37:37] DEBUG[9911] chan_sip.c: build_route: Contact hop: [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: list_route: hop: [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: Found RTP audio format 8 [2012-07-20 11:37:37] DEBUG[9911] rtp_engine.c: Setting payload 8 based on m type on 0xb6056ee8 [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: Found RTP audio format 101 [2012-07-20 11:37:37] DEBUG[9911] rtp_engine.c: Setting payload 101 based on m type on 0xb6056ee8 [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: Found audio description format PCMA for ID 8 [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: Found audio description format telephone-event for ID 101 [2012-07-20 11:37:37] DEBUG[9911] rtp_engine.c: Incorporating payload 8 on 0xb6056ee8 [2012-07-20 11:37:37] DEBUG[9911] rtp_engine.c: Incorporating payload 101 on 0xb6056ee8 [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: Capabilities: us - (alaw), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw) [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [2012-07-20 11:37:37] DEBUG[9911] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xf4aea50' [2012-07-20 11:37:37] VERBOSE[9911] chan_sip.c: Peer audio RTP is at port 193.227.252.70:10026 [2012-07-20 11:37:37] DEBUG[9911] rtp_engine.c: Copying payload 8 from 0xb6056ee8 to 0xf4aebfc [2012-07-20 11:37:37] DEBUG[9911] rtp_engine.c: Copying payload 101 from 0xb6056ee8 to 0xf4aebfc [2012-07-20 11:37:37] DEBUG[9911] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0xf4aea50' [2012-07-20 11:37:37] DEBUG[9911] chan_sip.c: We're settling with these formats: (alaw) [2012-07-20 11:37:37] DEBUG[9911] chan_sip.c: Setting native formats after processing SDP. peer joint formats (alaw), old nativeformats (alaw) [2012-07-20 11:37:37] VERBOSE[10295] app_dial.c: -- SIP/office-00000278 is making progress passing it to DAHDI/i1/3412600512-590 [2012-07-20 11:37:37] DEBUG[10295] chan_dahdi.c: Requested indication 14 on channel DAHDI/i1/3412600512-590 [2012-07-20 11:37:37] DEBUG[10295] sig_pri.c: Received AST_CONTROL_PROGRESS on DAHDI/i1/3412600512-590 [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: Ooh, format changed from unknown to alaw [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: Created smoother: format: alaw ms: 20 len: 160 [2012-07-20 11:37:37] DEBUG[10295] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0xf4aea50' [2012-07-20 11:37:38] DEBUG[10295] res_rtp_asterisk.c: 0xf30cc30 -- start learning mode pass with addr = 193.227.252.70:10026 [2012-07-20 11:37:38] DEBUG[10295] res_rtp_asterisk.c: 0xf30cc30 -- probation = 4, seq = 44792 [2012-07-20 11:37:38] DEBUG[10295] res_rtp_asterisk.c: 0xf30cc30 -- Condition for learning hasn't exited, so reject the frame. [2012-07-20 11:37:38] DEBUG[10295] res_rtp_asterisk.c: 0xf30cc30 -- start learning mode pass with addr = 193.227.252.70:10026 [2012-07-20 11:37:38] DEBUG[10295] res_rtp_asterisk.c: 0xf30cc30 -- probation = 3, seq = 44793 [2012-07-20 11:37:38] DEBUG[10295] res_rtp_asterisk.c: 0xf30cc30 -- Condition for learning hasn't exited, so reject the frame. [2012-07-20 11:37:38] DEBUG[10295] res_rtp_asterisk.c: 0xf30cc30 -- start learning mode pass with addr = 193.227.252.70:10026 [2012-07-20 11:37:38] DEBUG[10295] res_rtp_asterisk.c: 0xf30cc30 -- probation = 2, seq = 44794 [2012-07-20 11:37:38] DEBUG[10295] res_rtp_asterisk.c: 0xf30cc30 -- Condition for learning hasn't exited, so reject the frame. [2012-07-20 11:37:38] DEBUG[10295] res_rtp_asterisk.c: 0xf30cc30 -- start learning mode pass with addr = 193.227.252.70:10026 [2012-07-20 11:37:38] DEBUG[10295] res_rtp_asterisk.c: 0xf30cc30 -- probation = 1, seq = 44795 [2012-07-20 11:37:38] DEBUG[10295] res_rtp_asterisk.c: 0xf30cc30 -- Probation Ended. Set strict_rtp_state to STRICT_RTP_CLOSED with address 193.227.252.70:10026 [2012-07-20 11:37:40] VERBOSE[9911] chan_sip.c: Really destroying SIP dialog '2df7b478435414bc72eb0e3e1b6b8a3d@10.252.0.254' Method: REGISTER [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK46329694;rport;received=10.252.0.254 From: "3412539603" ;tag=as6300648a To: ;tag=as06d9badf Call-ID: 55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060 CSeq: 103 INVITE User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Contact: Content-Type: application/sdp Content-Length: 215 v=0 o=root 1098 1099 IN IP4 193.227.252.70 s=session c=IN IP4 193.227.252.70 t=0 0 m=audio 14856 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <-------------> [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: --- (12 headers 11 lines) --- [2012-07-20 11:37:41] DEBUG[9911] chan_sip.c: Acked pending invite 103 [2012-07-20 11:37:41] DEBUG[9911] chan_sip.c: Stopping retransmission on '55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060' of Request 103: Match Found [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: Found RTP audio format 8 [2012-07-20 11:37:41] DEBUG[9911] rtp_engine.c: Setting payload 8 based on m type on 0xb6056ee8 [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: Found RTP audio format 101 [2012-07-20 11:37:41] DEBUG[9911] rtp_engine.c: Setting payload 101 based on m type on 0xb6056ee8 [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: Found audio description format PCMA for ID 8 [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: Found audio description format telephone-event for ID 101 [2012-07-20 11:37:41] DEBUG[9911] rtp_engine.c: Incorporating payload 8 on 0xb6056ee8 [2012-07-20 11:37:41] DEBUG[9911] rtp_engine.c: Incorporating payload 101 on 0xb6056ee8 [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: Capabilities: us - (alaw), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw) [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [2012-07-20 11:37:41] DEBUG[9911] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xf2d8e08' [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: Peer audio RTP is at port 193.227.252.70:14856 [2012-07-20 11:37:41] DEBUG[9911] rtp_engine.c: Copying payload 8 from 0xb6056ee8 to 0xf2d8fb4 [2012-07-20 11:37:41] DEBUG[9911] rtp_engine.c: Copying payload 101 from 0xb6056ee8 to 0xf2d8fb4 [2012-07-20 11:37:41] DEBUG[9911] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0xf2d8e08' [2012-07-20 11:37:41] DEBUG[9911] chan_sip.c: We're settling with these formats: (alaw) [2012-07-20 11:37:41] DEBUG[9911] chan_sip.c: Setting native formats after processing SDP. peer joint formats (alaw), old nativeformats (alaw) [2012-07-20 11:37:41] DEBUG[9911] chan_sip.c: build_route: Contact hop: [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: list_route: hop: [2012-07-20 11:37:41] DEBUG[9911] chan_sip.c: Session timer started: 34554 - 55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060 [2012-07-20 11:37:41] DEBUG[9911] chan_sip.c: Strict routing enforced for session 55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060 [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: set_destination: Parsing for address/port to send to [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: set_destination: set destination to 193.227.252.70:5060 [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: Transmitting (NAT) to 193.227.252.70:5060: ACK sip:083414166950@193.227.252.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK5e81a564;rport Max-Forwards: 70 From: "3412539603" ;tag=as6300648a To: ;tag=as06d9badf Contact: Call-ID: 55cf568c7663c1485aebb7104d02651f@10.252.0.254:5060 CSeq: 103 ACK User-Agent: Asterisk PBX 10.6.0 Content-Length: 0 --- [2012-07-20 11:37:41] DEBUG[9911] chan_sip.c: Trying to put 'ACK sip:083' onto UDP socket destined for 193.227.252.70:5060 [2012-07-20 11:37:41] VERBOSE[10287] app_dial.c: -- SIP/office-00000277 answered SIP/office-gag-00000276 [2012-07-20 11:37:41] DEBUG[10287] chan_sip.c: SIP answering channel: SIP/office-gag-00000276 [2012-07-20 11:37:41] DEBUG[10287] chan_sip.c: Setting framing from config on incoming call [2012-07-20 11:37:41] DEBUG[10287] chan_sip.c: ** Our capability: (g729) Video flag: True Text flag: True [2012-07-20 11:37:41] DEBUG[10287] chan_sip.c: ** Our prefcodec: (nothing) [2012-07-20 11:37:41] VERBOSE[10287] chan_sip.c: Audio is at 10334 [2012-07-20 11:37:41] VERBOSE[10287] chan_sip.c: Adding codec 100008 (g729) to SDP [2012-07-20 11:37:41] VERBOSE[10287] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2012-07-20 11:37:41] VERBOSE[10287] chan_sip.c: <--- Reliably Transmitting (NAT) to 10.252.0.246:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK374ba994;received=10.252.0.246;rport=5060 From: "3412539603" ;tag=as2b2e1a57 To: ;tag=as7371b9ef Call-ID: 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 CSeq: 103 INVITE Server: Asterisk PBX 10.6.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Session-Expires: 600;refresher=uas Contact: Content-Type: application/sdp Content-Length: 256 v=0 o=root 728462413 728462414 IN IP4 10.252.0.254 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.254 t=0 0 m=audio 10334 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <------------> [2012-07-20 11:37:41] DEBUG[10287] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.252.0.246:5060 [2012-07-20 11:37:41] DEBUG[10287] features.c: Removing dialed interfaces datastore on SIP/office-00000277 since we're bridging [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> ACK sip:083414166950@10.252.0.254:5060 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK2db9ad8a;rport Max-Forwards: 70 From: "3412539603" ;tag=as2b2e1a57 To: ;tag=as7371b9ef Contact: Call-ID: 57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060 CSeq: 103 ACK User-Agent: Cisco-SIPGateway/IOS-12.x Content-Length: 0 <-------------> [2012-07-20 11:37:41] VERBOSE[9911] chan_sip.c: --- (10 headers 0 lines) --- [2012-07-20 11:37:41] DEBUG[9911] chan_sip.c: Stopping retransmission on '57e05f435fef392b7a805cb3176ebcf5@10.252.0.246:5060' of Response 103: Match Found [2012-07-20 11:37:41] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- start learning mode pass with addr = 193.227.252.70:14856 [2012-07-20 11:37:41] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- probation = 4, seq = 836 [2012-07-20 11:37:41] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- Condition for learning hasn't exited, so reject the frame. [2012-07-20 11:37:41] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- start learning mode pass with addr = 193.227.252.70:14856 [2012-07-20 11:37:41] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- probation = 3, seq = 837 [2012-07-20 11:37:41] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- Condition for learning hasn't exited, so reject the frame. [2012-07-20 11:37:41] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- start learning mode pass with addr = 193.227.252.70:14856 [2012-07-20 11:37:41] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- probation = 2, seq = 838 [2012-07-20 11:37:41] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- Condition for learning hasn't exited, so reject the frame. [2012-07-20 11:37:41] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- start learning mode pass with addr = 193.227.252.70:14856 [2012-07-20 11:37:41] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- probation = 1, seq = 839 [2012-07-20 11:37:41] DEBUG[10287] res_rtp_asterisk.c: 0xf2b74e8 -- Probation Ended. Set strict_rtp_state to STRICT_RTP_CLOSED with address 193.227.252.70:14856 [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/asterisk.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/asterisk.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action DBGet [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action DBPut [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action DBDel [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action DBDelTree [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered custom function 'MESSAGE' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered custom function 'MESSAGE_DATA' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'MessageSend' [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action DataGet [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/codecs.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/codecs.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] VERBOSE[10304] loader.c: Asterisk Dynamic Loader Starting: [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/modules.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/modules.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/dnsmgr.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/dnsmgr.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/http.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/http.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] WARNING[10304] http.c: Got 1 addresses [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Ping [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Events [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Logoff [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Login [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Challenge [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Hangup [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Status [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Setvar [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Getvar [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action GetConfig [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action GetConfigJSON [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action UpdateConfig [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action CreateConfig [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action ListCategories [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Redirect [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Atxfer [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Originate [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Command [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action ExtensionState [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action AbsoluteTimeout [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action MailboxStatus [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action MailboxCount [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action ListCommands [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action SendText [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action UserEvent [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action WaitEvent [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action CoreSettings [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action CoreStatus [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Reload [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action CoreShowChannels [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action ModuleLoad [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action ModuleCheck [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action AOCMessage [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Filter [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/manager.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/manager.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/users.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/users.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] DEBUG[10304] tcptls.c: Nothing changed in AMI server [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/cdr.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/cdr.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] NOTICE[10304] cdr.c: CDR simple logging enabled. [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/cel.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/cel.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] VERBOSE[10304] cel.c: -- CEL logging disabled. [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/dsp.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/dsp.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/udptl.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/udptl.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] VERBOSE[10304] udptl.c: == UDPTL allocating from port range 4000 -> 4999 [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: Asterisk PBX Core Initializing [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: Registering builtin applications: [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered custom function 'EXCEPTION' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered custom function 'TESTTIME' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [Answer] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Answer' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [BackGround] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'BackGround' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [Busy] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Busy' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [Congestion] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Congestion' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [ExecIfTime] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'ExecIfTime' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [Goto] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Goto' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [GotoIf] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'GotoIf' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [GotoIfTime] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'GotoIfTime' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [ImportVar] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'ImportVar' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [Hangup] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Hangup' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [Incomplete] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Incomplete' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [NoOp] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'NoOp' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [Proceeding] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Proceeding' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [Progress] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Progress' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [RaiseException] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'RaiseException' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [ResetCDR] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'ResetCDR' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [Ringing] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Ringing' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [SayAlpha] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'SayAlpha' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [SayDigits] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'SayDigits' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [SayNumber] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'SayNumber' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [SayPhonetic] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'SayPhonetic' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [Set] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Set' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [MSet] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'MSet' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [SetAMAFlags] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'SetAMAFlags' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [Wait] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Wait' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: [WaitExten] [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'WaitExten' [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action ShowDialPlan [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/indications.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/indications.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'at' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'au' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'bg' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'br' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'be' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'ch' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'cl' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'cn' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'cz' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'de' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'dk' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'ee' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'es' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'fi' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'fr' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'gr' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'hu' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'il' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'in' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'it' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'lt' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'jp' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'mx' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'my' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'nl' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'no' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'nz' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'ph' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'pl' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'pt' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'ru' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'se' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'sg' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'th' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'uk' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'us' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'us-old' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'tw' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 've' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Registered indication country 'za' [2012-07-20 11:37:42] VERBOSE[10304] indications.c: -- Setting default indication country to 'ru' [2012-07-20 11:37:42] DEBUG[10304] features.c: Building parking lot default [2012-07-20 11:37:42] DEBUG[10304] features.c: Configuration of default default parking lot done. [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/features.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/features.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] DEBUG[10304] features.c: Found Parking lot: default [2012-07-20 11:37:42] DEBUG[10304] features.c: Building parking lot default [2012-07-20 11:37:42] DEBUG[10304] pbx.c: Registered context 'parkedcalls'(0x8711e48) in table 0x8711da8 registrar: features [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: -- Registered extension context 'parkedcalls'; registrar: features [2012-07-20 11:37:42] DEBUG[10304] pbx.c: Added extension '700' priority 1 to parkedcalls (0x8711e48) [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: -- Added extension '700' priority 1 to parkedcalls [2012-07-20 11:37:42] DEBUG[10304] features.c: Parking lot default now open for business. (parkpos 701-750) [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Bridge' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'ParkedCall' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Park' [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action ParkedCalls [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Park [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Bridge [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/enum.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/enum.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'CallCompletionRequest' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'CallCompletionCancel' [2012-07-20 11:37:42] DEBUG[10304] logger.c: Registered dynamic logger level 'CC' with index 16. [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/ccss.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/ccss.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/ccss.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/ccss.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] VERBOSE[10304] loader.c: Asterisk Dynamic Loader Starting: [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/modules.conf': [2012-07-20 11:37:42] DEBUG[10304] config.c: Parsing /etc/asterisk/modules.conf [2012-07-20 11:37:42] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:42] NOTICE[10304] loader.c: 46 modules will be loaded. [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'Monitor' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'StopMonitor' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'ChangeMonitor' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'PauseMonitor' [2012-07-20 11:37:42] VERBOSE[10304] pbx.c: == Registered application 'UnpauseMonitor' [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action Monitor [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action StopMonitor [2012-07-20 11:37:42] VERBOSE[10304] manager.c: == Manager registered action ChangeMonitor [2012-07-20 11:37:43] VERBOSE[10304] manager.c: == Manager registered action PauseMonitor [2012-07-20 11:37:43] VERBOSE[10304] manager.c: == Manager registered action UnpauseMonitor [2012-07-20 11:37:43] VERBOSE[10304] loader.c: res_monitor.so => (Call Monitoring Resource) [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'answer' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'asyncagi break' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'channel status' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'database del' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'database deltree' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'database get' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'database put' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'exec' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'get data' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'get full variable' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'get option' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'get variable' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'hangup' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'noop' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'receive char' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'receive text' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'record file' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'say alpha' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'say digits' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'say number' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'say phonetic' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'say date' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'say time' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'say datetime' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'send image' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'send text' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'set autohangup' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'set callerid' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'set context' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'set extension' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'set music' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'set priority' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'set variable' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'stream file' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'control stream file' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'tdd mode' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'verbose' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'wait for digit' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'speech create' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'speech set' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'speech destroy' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'speech load grammar' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'speech unload grammar' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'speech activate grammar' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'speech deactivate grammar' registered [2012-07-20 11:37:43] VERBOSE[10304] res_agi.c: == AGI Command 'speech recognize' registered [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered application 'DeadAGI' [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered application 'EAGI' [2012-07-20 11:37:43] VERBOSE[10304] manager.c: == Manager registered action AGI [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered application 'AGI' [2012-07-20 11:37:43] VERBOSE[10304] loader.c: res_agi.so => (Asterisk Gateway Interface (AGI)) [2012-07-20 11:37:43] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/res_fax.conf': [2012-07-20 11:37:43] DEBUG[10304] config.c: Parsing /etc/asterisk/res_fax.conf [2012-07-20 11:37:43] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered application 'SendFAX' [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered application 'ReceiveFAX' [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered custom function 'FAXOPT' [2012-07-20 11:37:43] DEBUG[10304] logger.c: Registered dynamic logger level 'FAX' with index 17. [2012-07-20 11:37:43] VERBOSE[10304] loader.c: res_fax.so => (Generic FAX Applications) [2012-07-20 11:37:43] VERBOSE[10304] loader.c: res_timing_dahdi.so => (DAHDI Timing Interface) [2012-07-20 11:37:43] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/musiconhold.conf': [2012-07-20 11:37:43] DEBUG[10304] config.c: Parsing /etc/asterisk/musiconhold.conf [2012-07-20 11:37:43] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:43] VERBOSE[10304] res_musiconhold.c: -- Files not found in moh for moh class:default [2012-07-20 11:37:43] DEBUG[10304] res_musiconhold.c: Destroying MOH class 'default' [2012-07-20 11:37:43] WARNING[10304] res_musiconhold.c: No music on hold classes configured, disabling music on hold. [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered application 'MusicOnHold' [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered application 'WaitMusicOnHold' [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered application 'SetMusicOnHold' [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered application 'StartMusicOnHold' [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered application 'StopMusicOnHold' [2012-07-20 11:37:43] VERBOSE[10304] loader.c: res_musiconhold.so => (Music On Hold Resource) [2012-07-20 11:37:43] VERBOSE[10304] rtp_engine.c: == Registered RTP engine 'asterisk' [2012-07-20 11:37:43] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/rtp.conf': [2012-07-20 11:37:43] DEBUG[10304] config.c: Parsing /etc/asterisk/rtp.conf [2012-07-20 11:37:43] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:43] VERBOSE[10304] res_rtp_asterisk.c: == RTP Allocating from port range 10000 -> 20000 [2012-07-20 11:37:43] VERBOSE[10304] loader.c: res_rtp_asterisk.so => (Asterisk RTP Stack) [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered application 'DAHDISendKeypadFacility' [2012-07-20 11:37:43] VERBOSE[10304] pbx.c: == Registered application 'DAHDISendCallreroutingFacility' [2012-07-20 11:37:43] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/chan_dahdi.conf': [2012-07-20 11:37:43] DEBUG[10304] config.c: Parsing /etc/asterisk/chan_dahdi.conf [2012-07-20 11:37:43] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:43] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/users.conf': [2012-07-20 11:37:43] DEBUG[10304] config.c: Parsing /etc/asterisk/users.conf [2012-07-20 11:37:43] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 1, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:1' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 1, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 2, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:2' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 2, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 3, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:3' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 3, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 4, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:4' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 4, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 5, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:5' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 5, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 6, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:6' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 6, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 7, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:7' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 7, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 8, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:8' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 8, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 9, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:9' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 9, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 10, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:10' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 10, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 11, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:11' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 11, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 12, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:12' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 12, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 13, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:13' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 13, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 14, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:14' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 14, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Updated conferencing on 15, with 0 conference users [2012-07-20 11:37:43] DEBUG[10304] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:15' [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Registered channel 15, ISDN PRI signalling [2012-07-20 11:37:43] DEBUG[10304] chan_dahdi.c: Channel '1-15' configured. [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: -- Automatically generated pseudo channel [2012-07-20 11:37:43] VERBOSE[10304] chan_dahdi.c: == Starting D-Channel on span 1 [2012-07-20 11:37:43] DEBUG[10304] channel.c: Registered handler for 'DAHDI' (DAHDI Telephony Driver w/PRI) [2012-07-20 11:37:43] VERBOSE[10304] channel.c: == Registered channel type 'DAHDI' (DAHDI Telephony Driver w/PRI) [2012-07-20 11:37:43] VERBOSE[10304] manager.c: == Manager registered action DAHDITransfer [2012-07-20 11:37:43] VERBOSE[10304] manager.c: == Manager registered action DAHDIHangup [2012-07-20 11:37:43] VERBOSE[10304] manager.c: == Manager registered action DAHDIDialOffhook [2012-07-20 11:37:43] VERBOSE[10304] manager.c: == Manager registered action DAHDIDNDon [2012-07-20 11:37:43] VERBOSE[10304] manager.c: == Manager registered action DAHDIDNDoff [2012-07-20 11:37:43] VERBOSE[10304] manager.c: == Manager registered action DAHDIShowChannels [2012-07-20 11:37:43] VERBOSE[10304] manager.c: == Manager registered action DAHDIRestart [2012-07-20 11:37:43] VERBOSE[10304] manager.c: == Manager registered action PRIShowSpans [2012-07-20 11:37:43] VERBOSE[10304] loader.c: chan_dahdi.so => (DAHDI Telephony Driver w/PRI) [2012-07-20 11:37:43] VERBOSE[10316] sig_pri.c: == Primary D-Channel on span 1 up [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/iax.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/iax.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/config/config.iax': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/config/config.iax [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/users.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/users.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] VERBOSE[10304] chan_iax2.c: == Binding IAX2 to default address 0.0.0.0:4569 [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'IAX2Provision' [2012-07-20 11:37:44] DEBUG[10304] xmldoc.c: Cannot find variable 'description' in tree 'IAXPEER' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'IAXPEER' [2012-07-20 11:37:44] DEBUG[10304] xmldoc.c: Cannot find variable 'description' in tree 'IAXVAR' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'IAXVAR' [2012-07-20 11:37:44] VERBOSE[10304] manager.c: == Manager registered action IAXpeers [2012-07-20 11:37:44] VERBOSE[10304] manager.c: == Manager registered action IAXpeerlist [2012-07-20 11:37:44] VERBOSE[10304] manager.c: == Manager registered action IAXnetstats [2012-07-20 11:37:44] VERBOSE[10304] manager.c: == Manager registered action IAXregistry [2012-07-20 11:37:44] DEBUG[10304] channel.c: Registered handler for 'IAX2' (Inter Asterisk eXchange Driver (Ver 2)) [2012-07-20 11:37:44] VERBOSE[10304] channel.c: == Registered channel type 'IAX2' (Inter Asterisk eXchange Driver (Ver 2)) [2012-07-20 11:37:44] VERBOSE[10304] chan_iax2.c: == 10 helper threads started [2012-07-20 11:37:44] VERBOSE[10304] chan_iax2.c: == IAX Ready and Listening [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/iaxprov.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/iaxprov.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] VERBOSE[10304] iax2-provision.c: -- Loaded provisioning template 'default' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: chan_iax2.so => (Inter Asterisk eXchange (Ver 2)) [2012-07-20 11:37:44] VERBOSE[10304] chan_sip.c: SIP channel loading... [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/sip.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/sip.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/config/config.sip': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/config/config.sip [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/users.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/users.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Setting TCP socket address to 0.0.0.0:0 [2012-07-20 11:37:44] VERBOSE[10304] chan_sip.c: == SIP Listening on 10.252.0.254:5060 [2012-07-20 11:37:44] VERBOSE[10304] netsock2.c: == Using SIP CoS mark 4 [2012-07-20 11:37:44] DEBUG[10304] tcptls.c: Nothing changed in SIP TCP server [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: SIP TCP server started [2012-07-20 11:37:44] DEBUG[10304] acl.c: 0.0.0.0:0/0.0.0.0:0 sense 0 appended to acl for peer [2012-07-20 11:37:44] DEBUG[10304] acl.c: 193.227.252.70:0/255.255.255.255:0 sense 1 appended to acl for peer [2012-07-20 11:37:44] NOTICE[10304] chan_sip.c: The 'username' field for sip peers has been deprecated in favor of the term 'defaultuser' [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [2012-07-20 11:37:44] DEBUG[10304] acl.c: 0.0.0.0:0/0.0.0.0:0 sense 0 appended to acl for peer [2012-07-20 11:37:44] DEBUG[10304] acl.c: 10.252.0.246:0/255.255.255.255:0 sense 1 appended to acl for peer [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [2012-07-20 11:37:44] DEBUG[10304] db.c: Unable to find key 'gordeev' in family 'SIP/Registry' [2012-07-20 11:37:44] DEBUG[10304] acl.c: 0.0.0.0:0/0.0.0.0:0 sense 0 appended to acl for peer [2012-07-20 11:37:44] DEBUG[10304] acl.c: 192.168.67.43:0/255.255.255.255:0 sense 1 appended to acl for peer [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: SIP Seeding peer from astdb: 'asterisk10' at asterisk10@192.168.67.43 for 120 [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Allocating new SIP dialog for 12f07eef122a2cf814810cc30d5c649b@10.252.0.254:5060 - OPTIONS (No RTP) [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Initializing initreq for method OPTIONS - callid 241ef2a9441f04f84ff0acb16b4a6d06@10.252.0.254:5060 [2012-07-20 11:37:44] VERBOSE[10304] chan_sip.c: Reliably Transmitting (NAT) to 192.168.67.43:5060: OPTIONS sip:asterisk10@192.168.67.43 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK462cabbf;rport Max-Forwards: 70 From: "asterisk" ;tag=as03901e78 To: Contact: Call-ID: 241ef2a9441f04f84ff0acb16b4a6d06@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 10.6.0 Date: Fri, 20 Jul 2012 07:37:44 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2012-07-20 11:37:44] DEBUG[10304] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.67.43:5060 [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/sip_notify.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/sip_notify.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] VERBOSE[10304] message.c: -- Message technology handler 'sip' registered. [2012-07-20 11:37:44] DEBUG[10304] channel.c: Registered handler for 'SIP' (Session Initiation Protocol (SIP)) [2012-07-20 11:37:44] VERBOSE[10304] channel.c: == Registered channel type 'SIP' (Session Initiation Protocol (SIP)) [2012-07-20 11:37:44] VERBOSE[10304] rtp_engine.c: == Registered RTP glue 'SIP' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'SIPDtmfMode' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'SIPAddHeader' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'SIPRemoveHeader' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'SIP_HEADER' [2012-07-20 11:37:44] DEBUG[10304] xmldoc.c: Cannot find variable 'description' in tree 'SIPPEER' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'SIPPEER' [2012-07-20 11:37:44] DEBUG[10304] xmldoc.c: Cannot find variable 'description' in tree 'SIPCHANINFO' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'SIPCHANINFO' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'CHECKSIPDOMAIN' [2012-07-20 11:37:44] VERBOSE[10304] manager.c: == Manager registered action SIPpeers [2012-07-20 11:37:44] VERBOSE[10304] manager.c: == Manager registered action SIPshowpeer [2012-07-20 11:37:44] VERBOSE[10304] manager.c: == Manager registered action SIPqualifypeer [2012-07-20 11:37:44] VERBOSE[10304] manager.c: == Manager registered action SIPshowregistry [2012-07-20 11:37:44] VERBOSE[10304] manager.c: == Manager registered action SIPnotify [2012-07-20 11:37:44] VERBOSE[10304] loader.c: chan_sip.so => (Session Initiation Protocol (SIP)) [2012-07-20 11:37:44] VERBOSE[10304] file.c: == Registered file format gsm, extension(s) gsm [2012-07-20 11:37:44] NOTICE[10331] chan_sip.c: Still have a QUALIFY dialog active, deleting [2012-07-20 11:37:44] VERBOSE[10304] loader.c: format_gsm.so => (Raw GSM data) [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Session timer stopped: -1 - 241ef2a9441f04f84ff0acb16b4a6d06@10.252.0.254:5060 [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: Really destroying SIP dialog '241ef2a9441f04f84ff0acb16b4a6d06@10.252.0.254:5060' Method: OPTIONS [2012-07-20 11:37:44] VERBOSE[10304] file.c: == Registered file format wav, extension(s) wav [2012-07-20 11:37:44] VERBOSE[10304] file.c: == Registered file format wav16, extension(s) wav16 [2012-07-20 11:37:44] VERBOSE[10304] loader.c: format_wav.so => (Microsoft WAV/WAV16 format (8kHz/16kHz Signed Linear)) [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Allocating new SIP dialog for 7d883f0315ec11e9393e9ded5aac4559@10.252.0.254:5060 - OPTIONS (No RTP) [2012-07-20 11:37:44] VERBOSE[10304] file.c: == Registered file format g726-40, extension(s) g726-40 [2012-07-20 11:37:44] VERBOSE[10304] file.c: == Registered file format g726-32, extension(s) g726-32 [2012-07-20 11:37:44] VERBOSE[10304] file.c: == Registered file format g726-24, extension(s) g726-24 [2012-07-20 11:37:44] VERBOSE[10304] file.c: == Registered file format g726-16, extension(s) g726-16 [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Initializing initreq for method OPTIONS - callid 6b9e73916eb5a13e11754fd1394c645f@10.252.0.254:5060 [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: Reliably Transmitting (NAT) to 192.168.67.43:5060: OPTIONS sip:asterisk10@192.168.67.43 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK4ae7d352;rport Max-Forwards: 70 From: "asterisk" ;tag=as046595eb To: Contact: Call-ID: 6b9e73916eb5a13e11754fd1394c645f@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 10.6.0 Date: Fri, 20 Jul 2012 07:37:44 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2012-07-20 11:37:44] VERBOSE[10304] loader.c: format_g726.so => (Raw G.726 (16/24/32/40kbps) data) [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.67.43:5060 [2012-07-20 11:37:44] VERBOSE[10304] file.c: == Registered file format g729, extension(s) g729 [2012-07-20 11:37:44] VERBOSE[10304] loader.c: format_g729.so => (Raw G.729 data) [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: <--- SIP read from UDP:192.168.67.43:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK462cabbf;rport;received=10.252.0.254 From: "asterisk" ;tag=as03901e78 To: ;tag=as1b07e435 Call-ID: 241ef2a9441f04f84ff0acb16b4a6d06@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <-------------> [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: --- (12 headers 0 lines) --- [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: That's odd... Got a response on a call we don't know about. Callid 241ef2a9441f04f84ff0acb16b4a6d06@10.252.0.254:5060 [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Invalid SIP message - rejected , no callid, len 478 [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/cdr.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/cdr.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] DEBUG[10304] cdr_csv.c: logging time in GMT [2012-07-20 11:37:44] DEBUG[10304] cdr_csv.c: logging in separate files per accountcode [2012-07-20 11:37:44] DEBUG[10304] cdr_csv.c: logging CDR field UNIQUEID [2012-07-20 11:37:44] DEBUG[10304] cdr_csv.c: logging CDR user-defined field [2012-07-20 11:37:44] VERBOSE[10304] loader.c: cdr_csv.so => (Comma Separated Values CDR Backend) [2012-07-20 11:37:44] VERBOSE[10304] loader.c: res_limit.so => (Resource limits) [2012-07-20 11:37:44] DEBUG[10304] pbx.c: Registered context 'app_dial_gosub_virtual_context'(0xb6bcb0d8) in table 0x8711da8 registrar: app_dial [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: -- Registered extension context 'app_dial_gosub_virtual_context'; registrar: app_dial [2012-07-20 11:37:44] DEBUG[10304] pbx.c: Added extension 's' priority 1 to app_dial_gosub_virtual_context (0xb6bcb0d8) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: -- Added extension 's' priority 1 to app_dial_gosub_virtual_context [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'Dial' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'RetryDial' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: app_dial.so => (Dialing Application) [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/res_snmp.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/res_snmp.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] VERBOSE[10304] res_snmp.c: Loading [Sub]Agent Module [2012-07-20 11:37:44] VERBOSE[10304] loader.c: res_snmp.so => (SNMP [Sub]Agent for Asterisk) [2012-07-20 11:37:44] VERBOSE[10332] snmp/agent.c: == Starting SubAgent [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'ChanSpy' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'ExtenSpy' [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: <--- SIP read from UDP:192.168.67.43:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK4ae7d352;rport;received=10.252.0.254 From: "asterisk" ;tag=as046595eb To: ;tag=as637c8287 Call-ID: 6b9e73916eb5a13e11754fd1394c645f@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <-------------> [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: --- (12 headers 0 lines) --- [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Stopping retransmission on '6b9e73916eb5a13e11754fd1394c645f@10.252.0.254:5060' of Request 102: Match Found [2012-07-20 11:37:44] NOTICE[10331] chan_sip.c: Peer 'asterisk10' is now Reachable. (24ms / 60000ms) [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Session timer stopped: -1 - 6b9e73916eb5a13e11754fd1394c645f@10.252.0.254:5060 [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: Really destroying SIP dialog '6b9e73916eb5a13e11754fd1394c645f@10.252.0.254:5060' Method: OPTIONS [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'DAHDIScan' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: app_chanspy.so => (Listen to the audio of an active channel) [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'ulawtolin' from format ulaw to slin, table cost, 900000, computational cost 4000 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'lintoulaw' from format slin to ulaw, table cost, 600000, computational cost 1 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'lintotestlaw' from format slin to testlaw, table cost, 600000, computational cost 1 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'testlawtolin' from format testlaw to slin, table cost, 900000, computational cost 1 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] loader.c: codec_ulaw.so => (mu-Law Coder/Decoder) [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'gsmtolin' from format gsm to slin, table cost, 900000, computational cost 4000 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'lintogsm' from format slin to gsm, table cost, 600000, computational cost 8001 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] loader.c: codec_gsm.so => (GSM Coder/Decoder) [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'g729tolin' from format g729 to slin, table cost, 900000, computational cost 4000 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'lintog729' from format slin to g729, table cost, 600000, computational cost 12001 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] loader.c: codec_g729-ast100-gcc4-glibc-pentium3.so => (g729 Coder/Decoder, based on Intel IPP) [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'g726tolin' from format g726 to slin, table cost, 900000, computational cost 8000 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'lintog726' from format slin to g726, table cost, 600000, computational cost 8001 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'g726aal2tolin' from format g726aal2 to slin, table cost, 900000, computational cost 4000 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'lintog726aal2' from format slin to g726aal2, table cost, 600000, computational cost 8000 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] loader.c: codec_g726.so => (ITU G.726-32kbps G726 Transcoder) [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'alawtolin' from format alaw to slin, table cost, 900000, computational cost 1 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] translate.c: == Registered translator 'lintoalaw' from format slin to alaw, table cost, 600000, computational cost 4001 [2012-07-20 11:37:44] DEBUG[10304] translate.c: Resetting translation matrix [2012-07-20 11:37:44] VERBOSE[10304] loader.c: codec_alaw.so => (A-law Coder/Decoder) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'BackgroundDetect' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: app_talkdetect.so => (Playback with Talk Detection) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'TrySystem' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'System' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: app_system.so => (Generic System() application) [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Allocating new SIP dialog for 3b2115856279d6cc2e51f5135f180c72@10.252.0.254:5060 - OPTIONS (No RTP) [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Initializing initreq for method OPTIONS - callid 43232bc5091a814c141f758534c8a6f6@10.252.0.254:5060 [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: Reliably Transmitting (NAT) to 10.252.0.246:5060: OPTIONS sip:10.252.0.246 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK592c2225;rport Max-Forwards: 70 From: "asterisk" ;tag=as7d8338e0 To: Contact: Call-ID: 43232bc5091a814c141f758534c8a6f6@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 10.6.0 Date: Fri, 20 Jul 2012 07:37:44 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 10.252.0.246:5060 [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Allocating new SIP dialog for 0767690f6605cfb6674788451920972d@10.252.0.254:5060 - OPTIONS (No RTP) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'SayUnixTime' [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Initializing initreq for method OPTIONS - callid 4e07ce3c1ec6f6022e6eedc95c4dfa25@10.252.0.254:5060 [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: Reliably Transmitting (NAT) to 193.227.252.70:5060: OPTIONS sip:193.227.252.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK07774512;rport Max-Forwards: 70 From: "asterisk" ;tag=as1e5750a7 To: Contact: Call-ID: 4e07ce3c1ec6f6022e6eedc95c4dfa25@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 10.6.0 Date: Fri, 20 Jul 2012 07:37:44 GMT Session-Expires: 600 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 193.227.252.70:5060 [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'DateTime' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: app_sayunixtime.so => (Say time) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'Record' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: app_record.so => (Trivial Record Application) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'Read' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: app_read.so => (Read Variable Application) [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/say.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/say.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'Playback' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: app_playback.so => (Sound File Playback Application) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'MacroExit' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'MacroIf' [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK592c2225;received=10.252.0.254;rport=5060 From: "asterisk" ;tag=as7d8338e0 To: ;tag=as3b03b696 Call-ID: 43232bc5091a814c141f758534c8a6f6@10.252.0.254:5060 CSeq: 102 OPTIONS Server: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <-------------> [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: --- (12 headers 0 lines) --- [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Stopping retransmission on '43232bc5091a814c141f758534c8a6f6@10.252.0.254:5060' of Request 102: Match Found [2012-07-20 11:37:44] NOTICE[10331] chan_sip.c: Peer 'office-gag' is now Reachable. (14ms / 1000ms) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'MacroExclusive' [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Session timer stopped: -1 - 43232bc5091a814c141f758534c8a6f6@10.252.0.254:5060 [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: Really destroying SIP dialog '43232bc5091a814c141f758534c8a6f6@10.252.0.254:5060' Method: OPTIONS [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'Macro' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: app_macro.so => (Extension Macros) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'ForkCDR' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: app_forkcdr.so => (Fork The CDR into 2 separate entities) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'MATH' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'INC' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'DEC' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: func_math.so => (Mathematical dialplan function) [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: <--- SIP read from UDP:193.227.252.70:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK07774512;rport;received=10.252.0.254 From: "asterisk" ;tag=as1e5750a7 To: ;tag=as3c692b87 Call-ID: 4e07ce3c1ec6f6022e6eedc95c4dfa25@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Contact: Accept: application/sdp Content-Length: 0 <-------------> [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: --- (12 headers 0 lines) --- [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Stopping retransmission on '4e07ce3c1ec6f6022e6eedc95c4dfa25@10.252.0.254:5060' of Request 102: Match Found [2012-07-20 11:37:44] NOTICE[10331] chan_sip.c: Peer 'office' is now Reachable. (24ms / 1000ms) [2012-07-20 11:37:44] DEBUG[10331] chan_sip.c: Session timer stopped: -1 - 4e07ce3c1ec6f6022e6eedc95c4dfa25@10.252.0.254:5060 [2012-07-20 11:37:44] VERBOSE[10331] chan_sip.c: Really destroying SIP dialog '4e07ce3c1ec6f6022e6eedc95c4dfa25@10.252.0.254:5060' Method: OPTIONS [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'ISNULL' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'SET' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'EXISTS' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'IF' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'IFTIME' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'IMPORT' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: func_logic.so => (Logical dialplan functions) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'ChannelRedirect' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: app_channelredirect.so => (Redirects a given channel to a dialplan target) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'ChanIsAvail' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: app_chanisavail.so => (Check channel availability) [2012-07-20 11:37:44] VERBOSE[10304] res_fax.c: -- Registered handler for 'Spandsp' (Spandsp FAX Driver) [2012-07-20 11:37:44] VERBOSE[10304] loader.c: res_fax_spandsp.so => (Spandsp G.711 and T.38 FAX Technologies) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'TIMEOUT' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: func_timeout.so => (Channel timeout dialplan functions) [2012-07-20 11:37:44] VERBOSE[10304] loader.c: pbx_spool.so => (Outgoing Spool Support) [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/extensions.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/extensions.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/config/extensions.config': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/config/extensions.config [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/users.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/users.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] DEBUG[10304] pbx.c: Registered context 'app_dial_gosub_virtual_context'(0xb6bd20d0) in local table 0xb6bd38b0; registrar: app_dial [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: -- Registered extension context 'app_dial_gosub_virtual_context'; registrar: app_dial [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: -- merging incls/swits/igpats from old(app_dial_gosub_virtual_context) to new(app_dial_gosub_virtual_context) context, registrar = pbx_config [2012-07-20 11:37:44] DEBUG[10304] pbx.c: Added extension 's' priority 1 to app_dial_gosub_virtual_context (0xb6bd20d0) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: -- Added extension 's' priority 1 to app_dial_gosub_virtual_context [2012-07-20 11:37:44] DEBUG[10304] pbx.c: Registered context 'parkedcalls'(0xb5808dc8) in local table 0xb6bd38b0; registrar: features [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: -- Registered extension context 'parkedcalls'; registrar: features [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: -- merging incls/swits/igpats from old(parkedcalls) to new(parkedcalls) context, registrar = pbx_config [2012-07-20 11:37:44] DEBUG[10304] pbx.c: Added extension '700' priority 1 to parkedcalls (0xb5808dc8) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: -- Added extension '700' priority 1 to parkedcalls [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: -- Time to scan old dialplan and merge leftovers back into the new: 0.000490 sec [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: -- Time to restore hints and swap in new dialplan: 0.000031 sec [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: -- Time to delete the old dialplan: 0.000020 sec [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: -- Total time merge_contexts_delete: 0.000541 sec [2012-07-20 11:37:44] VERBOSE[10304] loader.c: pbx_config.so => (Text Extension Configuration) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'GROUP_COUNT' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'GROUP_MATCH_COUNT' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'GROUP_LIST' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'GROUP' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: func_groupcount.so => (Channel group dialplan functions) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'CHANNEL' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'CHANNELS' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'MASTER_CHANNEL' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: func_channel.so => (Channel information dialplan functions) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'FIELDQTY' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'FIELDNUM' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'FILTER' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'REPLACE' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'STRREPLACE' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'LISTFILTER' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'REGEX' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'ARRAY' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'QUOTE' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'CSV_QUOTE' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'LEN' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'STRFTIME' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'STRPTIME' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'EVAL' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'KEYPADHASH' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'HASHKEYS' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'HASH' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered application 'ClearHash' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'TOUPPER' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'TOLOWER' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'SHIFT' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'POP' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'PUSH' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'UNSHIFT' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'PASSTHRU' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: func_strings.so => (String handling dialplan functions) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'RAND' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: func_rand.so => (Random number dialplan function) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'CUT' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'SORT' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: func_cut.so => (Cut out information from a string) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'CDR' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: func_cdr.so => (Call Detail Record (CDR) dialplan function) [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'CALLERPRES' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'CALLERID' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'CONNECTEDLINE' [2012-07-20 11:37:44] VERBOSE[10304] pbx.c: == Registered custom function 'REDIRECTING' [2012-07-20 11:37:44] VERBOSE[10304] loader.c: func_callerid.so => (Party ID related dialplan functions (Caller-ID, Connected-line, Redirecting)) [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/cli_permissions.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/cli_permissions.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found [2012-07-20 11:37:44] VERBOSE[10304] asterisk.c: Asterisk Ready. [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Parsing '/etc/asterisk/cli.conf': [2012-07-20 11:37:44] DEBUG[10304] config.c: Parsing /etc/asterisk/cli.conf [2012-07-20 11:37:44] VERBOSE[10304] config.c: == Found