[2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> INVITE sip:084955452339@10.252.0.254 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK78503d02;rport Max-Forwards: 70 From: "3412539370" ;tag=as1f80b60f To: Contact: Call-ID: 01b13f106b1921ac5cf8041c6a86e248@10.252.0.246:5060 CSeq: 102 INVITE User-Agent: Cisco-SIPGateway/IOS-12.x Date: Thu, 19 Jul 2012 07:20:47 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 484014511 484014511 IN IP4 10.252.0.246 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.246 t=0 0 m=audio 21508 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-19 11:20:47] VERBOSE[6496] chan_sip.c: --- (16 headers 12 lines) --- [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Allocating new SIP dialog for 01b13f106b1921ac5cf8041c6a86e248@10.252.0.246:5060 - INVITE (No RTP) [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Sending to 10.252.0.246:5060 (NAT) [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Initializing initreq for method INVITE - callid 01b13f106b1921ac5cf8041c6a86e248@10.252.0.246:5060 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Using INVITE request as basis request - 01b13f106b1921ac5cf8041c6a86e248@10.252.0.246:5060 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Found peer 'office-gag' for '3412539370' from 10.252.0.246:5060 [2012-07-19 11:20:47] VERBOSE[6496] 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=z9hG4bK78503d02;received=10.252.0.246;rport=5060 From: "3412539370" ;tag=as1f80b60f To: ;tag=as34e78594 Call-ID: 01b13f106b1921ac5cf8041c6a86e248@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="373cc07e" Content-Length: 0 <------------> [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.252.0.246:5060 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Scheduling destruction of SIP dialog '01b13f106b1921ac5cf8041c6a86e248@10.252.0.246:5060' in 6400 ms (Method: INVITE) [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> ACK sip:084955452339@10.252.0.254 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK78503d02;rport Max-Forwards: 70 From: "3412539370" ;tag=as1f80b60f To: ;tag=as34e78594 Contact: Call-ID: 01b13f106b1921ac5cf8041c6a86e248@10.252.0.246:5060 CSeq: 102 ACK User-Agent: Cisco-SIPGateway/IOS-12.x Content-Length: 0 <-------------> [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: --- (10 headers 0 lines) --- [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Stopping retransmission on '01b13f106b1921ac5cf8041c6a86e248@10.252.0.246:5060' of Response 102: Match Found [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> INVITE sip:084955452339@10.252.0.254 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK29797b88;rport Max-Forwards: 70 From: "3412539370" ;tag=as1f80b60f To: Contact: Call-ID: 01b13f106b1921ac5cf8041c6a86e248@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:084955452339@10.252.0.254", nonce="373cc07e", response="f1e8065da3a5ed5a7de0c2e53660fb6b" Date: Thu, 19 Jul 2012 07:20:47 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 484014511 484014512 IN IP4 10.252.0.246 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.246 t=0 0 m=audio 21508 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-19 11:20:47] VERBOSE[6496] chan_sip.c: --- (17 headers 12 lines) --- [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Sending to 10.252.0.246:5060 (NAT) [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Initializing initreq for method INVITE - callid 01b13f106b1921ac5cf8041c6a86e248@10.252.0.246:5060 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Using INVITE request as basis request - 01b13f106b1921ac5cf8041c6a86e248@10.252.0.246:5060 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Found peer 'office-gag' for 'office-gag' from 10.252.0.246:5060 [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xaf300048' [2012-07-19 11:20:47] DEBUG[6496] res_rtp_asterisk.c: Allocated port 14648 for RTP instance '0xaf300048' [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: RTP instance '0xaf300048' is setup and ready to go [2012-07-19 11:20:47] DEBUG[6496] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xaf300048' [2012-07-19 11:20:47] VERBOSE[6496] netsock2.c: == Using SIP RTP CoS mark 5 [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Setting NAT on RTP to On [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Found RTP audio format 18 [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Setting payload 18 based on m type on 0xafab6dd8 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Found RTP audio format 101 [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Setting payload 101 based on m type on 0xafab6dd8 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Found audio description format G729 for ID 18 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Found audio description format telephone-event for ID 101 [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Incorporating payload 18 on 0xafab6dd8 [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Incorporating payload 101 on 0xafab6dd8 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Capabilities: us - (g729), peer - audio=(g729)/video=(nothing)/text=(nothing), combined - (g729) [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [2012-07-19 11:20:47] DEBUG[6496] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xaf300048' [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Peer audio RTP is at port 10.252.0.246:21508 [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Copying payload 18 from 0xafab6dd8 to 0xaf3001f4 [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Copying payload 101 from 0xafab6dd8 to 0xaf3001f4 [2012-07-19 11:20:47] DEBUG[6496] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0xaf300048' [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: We're settling with these formats: (g729) [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Checking SIP call limits for device office [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Looking for 084955452339 in from-gagarina-to-pesochnaya (domain 10.252.0.254) [2012-07-19 11:20:47] DEBUG[6496] res_fax.c: Attached T.38 gateway to channel SIP/office-gag-0000319e. [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: build_route: Contact hop: [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: list_route: hop: [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Incoming INVITE with 'timer' option supported and "Session-Expires" header. [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Session-Expires: 600 [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Received Min-SE: 90 [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Session timer started: 135666 - 01b13f106b1921ac5cf8041c6a86e248@10.252.0.246:5060 [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: SIP/office-gag-0000319e: New call is still down.... Trying... [2012-07-19 11:20:47] VERBOSE[6496] 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=z9hG4bK29797b88;received=10.252.0.246;rport=5060 From: "3412539370" ;tag=as1f80b60f To: Call-ID: 01b13f106b1921ac5cf8041c6a86e248@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-19 11:20:47] DEBUG[6496] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.252.0.246:5060 [2012-07-19 11:20:47] DEBUG[9865] pbx.c: Function result is '"3412539370" <3412539370>' [2012-07-19 11:20:47] DEBUG[9865] pbx.c: Launching 'NoOp' [2012-07-19 11:20:47] VERBOSE[9865] pbx.c: -- Executing [084955452339@from-gagarina-to-pesochnaya:1] NoOp("SIP/office-gag-0000319e", "Call from ""3412539370" <3412539370>" to "084955452339"") in new stack [2012-07-19 11:20:47] DEBUG[9865] func_strings.c: Allowed: 0123456789 [2012-07-19 11:20:47] DEBUG[9865] pbx.c: Function result is '084955452339' [2012-07-19 11:20:47] DEBUG[9865] pbx.c: Launching 'Set' [2012-07-19 11:20:47] VERBOSE[9865] pbx.c: -- Executing [084955452339@from-gagarina-to-pesochnaya:2] Set("SIP/office-gag-0000319e", "route=084955452339") in new stack [2012-07-19 11:20:47] DEBUG[9865] pbx.c: Launching 'Dial' [2012-07-19 11:20:47] VERBOSE[9865] pbx.c: -- Executing [084955452339@from-gagarina-to-pesochnaya:3] Dial("SIP/office-gag-0000319e", "SIP/office/084955452339") in new stack [2012-07-19 11:20:47] DEBUG[9865] chan_sip.c: Asked to create a SIP channel with formats: (g729) [2012-07-19 11:20:47] DEBUG[9865] chan_sip.c: Allocating new SIP dialog for 02a350f514629d945e71bf986c142163@10.252.0.254:5060 - INVITE (No RTP) [2012-07-19 11:20:47] DEBUG[9865] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xa11eb50' [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: Allocated port 16694 for RTP instance '0xa11eb50' [2012-07-19 11:20:47] DEBUG[9865] rtp_engine.c: RTP instance '0xa11eb50' is setup and ready to go [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xa11eb50' [2012-07-19 11:20:47] VERBOSE[9865] netsock2.c: == Using SIP RTP CoS mark 5 [2012-07-19 11:20:47] DEBUG[9865] chan_sip.c: Setting NAT on RTP to On [2012-07-19 11:20:47] DEBUG[9865] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2012-07-19 11:20:47] DEBUG[9865] res_fax.c: Attached T.38 gateway to channel SIP/office-0000319f. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable DIALEDTIME. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable ANSWEREDTIME. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable DIALEDPEERNAME. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable DIALEDPEERNUMBER. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable DIALSTATUS. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable route. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable FAXPAGES. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable FAXSTATUSSTRING. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable FAXERROR. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable FAXSTATUS. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable SIPCALLID. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable SIPDOMAIN. [2012-07-19 11:20:47] DEBUG[9865] channel.c: Not copying variable SIPURI. [2012-07-19 11:20:47] DEBUG[9865] chan_sip.c: Outgoing Call for 084955452339 [2012-07-19 11:20:47] DEBUG[9865] chan_sip.c: ** Our capability: (alaw) Video flag: False Text flag: False [2012-07-19 11:20:47] DEBUG[9865] chan_sip.c: ** Our prefcodec: (g729) [2012-07-19 11:20:47] VERBOSE[9865] chan_sip.c: Audio is at 16694 [2012-07-19 11:20:47] VERBOSE[9865] chan_sip.c: Adding codec 100004 (alaw) to SDP [2012-07-19 11:20:47] VERBOSE[9865] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2012-07-19 11:20:47] DEBUG[9865] chan_sip.c: Initializing initreq for method INVITE - callid 5675ed2b4b2da9ec5a2fc4cc32b3027a@10.252.0.254:5060 [2012-07-19 11:20:47] VERBOSE[9865] chan_sip.c: Reliably Transmitting (NAT) to 88.80.52.70:5060: INVITE sip:084955452339@88.80.52.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK6f108794;rport Max-Forwards: 70 From: "3412539370" ;tag=as6aa9006f To: Contact: Call-ID: 5675ed2b4b2da9ec5a2fc4cc32b3027a@10.252.0.254:5060 CSeq: 102 INVITE User-Agent: Asterisk PBX 10.6.0 Date: Thu, 19 Jul 2012 07:20:47 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 1990431767 1990431767 IN IP4 10.252.0.254 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.254 t=0 0 m=audio 16694 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-19 11:20:47] DEBUG[9865] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 88.80.52.70:5060 [2012-07-19 11:20:47] VERBOSE[9865] app_dial.c: -- Called SIP/office/084955452339 [2012-07-19 11:20:47] DEBUG[9865] channel.c: Set channel SIP/office-0000319f to read format slin [2012-07-19 11:20:47] DEBUG[9865] channel.c: Set channel SIP/office-gag-0000319e to write format slin [2012-07-19 11:20:47] DEBUG[9865] channel.c: Set channel SIP/office-gag-0000319e to read format slin [2012-07-19 11:20:47] DEBUG[9865] channel.c: Set channel SIP/office-0000319f to write format slin [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:88.80.52.70:5060 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK6f108794;rport;received=10.252.0.254 From: "3412539370" ;tag=as6aa9006f To: ;tag=as665dd7d8 Call-ID: 5675ed2b4b2da9ec5a2fc4cc32b3027a@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="6797d7b1" Content-Length: 0 <-------------> [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: --- (11 headers 0 lines) --- [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Acked pending invite 102 [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Stopping retransmission on '5675ed2b4b2da9ec5a2fc4cc32b3027a@10.252.0.254:5060' of Request 102: Match Found [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Transmitting (NAT) to 88.80.52.70:5060: ACK sip:084955452339@88.80.52.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK6f108794;rport Max-Forwards: 70 From: "3412539370" ;tag=as6aa9006f To: ;tag=as665dd7d8 Contact: Call-ID: 5675ed2b4b2da9ec5a2fc4cc32b3027a@10.252.0.254:5060 CSeq: 102 ACK User-Agent: Asterisk PBX 10.6.0 Content-Length: 0 --- [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Trying to put 'ACK sip:084' onto UDP socket destined for 88.80.52.70:5060 [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Auth attempt 1 on INVITE [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: ** Our capability: (alaw) Video flag: False Text flag: False [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: ** Our prefcodec: (g729) [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Audio is at 16694 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Adding codec 100004 (alaw) to SDP [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Reliably Transmitting (NAT) to 88.80.52.70:5060: INVITE sip:084955452339@88.80.52.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK48c37e7a;rport Max-Forwards: 70 From: "3412539370" ;tag=as6aa9006f To: Contact: Call-ID: 5675ed2b4b2da9ec5a2fc4cc32b3027a@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:084955452339@88.80.52.70", nonce="6797d7b1", response="a3891516ceb0d4444be65067161612df" Date: Thu, 19 Jul 2012 07:20:47 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 1990431767 1990431768 IN IP4 10.252.0.254 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.254 t=0 0 m=audio 16694 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-19 11:20:47] DEBUG[6496] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 88.80.52.70:5060 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:88.80.52.70:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK48c37e7a;rport;received=10.252.0.254 From: "3412539370" ;tag=as6aa9006f To: Call-ID: 5675ed2b4b2da9ec5a2fc4cc32b3027a@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-19 11:20:47] VERBOSE[6496] chan_sip.c: --- (11 headers 0 lines) --- [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5675ed2b4b2da9ec5a2fc4cc32b3027a@10.252.0.254:5060' Request 103: Found [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:88.80.52.70:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK48c37e7a;rport;received=10.252.0.254 From: "3412539370" ;tag=as6aa9006f To: ;tag=as5ea41777 Call-ID: 5675ed2b4b2da9ec5a2fc4cc32b3027a@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 88.80.52.70 s=session c=IN IP4 88.80.52.70 t=0 0 m=audio 16252 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-19 11:20:47] VERBOSE[6496] chan_sip.c: --- (12 headers 11 lines) --- [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '5675ed2b4b2da9ec5a2fc4cc32b3027a@10.252.0.254:5060' Request 103: Found [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: build_route: Contact hop: [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: list_route: hop: [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Found RTP audio format 8 [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Setting payload 8 based on m type on 0xafab6ee8 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Found RTP audio format 101 [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Setting payload 101 based on m type on 0xafab6ee8 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Found audio description format PCMA for ID 8 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Found audio description format telephone-event for ID 101 [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Incorporating payload 8 on 0xafab6ee8 [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Incorporating payload 101 on 0xafab6ee8 [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Capabilities: us - (alaw), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw) [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [2012-07-19 11:20:47] DEBUG[6496] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xa11eb50' [2012-07-19 11:20:47] VERBOSE[6496] chan_sip.c: Peer audio RTP is at port 88.80.52.70:16252 [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Copying payload 8 from 0xafab6ee8 to 0xa11ecfc [2012-07-19 11:20:47] DEBUG[6496] rtp_engine.c: Copying payload 101 from 0xafab6ee8 to 0xa11ecfc [2012-07-19 11:20:47] DEBUG[6496] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0xa11eb50' [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: We're settling with these formats: (alaw) [2012-07-19 11:20:47] DEBUG[6496] chan_sip.c: Setting native formats after processing SDP. peer joint formats (alaw), old nativeformats (alaw) [2012-07-19 11:20:47] VERBOSE[9865] app_dial.c: -- SIP/office-0000319f is making progress passing it to SIP/office-gag-0000319e [2012-07-19 11:20:47] DEBUG[9865] chan_sip.c: Setting framing from config on incoming call [2012-07-19 11:20:47] DEBUG[9865] chan_sip.c: ** Our capability: (g729) Video flag: True Text flag: True [2012-07-19 11:20:47] DEBUG[9865] chan_sip.c: ** Our prefcodec: (nothing) [2012-07-19 11:20:47] VERBOSE[9865] chan_sip.c: Audio is at 14648 [2012-07-19 11:20:47] VERBOSE[9865] chan_sip.c: Adding codec 100008 (g729) to SDP [2012-07-19 11:20:47] VERBOSE[9865] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2012-07-19 11:20:47] VERBOSE[9865] 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=z9hG4bK29797b88;received=10.252.0.246;rport=5060 From: "3412539370" ;tag=as1f80b60f To: ;tag=as26bc52ec Call-ID: 01b13f106b1921ac5cf8041c6a86e248@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: 258 v=0 o=root 1563790189 1563790189 IN IP4 10.252.0.254 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.254 t=0 0 m=audio 14648 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-19 11:20:47] DEBUG[9865] chan_sip.c: Trying to put 'SIP/2.0 183' onto UDP socket destined for 10.252.0.246:5060 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- start learning mode pass with addr = 88.80.52.70:16252 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- probation = 4, seq = 31306 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- Condition for learning hasn't exited, so reject the frame. [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xaf79eee8 -- start learning mode pass with addr = 10.252.0.246:21508 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xaf79eee8 -- probation = 4, seq = 4384 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xaf79eee8 -- Condition for learning hasn't exited, so reject the frame. [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- start learning mode pass with addr = 88.80.52.70:16252 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- probation = 3, seq = 31307 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- Condition for learning hasn't exited, so reject the frame. [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xaf79eee8 -- start learning mode pass with addr = 10.252.0.246:21508 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xaf79eee8 -- probation = 3, seq = 4385 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xaf79eee8 -- Condition for learning hasn't exited, so reject the frame. [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- start learning mode pass with addr = 88.80.52.70:16252 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- probation = 2, seq = 31308 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- Condition for learning hasn't exited, so reject the frame. [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xaf79eee8 -- start learning mode pass with addr = 10.252.0.246:21508 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xaf79eee8 -- probation = 2, seq = 4386 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xaf79eee8 -- Condition for learning hasn't exited, so reject the frame. [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- start learning mode pass with addr = 88.80.52.70:16252 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- probation = 1, seq = 31309 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- Probation Ended. Set strict_rtp_state to STRICT_RTP_CLOSED with address 88.80.52.70:16252 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: Ooh, format changed from unknown to g729 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: Created smoother: format: g729 ms: 20 len: 20 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0xaf300048' [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xaf79eee8 -- start learning mode pass with addr = 10.252.0.246:21508 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xaf79eee8 -- probation = 1, seq = 4387 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: 0xaf79eee8 -- Probation Ended. Set strict_rtp_state to STRICT_RTP_CLOSED with address 10.252.0.246:21508 [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: Ooh, format changed from unknown to alaw [2012-07-19 11:20:47] DEBUG[9865] res_rtp_asterisk.c: Created smoother: format: alaw ms: 20 len: 160 [2012-07-19 11:20:49] VERBOSE[6496] chan_sip.c: Really destroying SIP dialog '56eb47dd2446a7bb221421d61fd949fe@10.252.0.246:5060' Method: OPTIONS [2012-07-19 11:20:52] DEBUG[9865] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-19 11:20:52] DEBUG[9865] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-19 11:20:57] DEBUG[9865] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-19 11:20:57] DEBUG[9865] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-19 11:20:59] NOTICE[6496] chan_sip.c: -- Re-registration for office@office [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: Allocating new SIP dialog for 667202b70a107da16cf20e230f87d024@10.252.0.254 - REGISTER (No RTP) [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: Scheduled a registration timeout for office id #135674 [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: >>> Re-using Auth data for office@office [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: Initializing initreq for method REGISTER - callid 667202b70a107da16cf20e230f87d024@10.252.0.254 [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: REGISTER 11 headers, 0 lines [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: Reliably Transmitting (NAT) to 88.80.52.70:5060: REGISTER sip:office SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK587cdf02;rport Max-Forwards: 70 From: ;tag=as2be391ce To: Call-ID: 667202b70a107da16cf20e230f87d024@10.252.0.254 CSeq: 3674 REGISTER User-Agent: Asterisk PBX 10.6.0 Authorization: Digest username="office", realm="asterisk", algorithm=MD5, uri="sip:office", nonce="6083a079", response="f90e39242180eb78a60c1807f390918e" Expires: 120 Contact: Content-Length: 0 --- [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: Trying to put 'REGISTER si' onto UDP socket destined for 88.80.52.70:5060 [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:88.80.52.70:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK587cdf02;rport;received=10.252.0.254 From: ;tag=as2be391ce To: Call-ID: 667202b70a107da16cf20e230f87d024@10.252.0.254 CSeq: 3674 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-19 11:20:59] VERBOSE[6496] chan_sip.c: --- (10 headers 0 lines) --- [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:88.80.52.70:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK587cdf02;rport;received=10.252.0.254 From: ;tag=as2be391ce To: ;tag=as481a2d13 Call-ID: 667202b70a107da16cf20e230f87d024@10.252.0.254 CSeq: 3674 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="70179c7a" Content-Length: 0 <-------------> [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: --- (11 headers 0 lines) --- [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: Stopping retransmission on '667202b70a107da16cf20e230f87d024@10.252.0.254' of Request 3674: Match Found [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: Responding to challenge, registration to domain/host name office [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: Initializing already initialized SIP dialog 667202b70a107da16cf20e230f87d024@10.252.0.254 (presumably reinvite) [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: REGISTER 11 headers, 0 lines [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: Reliably Transmitting (NAT) to 88.80.52.70:5060: REGISTER sip:office SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK7fecafd1;rport Max-Forwards: 70 From: ;tag=as3359609b To: Call-ID: 667202b70a107da16cf20e230f87d024@10.252.0.254 CSeq: 3675 REGISTER User-Agent: Asterisk PBX 10.6.0 Authorization: Digest username="office", realm="asterisk", algorithm=MD5, uri="sip:office", nonce="70179c7a", response="976621fdcc4354e82a9fdffb3d1cadf3" Expires: 120 Contact: Content-Length: 0 --- [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: Trying to put 'REGISTER si' onto UDP socket destined for 88.80.52.70:5060 [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:88.80.52.70:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK7fecafd1;rport;received=10.252.0.254 From: ;tag=as3359609b To: Call-ID: 667202b70a107da16cf20e230f87d024@10.252.0.254 CSeq: 3675 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-19 11:20:59] VERBOSE[6496] chan_sip.c: --- (10 headers 0 lines) --- [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:88.80.52.70:5060 ---> OPTIONS sip:office@10.252.0.254:5060 SIP/2.0 Via: SIP/2.0/UDP 88.80.52.70:5060;branch=z9hG4bK0d76ff12 From: "asterisk" ;tag=as3895c562 To: "" Contact: Call-ID: 5ac895c7647c38222c362b777ec092af@88.80.52.70 CSeq: 102 OPTIONS User-Agent: Cisco-SIPGateway/IOS-12.x Max-Forwards: 70 Date: Thu, 19 Jul 2012 07:20:59 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Content-Length: 0 <-------------> [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: --- (13 headers 0 lines) --- [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: Allocating new SIP dialog for 5ac895c7647c38222c362b777ec092af@88.80.52.70 - OPTIONS (No RTP) [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: Looking for office in default (domain 10.252.0.254) [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: <--- Transmitting (NAT) to 88.80.52.70:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 88.80.52.70:5060;branch=z9hG4bK0d76ff12;received=88.80.52.70;rport=5060 From: "asterisk" ;tag=as3895c562 To: "" ;tag=as3e8fa03e Call-ID: 5ac895c7647c38222c362b777ec092af@88.80.52.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-19 11:20:59] DEBUG[6496] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 88.80.52.70:5060 [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: Scheduling destruction of SIP dialog '5ac895c7647c38222c362b777ec092af@88.80.52.70' in 32000 ms (Method: OPTIONS) [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:88.80.52.70:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK7fecafd1;rport;received=10.252.0.254 From: ;tag=as3359609b To: ;tag=as481a2d13 Call-ID: 667202b70a107da16cf20e230f87d024@10.252.0.254 CSeq: 3675 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: Thu, 19 Jul 2012 07:20:59 GMT Content-Length: 0 <-------------> [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: --- (13 headers 0 lines) --- [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: Stopping retransmission on '667202b70a107da16cf20e230f87d024@10.252.0.254' of Request 3675: Match Found [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: Registration successful [2012-07-19 11:20:59] DEBUG[6496] chan_sip.c: Cancelling timeout 135674 [2012-07-19 11:20:59] VERBOSE[6496] chan_sip.c: Scheduling destruction of SIP dialog '667202b70a107da16cf20e230f87d024@10.252.0.254' in 6400 ms (Method: REGISTER) [2012-07-19 11:20:59] NOTICE[6496] chan_sip.c: Outbound Registration: Expiry for office is 120 sec (Scheduling reregistration in 105 s) [2012-07-19 11:21:02] VERBOSE[6496] 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=z9hG4bK62d397f1 From: ;tag=as3d74f80a To: Call-ID: 7cfc13ce1dc0de7a06ab6ab61b496758@127.0.1.1 CSeq: 118 REGISTER User-Agent: Asterisk PBX Max-Forwards: 70 Authorization: Digest username="asterisk10", realm="asterisk", algorithm=MD5, uri="sip:asterisk10", nonce="6142cdb2", response="a19b281d2621ed5f9e701fe91e2f7f7f" Expires: 120 Contact: Event: registration Content-Length: 0 <-------------> [2012-07-19 11:21:02] VERBOSE[6496] chan_sip.c: --- (13 headers 0 lines) --- [2012-07-19 11:21:02] DEBUG[6496] chan_sip.c: Allocating new SIP dialog for 7cfc13ce1dc0de7a06ab6ab61b496758@127.0.1.1 - REGISTER (No RTP) [2012-07-19 11:21:02] VERBOSE[6496] chan_sip.c: Sending to 192.168.67.43:5060 (NAT) [2012-07-19 11:21:02] VERBOSE[6496] 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=z9hG4bK62d397f1;received=192.168.67.43;rport=5060 From: ;tag=as3d74f80a To: ;tag=as2241d662 Call-ID: 7cfc13ce1dc0de7a06ab6ab61b496758@127.0.1.1 CSeq: 118 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="389cd85a" Content-Length: 0 <------------> [2012-07-19 11:21:02] DEBUG[6496] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.67.43:5060 [2012-07-19 11:21:02] VERBOSE[6496] chan_sip.c: Scheduling destruction of SIP dialog '7cfc13ce1dc0de7a06ab6ab61b496758@127.0.1.1' in 32000 ms (Method: REGISTER) [2012-07-19 11:21:02] VERBOSE[6496] 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=z9hG4bK61f2b0ef From: ;tag=as4f698332 To: Call-ID: 7cfc13ce1dc0de7a06ab6ab61b496758@127.0.1.1 CSeq: 119 REGISTER User-Agent: Asterisk PBX Max-Forwards: 70 Authorization: Digest username="asterisk10", realm="asterisk", algorithm=MD5, uri="sip:asterisk10", nonce="389cd85a", response="a10ac1ed8f27dc30f663fe7150eedfb1" Expires: 120 Contact: Event: registration Content-Length: 0 <-------------> [2012-07-19 11:21:02] VERBOSE[6496] chan_sip.c: --- (13 headers 0 lines) --- [2012-07-19 11:21:02] VERBOSE[6496] chan_sip.c: Sending to 192.168.67.43:5060 (NAT) [2012-07-19 11:21:02] DEBUG[6496] chan_sip.c: Store REGISTER's src-IP:port for call routing. [2012-07-19 11:21:02] DEBUG[6496] chan_sip.c: Allocating new SIP dialog for 30333bb611931e25432f68d208c1d6c9@10.252.0.254:5060 - OPTIONS (No RTP) [2012-07-19 11:21:02] DEBUG[6496] chan_sip.c: Initializing initreq for method OPTIONS - callid 0ce878ec0d41cd320c0df9db5477c876@10.252.0.254:5060 [2012-07-19 11:21:02] VERBOSE[6496] 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=z9hG4bK2ba515bc;rport Max-Forwards: 70 From: "asterisk" ;tag=as543e6829 To: Contact: Call-ID: 0ce878ec0d41cd320c0df9db5477c876@10.252.0.254:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 10.6.0 Date: Thu, 19 Jul 2012 07:21:02 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-19 11:21:02] DEBUG[6496] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.67.43:5060 [2012-07-19 11:21:02] VERBOSE[6496] 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=z9hG4bK61f2b0ef;received=192.168.67.43;rport=5060 From: ;tag=as4f698332 To: ;tag=as2241d662 Call-ID: 7cfc13ce1dc0de7a06ab6ab61b496758@127.0.1.1 CSeq: 119 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: Thu, 19 Jul 2012 07:21:02 GMT Content-Length: 0 <------------> [2012-07-19 11:21:02] DEBUG[6496] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.67.43:5060 [2012-07-19 11:21:02] VERBOSE[6496] chan_sip.c: Scheduling destruction of SIP dialog '7cfc13ce1dc0de7a06ab6ab61b496758@127.0.1.1' in 32000 ms (Method: REGISTER) [2012-07-19 11:21:02] VERBOSE[6496] 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=z9hG4bK2ba515bc;rport;received=10.252.0.254 From: "asterisk" ;tag=as543e6829 To: ;tag=as14de9828 Call-ID: 0ce878ec0d41cd320c0df9db5477c876@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-19 11:21:02] VERBOSE[6496] chan_sip.c: --- (12 headers 0 lines) --- [2012-07-19 11:21:02] DEBUG[6496] chan_sip.c: Stopping retransmission on '0ce878ec0d41cd320c0df9db5477c876@10.252.0.254:5060' of Request 102: Match Found [2012-07-19 11:21:02] DEBUG[6496] chan_sip.c: Session timer stopped: -1 - 0ce878ec0d41cd320c0df9db5477c876@10.252.0.254:5060 [2012-07-19 11:21:02] VERBOSE[6496] chan_sip.c: Really destroying SIP dialog '0ce878ec0d41cd320c0df9db5477c876@10.252.0.254:5060' Method: OPTIONS [2012-07-19 11:21:02] DEBUG[9865] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-19 11:21:02] DEBUG[9865] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-19 11:21:03] VERBOSE[6496] 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=z9hG4bK43daad44 From: "asterisk" ;tag=as404ca6a3 To: "" Contact: Call-ID: 70749bea2cfd10041b1f48d23c5788f6@192.168.67.43 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 19 Jul 2012 07:21:03 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces Content-Length: 0 <-------------> [2012-07-19 11:21:03] VERBOSE[6496] chan_sip.c: --- (13 headers 0 lines) --- [2012-07-19 11:21:03] DEBUG[6496] chan_sip.c: Allocating new SIP dialog for 70749bea2cfd10041b1f48d23c5788f6@192.168.67.43 - OPTIONS (No RTP) [2012-07-19 11:21:03] VERBOSE[6496] chan_sip.c: Looking for s in default (domain 10.252.0.254) [2012-07-19 11:21:03] VERBOSE[6496] 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=z9hG4bK43daad44;received=192.168.67.43;rport=5060 From: "asterisk" ;tag=as404ca6a3 To: "" ;tag=as7c872b6f Call-ID: 70749bea2cfd10041b1f48d23c5788f6@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-19 11:21:03] DEBUG[6496] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.67.43:5060 [2012-07-19 11:21:03] VERBOSE[6496] chan_sip.c: Scheduling destruction of SIP dialog '70749bea2cfd10041b1f48d23c5788f6@192.168.67.43' in 32000 ms (Method: OPTIONS) [2012-07-19 11:21:05] VERBOSE[6496] chan_sip.c: Really destroying SIP dialog '667202b70a107da16cf20e230f87d024@10.252.0.254' Method: REGISTER [2012-07-19 11:21:07] DEBUG[9865] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-19 11:21:07] DEBUG[9865] res_rtp_asterisk.c: Got RTCP report of 64 bytes [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:88.80.52.70:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK48c37e7a;rport;received=10.252.0.254 From: "3412539370" ;tag=as6aa9006f To: ;tag=as5ea41777 Call-ID: 5675ed2b4b2da9ec5a2fc4cc32b3027a@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 88.80.52.70 s=session c=IN IP4 88.80.52.70 t=0 0 m=audio 16252 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-19 11:21:08] VERBOSE[6496] chan_sip.c: --- (12 headers 11 lines) --- [2012-07-19 11:21:08] DEBUG[6496] chan_sip.c: Acked pending invite 103 [2012-07-19 11:21:08] DEBUG[6496] chan_sip.c: Stopping retransmission on '5675ed2b4b2da9ec5a2fc4cc32b3027a@10.252.0.254:5060' of Request 103: Match Found [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: Found RTP audio format 8 [2012-07-19 11:21:08] DEBUG[6496] rtp_engine.c: Setting payload 8 based on m type on 0xafab6ee8 [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: Found RTP audio format 101 [2012-07-19 11:21:08] DEBUG[6496] rtp_engine.c: Setting payload 101 based on m type on 0xafab6ee8 [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: Found audio description format PCMA for ID 8 [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: Found audio description format telephone-event for ID 101 [2012-07-19 11:21:08] DEBUG[6496] rtp_engine.c: Incorporating payload 8 on 0xafab6ee8 [2012-07-19 11:21:08] DEBUG[6496] rtp_engine.c: Incorporating payload 101 on 0xafab6ee8 [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: Capabilities: us - (alaw), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw) [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [2012-07-19 11:21:08] DEBUG[6496] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xa11eb50' [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: Peer audio RTP is at port 88.80.52.70:16252 [2012-07-19 11:21:08] DEBUG[6496] rtp_engine.c: Copying payload 8 from 0xafab6ee8 to 0xa11ecfc [2012-07-19 11:21:08] DEBUG[6496] rtp_engine.c: Copying payload 101 from 0xafab6ee8 to 0xa11ecfc [2012-07-19 11:21:08] DEBUG[6496] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0xa11eb50' [2012-07-19 11:21:08] DEBUG[6496] chan_sip.c: We're settling with these formats: (alaw) [2012-07-19 11:21:08] DEBUG[6496] chan_sip.c: Setting native formats after processing SDP. peer joint formats (alaw), old nativeformats (alaw) [2012-07-19 11:21:08] DEBUG[6496] chan_sip.c: build_route: Contact hop: [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: list_route: hop: [2012-07-19 11:21:08] DEBUG[6496] chan_sip.c: Session timer started: 135687 - 5675ed2b4b2da9ec5a2fc4cc32b3027a@10.252.0.254:5060 [2012-07-19 11:21:08] DEBUG[6496] chan_sip.c: Strict routing enforced for session 5675ed2b4b2da9ec5a2fc4cc32b3027a@10.252.0.254:5060 [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: set_destination: Parsing for address/port to send to [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: set_destination: set destination to 88.80.52.70:5060 [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: Transmitting (NAT) to 88.80.52.70:5060: ACK sip:084955452339@88.80.52.70 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.254:5060;branch=z9hG4bK41e7c96f;rport Max-Forwards: 70 From: "3412539370" ;tag=as6aa9006f To: ;tag=as5ea41777 Contact: Call-ID: 5675ed2b4b2da9ec5a2fc4cc32b3027a@10.252.0.254:5060 CSeq: 103 ACK User-Agent: Asterisk PBX 10.6.0 Content-Length: 0 --- [2012-07-19 11:21:08] DEBUG[6496] chan_sip.c: Trying to put 'ACK sip:084' onto UDP socket destined for 88.80.52.70:5060 [2012-07-19 11:21:08] VERBOSE[9865] app_dial.c: -- SIP/office-0000319f answered SIP/office-gag-0000319e [2012-07-19 11:21:08] DEBUG[9865] chan_sip.c: SIP answering channel: SIP/office-gag-0000319e [2012-07-19 11:21:08] DEBUG[9865] chan_sip.c: Setting framing from config on incoming call [2012-07-19 11:21:08] DEBUG[9865] chan_sip.c: ** Our capability: (g729) Video flag: True Text flag: True [2012-07-19 11:21:08] DEBUG[9865] chan_sip.c: ** Our prefcodec: (nothing) [2012-07-19 11:21:08] VERBOSE[9865] chan_sip.c: Audio is at 14648 [2012-07-19 11:21:08] VERBOSE[9865] chan_sip.c: Adding codec 100008 (g729) to SDP [2012-07-19 11:21:08] VERBOSE[9865] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2012-07-19 11:21:08] VERBOSE[9865] 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=z9hG4bK29797b88;received=10.252.0.246;rport=5060 From: "3412539370" ;tag=as1f80b60f To: ;tag=as26bc52ec Call-ID: 01b13f106b1921ac5cf8041c6a86e248@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: 258 v=0 o=root 1563790189 1563790190 IN IP4 10.252.0.254 s=Asterisk PBX 10.6.0 c=IN IP4 10.252.0.254 t=0 0 m=audio 14648 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-19 11:21:08] DEBUG[9865] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.252.0.246:5060 [2012-07-19 11:21:08] DEBUG[9865] features.c: Removing dialed interfaces datastore on SIP/office-0000319f since we're bridging [2012-07-19 11:21:08] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- start learning mode pass with addr = 88.80.52.70:16252 [2012-07-19 11:21:08] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- probation = 4, seq = 32349 [2012-07-19 11:21:08] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- Condition for learning hasn't exited, so reject the frame. [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: <--- SIP read from UDP:10.252.0.246:5060 ---> ACK sip:084955452339@10.252.0.254:5060 SIP/2.0 Via: SIP/2.0/UDP 10.252.0.246:5060;branch=z9hG4bK064dcc9e;rport Max-Forwards: 70 From: "3412539370" ;tag=as1f80b60f To: ;tag=as26bc52ec Contact: Call-ID: 01b13f106b1921ac5cf8041c6a86e248@10.252.0.246:5060 CSeq: 103 ACK User-Agent: Cisco-SIPGateway/IOS-12.x Content-Length: 0 <-------------> [2012-07-19 11:21:08] VERBOSE[6496] chan_sip.c: --- (10 headers 0 lines) --- [2012-07-19 11:21:08] DEBUG[6496] chan_sip.c: Stopping retransmission on '01b13f106b1921ac5cf8041c6a86e248@10.252.0.246:5060' of Response 103: Match Found [2012-07-19 11:21:08] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- start learning mode pass with addr = 88.80.52.70:16252 [2012-07-19 11:21:08] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- probation = 3, seq = 32350 [2012-07-19 11:21:08] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- Condition for learning hasn't exited, so reject the frame. [2012-07-19 11:21:08] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- start learning mode pass with addr = 88.80.52.70:16252 [2012-07-19 11:21:08] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- probation = 2, seq = 32351 [2012-07-19 11:21:08] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- Condition for learning hasn't exited, so reject the frame. [2012-07-19 11:21:08] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- start learning mode pass with addr = 88.80.52.70:16252 [2012-07-19 11:21:08] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- probation = 1, seq = 32352 [2012-07-19 11:21:08] DEBUG[9865] res_rtp_asterisk.c: 0xa011b40 -- Probation Ended. Set strict_rtp_state to STRICT_RTP_CLOSED with address 88.80.52.70:16252 [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/asterisk.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/asterisk.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action DBGet [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action DBPut [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action DBDel [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action DBDelTree [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered custom function 'MESSAGE' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered custom function 'MESSAGE_DATA' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'MessageSend' [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action DataGet [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/codecs.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/codecs.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] loader.c: Asterisk Dynamic Loader Starting: [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/modules.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/modules.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/dnsmgr.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/dnsmgr.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/http.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/http.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] WARNING[9884] http.c: Got 1 addresses [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Ping [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Events [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Logoff [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Login [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Challenge [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Hangup [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Status [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Setvar [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Getvar [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action GetConfig [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action GetConfigJSON [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action UpdateConfig [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action CreateConfig [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action ListCategories [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Redirect [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Atxfer [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Originate [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Command [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action ExtensionState [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action AbsoluteTimeout [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action MailboxStatus [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action MailboxCount [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action ListCommands [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action SendText [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action UserEvent [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action WaitEvent [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action CoreSettings [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action CoreStatus [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Reload [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action CoreShowChannels [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action ModuleLoad [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action ModuleCheck [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action AOCMessage [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Filter [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/manager.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/manager.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/users.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/users.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] DEBUG[9884] tcptls.c: Nothing changed in AMI server [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/cdr.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/cdr.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] NOTICE[9884] cdr.c: CDR simple logging enabled. [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/cel.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/cel.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] cel.c: -- CEL logging disabled. [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/dsp.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/dsp.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/udptl.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/udptl.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] udptl.c: == UDPTL allocating from port range 4000 -> 4999 [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: Asterisk PBX Core Initializing [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: Registering builtin applications: [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered custom function 'EXCEPTION' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered custom function 'TESTTIME' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [Answer] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Answer' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [BackGround] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'BackGround' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [Busy] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Busy' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [Congestion] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Congestion' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [ExecIfTime] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'ExecIfTime' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [Goto] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Goto' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [GotoIf] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'GotoIf' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [GotoIfTime] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'GotoIfTime' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [ImportVar] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'ImportVar' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [Hangup] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Hangup' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [Incomplete] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Incomplete' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [NoOp] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'NoOp' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [Proceeding] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Proceeding' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [Progress] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Progress' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [RaiseException] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'RaiseException' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [ResetCDR] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'ResetCDR' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [Ringing] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Ringing' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [SayAlpha] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'SayAlpha' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [SayDigits] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'SayDigits' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [SayNumber] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'SayNumber' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [SayPhonetic] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'SayPhonetic' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [Set] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Set' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [MSet] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'MSet' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [SetAMAFlags] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'SetAMAFlags' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [Wait] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Wait' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: [WaitExten] [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'WaitExten' [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action ShowDialPlan [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/indications.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/indications.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'at' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'au' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'bg' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'br' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'be' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'ch' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'cl' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'cn' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'cz' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'de' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'dk' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'ee' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'es' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'fi' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'fr' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'gr' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'hu' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'il' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'in' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'it' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'lt' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'jp' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'mx' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'my' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'nl' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'no' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'nz' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'ph' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'pl' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'pt' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'ru' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'se' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'sg' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'th' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'uk' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'us' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'us-old' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'tw' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 've' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Registered indication country 'za' [2012-07-19 11:21:10] VERBOSE[9884] indications.c: -- Setting default indication country to 'ru' [2012-07-19 11:21:10] DEBUG[9884] features.c: Building parking lot default [2012-07-19 11:21:10] DEBUG[9884] features.c: Configuration of default default parking lot done. [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/features.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/features.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] DEBUG[9884] features.c: Found Parking lot: default [2012-07-19 11:21:10] DEBUG[9884] features.c: Building parking lot default [2012-07-19 11:21:10] DEBUG[9884] pbx.c: Registered context 'parkedcalls'(0x8c9d538) in table 0x8ca0458 registrar: features [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: -- Registered extension context 'parkedcalls'; registrar: features [2012-07-19 11:21:10] DEBUG[9884] pbx.c: Added extension '700' priority 1 to parkedcalls (0x8c9d538) [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: -- Added extension '700' priority 1 to parkedcalls [2012-07-19 11:21:10] DEBUG[9884] features.c: Parking lot default now open for business. (parkpos 701-750) [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Bridge' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'ParkedCall' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Park' [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action ParkedCalls [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Park [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Bridge [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/enum.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/enum.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'CallCompletionRequest' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'CallCompletionCancel' [2012-07-19 11:21:10] DEBUG[9884] logger.c: Registered dynamic logger level 'CC' with index 16. [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/ccss.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/ccss.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/ccss.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/ccss.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] loader.c: Asterisk Dynamic Loader Starting: [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/modules.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/modules.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] NOTICE[9884] loader.c: 46 modules will be loaded. [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'Monitor' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'StopMonitor' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'ChangeMonitor' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'PauseMonitor' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'UnpauseMonitor' [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action Monitor [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action StopMonitor [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action ChangeMonitor [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action PauseMonitor [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action UnpauseMonitor [2012-07-19 11:21:10] VERBOSE[9884] loader.c: res_monitor.so => (Call Monitoring Resource) [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'answer' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'asyncagi break' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'channel status' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'database del' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'database deltree' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'database get' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'database put' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'exec' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'get data' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'get full variable' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'get option' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'get variable' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'hangup' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'noop' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'receive char' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'receive text' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'record file' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'say alpha' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'say digits' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'say number' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'say phonetic' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'say date' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'say time' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'say datetime' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'send image' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'send text' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'set autohangup' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'set callerid' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'set context' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'set extension' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'set music' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'set priority' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'set variable' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'stream file' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'control stream file' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'tdd mode' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'verbose' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'wait for digit' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'speech create' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'speech set' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'speech destroy' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'speech load grammar' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'speech unload grammar' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'speech activate grammar' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'speech deactivate grammar' registered [2012-07-19 11:21:10] VERBOSE[9884] res_agi.c: == AGI Command 'speech recognize' registered [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'DeadAGI' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'EAGI' [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action AGI [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'AGI' [2012-07-19 11:21:10] VERBOSE[9884] loader.c: res_agi.so => (Asterisk Gateway Interface (AGI)) [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/res_fax.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/res_fax.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'SendFAX' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'ReceiveFAX' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered custom function 'FAXOPT' [2012-07-19 11:21:10] DEBUG[9884] logger.c: Registered dynamic logger level 'FAX' with index 17. [2012-07-19 11:21:10] VERBOSE[9884] loader.c: res_fax.so => (Generic FAX Applications) [2012-07-19 11:21:10] VERBOSE[9884] loader.c: res_timing_dahdi.so => (DAHDI Timing Interface) [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/musiconhold.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/musiconhold.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] res_musiconhold.c: -- Files not found in moh for moh class:default [2012-07-19 11:21:10] DEBUG[9884] res_musiconhold.c: Destroying MOH class 'default' [2012-07-19 11:21:10] WARNING[9884] res_musiconhold.c: No music on hold classes configured, disabling music on hold. [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'MusicOnHold' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'WaitMusicOnHold' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'SetMusicOnHold' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'StartMusicOnHold' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'StopMusicOnHold' [2012-07-19 11:21:10] VERBOSE[9884] loader.c: res_musiconhold.so => (Music On Hold Resource) [2012-07-19 11:21:10] VERBOSE[9884] rtp_engine.c: == Registered RTP engine 'asterisk' [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/rtp.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/rtp.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] res_rtp_asterisk.c: == RTP Allocating from port range 10000 -> 20000 [2012-07-19 11:21:10] VERBOSE[9884] loader.c: res_rtp_asterisk.so => (Asterisk RTP Stack) [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'DAHDISendKeypadFacility' [2012-07-19 11:21:10] VERBOSE[9884] pbx.c: == Registered application 'DAHDISendCallreroutingFacility' [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/chan_dahdi.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/chan_dahdi.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/users.conf': [2012-07-19 11:21:10] DEBUG[9884] config.c: Parsing /etc/asterisk/users.conf [2012-07-19 11:21:10] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 1, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:1' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 1, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 2, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:2' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 2, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 3, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:3' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 3, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 4, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:4' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 4, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 5, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:5' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 5, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 6, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:6' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 6, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 7, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:7' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 7, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 8, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:8' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 8, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 9, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:9' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 9, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 10, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:10' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 10, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 11, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:11' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 11, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 12, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:12' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 12, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 13, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:13' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 13, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 14, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:14' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 14, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Failed to read gains: Invalid argument [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Updated conferencing on 15, with 0 conference users [2012-07-19 11:21:10] DEBUG[9884] db.c: Unable to find key 'service-state' in family 'dahdi/registry/1:15' [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Registered channel 15, ISDN PRI signalling [2012-07-19 11:21:10] DEBUG[9884] chan_dahdi.c: Channel '1-15' configured. [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: -- Automatically generated pseudo channel [2012-07-19 11:21:10] VERBOSE[9884] chan_dahdi.c: == Starting D-Channel on span 1 [2012-07-19 11:21:10] DEBUG[9884] channel.c: Registered handler for 'DAHDI' (DAHDI Telephony Driver w/PRI) [2012-07-19 11:21:10] VERBOSE[9884] channel.c: == Registered channel type 'DAHDI' (DAHDI Telephony Driver w/PRI) [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action DAHDITransfer [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action DAHDIHangup [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action DAHDIDialOffhook [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action DAHDIDNDon [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action DAHDIDNDoff [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action DAHDIShowChannels [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action DAHDIRestart [2012-07-19 11:21:10] VERBOSE[9884] manager.c: == Manager registered action PRIShowSpans [2012-07-19 11:21:10] VERBOSE[9884] loader.c: chan_dahdi.so => (DAHDI Telephony Driver w/PRI) [2012-07-19 11:21:11] VERBOSE[9896] sig_pri.c: == Primary D-Channel on span 1 up [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/iax.conf': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/iax.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/config/config.iax': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/config/config.iax [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/users.conf': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/users.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] VERBOSE[9884] chan_iax2.c: == Binding IAX2 to default address 0.0.0.0:4569 [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'IAX2Provision' [2012-07-19 11:21:12] DEBUG[9884] xmldoc.c: Cannot find variable 'description' in tree 'IAXPEER' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'IAXPEER' [2012-07-19 11:21:12] DEBUG[9884] xmldoc.c: Cannot find variable 'description' in tree 'IAXVAR' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'IAXVAR' [2012-07-19 11:21:12] VERBOSE[9884] manager.c: == Manager registered action IAXpeers [2012-07-19 11:21:12] VERBOSE[9884] manager.c: == Manager registered action IAXpeerlist [2012-07-19 11:21:12] VERBOSE[9884] manager.c: == Manager registered action IAXnetstats [2012-07-19 11:21:12] VERBOSE[9884] manager.c: == Manager registered action IAXregistry [2012-07-19 11:21:12] DEBUG[9884] channel.c: Registered handler for 'IAX2' (Inter Asterisk eXchange Driver (Ver 2)) [2012-07-19 11:21:12] VERBOSE[9884] channel.c: == Registered channel type 'IAX2' (Inter Asterisk eXchange Driver (Ver 2)) [2012-07-19 11:21:12] VERBOSE[9884] chan_iax2.c: == 10 helper threads started [2012-07-19 11:21:12] VERBOSE[9884] chan_iax2.c: == IAX Ready and Listening [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/iaxprov.conf': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/iaxprov.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] VERBOSE[9884] iax2-provision.c: -- Loaded provisioning template 'default' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: chan_iax2.so => (Inter Asterisk eXchange (Ver 2)) [2012-07-19 11:21:12] VERBOSE[9884] chan_sip.c: SIP channel loading... [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/sip.conf': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/sip.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/config/config.sip': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/config/config.sip [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/users.conf': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/users.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Setting TCP socket address to 0.0.0.0:0 [2012-07-19 11:21:12] VERBOSE[9884] chan_sip.c: == SIP Listening on 10.252.0.254:5060 [2012-07-19 11:21:12] VERBOSE[9884] netsock2.c: == Using SIP CoS mark 4 [2012-07-19 11:21:12] DEBUG[9884] tcptls.c: Nothing changed in SIP TCP server [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: SIP TCP server started [2012-07-19 11:21:12] DEBUG[9884] acl.c: 0.0.0.0:0/0.0.0.0:0 sense 0 appended to acl for peer [2012-07-19 11:21:12] DEBUG[9884] acl.c: 88.80.52.70:0/255.255.255.255:0 sense 1 appended to acl for peer [2012-07-19 11:21:12] NOTICE[9884] chan_sip.c: The 'username' field for sip peers has been deprecated in favor of the term 'defaultuser' [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [2012-07-19 11:21:12] DEBUG[9884] acl.c: 0.0.0.0:0/0.0.0.0:0 sense 0 appended to acl for peer [2012-07-19 11:21:12] DEBUG[9884] acl.c: 10.252.0.246:0/255.255.255.255:0 sense 1 appended to acl for peer [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [2012-07-19 11:21:12] DEBUG[9884] db.c: Unable to find key 'gordeev' in family 'SIP/Registry' [2012-07-19 11:21:12] DEBUG[9884] acl.c: 0.0.0.0:0/0.0.0.0:0 sense 0 appended to acl for peer [2012-07-19 11:21:12] DEBUG[9884] acl.c: 192.168.67.43:0/255.255.255.255:0 sense 1 appended to acl for peer [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: SIP Seeding peer from astdb: 'asterisk10' at asterisk10@192.168.67.43 for 120 [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Allocating new SIP dialog for 7defa4897415cc83613a20c15a5c1dc5@10.252.0.254:5060 - OPTIONS (No RTP) [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Initializing initreq for method OPTIONS - callid 7e310faa136f61656f994c2c1d7e28ff@10.252.0.254:5060 [2012-07-19 11:21:12] VERBOSE[9884] chan_sip.c: Reliably Transmitting (NAT) to 192.168.67.43:5060: [2012-07-19 11:21:12] DEBUG[9884] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.67.43:5060 [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/sip_notify.conf': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/sip_notify.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] VERBOSE[9884] message.c: -- Message technology handler 'sip' registered. [2012-07-19 11:21:12] DEBUG[9884] channel.c: Registered handler for 'SIP' (Session Initiation Protocol (SIP)) [2012-07-19 11:21:12] VERBOSE[9884] channel.c: == Registered channel type 'SIP' (Session Initiation Protocol (SIP)) [2012-07-19 11:21:12] VERBOSE[9884] rtp_engine.c: == Registered RTP glue 'SIP' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'SIPDtmfMode' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'SIPAddHeader' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'SIPRemoveHeader' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'SIP_HEADER' [2012-07-19 11:21:12] DEBUG[9884] xmldoc.c: Cannot find variable 'description' in tree 'SIPPEER' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'SIPPEER' [2012-07-19 11:21:12] DEBUG[9884] xmldoc.c: Cannot find variable 'description' in tree 'SIPCHANINFO' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'SIPCHANINFO' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'CHECKSIPDOMAIN' [2012-07-19 11:21:12] VERBOSE[9884] manager.c: == Manager registered action SIPpeers [2012-07-19 11:21:12] VERBOSE[9884] manager.c: == Manager registered action SIPshowpeer [2012-07-19 11:21:12] VERBOSE[9884] manager.c: == Manager registered action SIPqualifypeer [2012-07-19 11:21:12] VERBOSE[9884] manager.c: == Manager registered action SIPshowregistry [2012-07-19 11:21:12] VERBOSE[9884] manager.c: == Manager registered action SIPnotify [2012-07-19 11:21:12] VERBOSE[9884] loader.c: chan_sip.so => (Session Initiation Protocol (SIP)) [2012-07-19 11:21:12] VERBOSE[9884] file.c: == Registered file format gsm, extension(s) gsm [2012-07-19 11:21:12] VERBOSE[9884] loader.c: format_gsm.so => (Raw GSM data) [2012-07-19 11:21:12] VERBOSE[9884] file.c: == Registered file format wav, extension(s) wav [2012-07-19 11:21:12] VERBOSE[9884] file.c: == Registered file format wav16, extension(s) wav16 [2012-07-19 11:21:12] VERBOSE[9884] loader.c: format_wav.so => (Microsoft WAV/WAV16 format (8kHz/16kHz Signed Linear)) [2012-07-19 11:21:12] VERBOSE[9884] file.c: == Registered file format g726-40, extension(s) g726-40 [2012-07-19 11:21:12] VERBOSE[9884] file.c: == Registered file format g726-32, extension(s) g726-32 [2012-07-19 11:21:12] VERBOSE[9884] file.c: == Registered file format g726-24, extension(s) g726-24 [2012-07-19 11:21:12] VERBOSE[9884] file.c: == Registered file format g726-16, extension(s) g726-16 [2012-07-19 11:21:12] VERBOSE[9884] loader.c: format_g726.so => (Raw G.726 (16/24/32/40kbps) data) [2012-07-19 11:21:12] VERBOSE[9884] file.c: == Registered file format g729, extension(s) g729 [2012-07-19 11:21:12] VERBOSE[9884] loader.c: format_g729.so => (Raw G.729 data) [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/cdr.conf': [2012-07-19 11:21:12] VERBOSE[9911] chan_sip.c: [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/cdr.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] DEBUG[9884] cdr_csv.c: logging time in GMT [2012-07-19 11:21:12] DEBUG[9884] cdr_csv.c: logging in separate files per accountcode [2012-07-19 11:21:12] DEBUG[9884] cdr_csv.c: logging CDR field UNIQUEID [2012-07-19 11:21:12] DEBUG[9884] cdr_csv.c: logging CDR user-defined field [2012-07-19 11:21:12] VERBOSE[9884] loader.c: cdr_csv.so => (Comma Separated Values CDR Backend) [2012-07-19 11:21:12] VERBOSE[9884] loader.c: res_limit.so => (Resource limits) [2012-07-19 11:21:12] DEBUG[9884] pbx.c: Registered context 'app_dial_gosub_virtual_context'(0xf236808) in table 0x8ca0458 registrar: app_dial [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: -- Registered extension context 'app_dial_gosub_virtual_context'; registrar: app_dial [2012-07-19 11:21:12] DEBUG[9884] pbx.c: Added extension 's' priority 1 to app_dial_gosub_virtual_context (0xf236808) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: -- Added extension 's' priority 1 to app_dial_gosub_virtual_context [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'Dial' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'RetryDial' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: app_dial.so => (Dialing Application) [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/res_snmp.conf': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/res_snmp.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] VERBOSE[9884] res_snmp.c: Loading [Sub]Agent Module [2012-07-19 11:21:12] VERBOSE[9884] loader.c: res_snmp.so => (SNMP [Sub]Agent for Asterisk) [2012-07-19 11:21:12] VERBOSE[9912] snmp/agent.c: == Starting SubAgent [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'ChanSpy' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'ExtenSpy' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'DAHDIScan' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: app_chanspy.so => (Listen to the audio of an active channel) [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'ulawtolin' from format ulaw to slin, table cost, 900000, computational cost 1 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'lintoulaw' from format slin to ulaw, table cost, 600000, computational cost 1 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'lintotestlaw' from format slin to testlaw, table cost, 600000, computational cost 1 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'testlawtolin' from format testlaw to slin, table cost, 900000, computational cost 1 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] loader.c: codec_ulaw.so => (mu-Law Coder/Decoder) [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'gsmtolin' from format gsm to slin, table cost, 900000, computational cost 4000 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'lintogsm' from format slin to gsm, table cost, 600000, computational cost 8001 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] loader.c: codec_gsm.so => (GSM Coder/Decoder) [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'g729tolin' from format g729 to slin, table cost, 900000, computational cost 4000 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'lintog729' from format slin to g729, table cost, 600000, computational cost 8000 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] loader.c: codec_g729-ast100-gcc4-glibc-pentium3.so => (g729 Coder/Decoder, based on Intel IPP) [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'g726tolin' from format g726 to slin, table cost, 900000, computational cost 8000 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'lintog726' from format slin to g726, table cost, 600000, computational cost 12001 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'g726aal2tolin' from format g726aal2 to slin, table cost, 900000, computational cost 4000 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'lintog726aal2' from format slin to g726aal2, table cost, 600000, computational cost 8001 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] loader.c: codec_g726.so => (ITU G.726-32kbps G726 Transcoder) [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'alawtolin' from format alaw to slin, table cost, 900000, computational cost 1 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] translate.c: == Registered translator 'lintoalaw' from format slin to alaw, table cost, 600000, computational cost 1 [2012-07-19 11:21:12] DEBUG[9884] translate.c: Resetting translation matrix [2012-07-19 11:21:12] VERBOSE[9884] loader.c: codec_alaw.so => (A-law Coder/Decoder) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'BackgroundDetect' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: app_talkdetect.so => (Playback with Talk Detection) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'TrySystem' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'System' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: app_system.so => (Generic System() application) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'SayUnixTime' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'DateTime' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: app_sayunixtime.so => (Say time) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'Record' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: app_record.so => (Trivial Record Application) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'Read' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: app_read.so => (Read Variable Application) [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/say.conf': [2012-07-19 11:21:12] DEBUG[9911] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 10.252.0.246:5060 [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/say.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'Playback' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: app_playback.so => (Sound File Playback Application) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'MacroExit' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'MacroIf' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'MacroExclusive' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'Macro' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: app_macro.so => (Extension Macros) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'ForkCDR' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: app_forkcdr.so => (Fork The CDR into 2 separate entities) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'MATH' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'INC' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'DEC' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: func_math.so => (Mathematical dialplan function) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'ISNULL' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'SET' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'EXISTS' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'IF' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'IFTIME' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'IMPORT' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: func_logic.so => (Logical dialplan functions) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'ChannelRedirect' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: app_channelredirect.so => (Redirects a given channel to a dialplan target) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'ChanIsAvail' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: app_chanisavail.so => (Check channel availability) [2012-07-19 11:21:12] VERBOSE[9884] res_fax.c: -- Registered handler for 'Spandsp' (Spandsp FAX Driver) [2012-07-19 11:21:12] VERBOSE[9884] loader.c: res_fax_spandsp.so => (Spandsp G.711 and T.38 FAX Technologies) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'TIMEOUT' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: func_timeout.so => (Channel timeout dialplan functions) [2012-07-19 11:21:12] VERBOSE[9884] loader.c: pbx_spool.so => (Outgoing Spool Support) [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/extensions.conf': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/extensions.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/config/extensions.config': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/config/extensions.config [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/users.conf': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/users.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] DEBUG[9884] pbx.c: Registered context 'app_dial_gosub_virtual_context'(0xb5f13c58) in local table 0xb5f13b58; registrar: app_dial [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: -- Registered extension context 'app_dial_gosub_virtual_context'; registrar: app_dial [2012-07-19 11:21:12] VERBOSE[9884] 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-19 11:21:12] DEBUG[9884] pbx.c: Added extension 's' priority 1 to app_dial_gosub_virtual_context (0xb5f13c58) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: -- Added extension 's' priority 1 to app_dial_gosub_virtual_context [2012-07-19 11:21:12] DEBUG[9884] pbx.c: Registered context 'parkedcalls'(0xb5f44630) in local table 0xb5f13b58; registrar: features [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: -- Registered extension context 'parkedcalls'; registrar: features [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: -- merging incls/swits/igpats from old(parkedcalls) to new(parkedcalls) context, registrar = pbx_config [2012-07-19 11:21:12] DEBUG[9884] pbx.c: Added extension '700' priority 1 to parkedcalls (0xb5f44630) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: -- Added extension '700' priority 1 to parkedcalls [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: -- Time to scan old dialplan and merge leftovers back into the new: 0.000552 sec [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: -- Time to restore hints and swap in new dialplan: 0.000037 sec [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: -- Time to delete the old dialplan: 0.000023 sec [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: -- Total time merge_contexts_delete: 0.000612 sec [2012-07-19 11:21:12] VERBOSE[9884] loader.c: pbx_config.so => (Text Extension Configuration) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'GROUP_COUNT' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'GROUP_MATCH_COUNT' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'GROUP_LIST' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'GROUP' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: func_groupcount.so => (Channel group dialplan functions) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'CHANNEL' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'CHANNELS' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'MASTER_CHANNEL' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: func_channel.so => (Channel information dialplan functions) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'FIELDQTY' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'FIELDNUM' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'FILTER' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'REPLACE' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'STRREPLACE' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'LISTFILTER' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'REGEX' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'ARRAY' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'QUOTE' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'CSV_QUOTE' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'LEN' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'STRFTIME' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'STRPTIME' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'EVAL' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'KEYPADHASH' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'HASHKEYS' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'HASH' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered application 'ClearHash' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'TOUPPER' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'TOLOWER' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'SHIFT' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'POP' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'PUSH' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'UNSHIFT' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'PASSTHRU' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: func_strings.so => (String handling dialplan functions) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'RAND' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: func_rand.so => (Random number dialplan function) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'CUT' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'SORT' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: func_cut.so => (Cut out information from a string) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'CDR' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: func_cdr.so => (Call Detail Record (CDR) dialplan function) [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'CALLERPRES' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'CALLERID' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'CONNECTEDLINE' [2012-07-19 11:21:12] VERBOSE[9884] pbx.c: == Registered custom function 'REDIRECTING' [2012-07-19 11:21:12] VERBOSE[9884] loader.c: func_callerid.so => (Party ID related dialplan functions (Caller-ID, Connected-line, Redirecting)) [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/cli_permissions.conf': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/cli_permissions.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found [2012-07-19 11:21:12] VERBOSE[9884] asterisk.c: Asterisk Ready. [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Parsing '/etc/asterisk/cli.conf': [2012-07-19 11:21:12] DEBUG[9884] config.c: Parsing /etc/asterisk/cli.conf [2012-07-19 11:21:12] VERBOSE[9884] config.c: == Found