Feb 15 14:37:35 DEBUG[19350] chan_sip.c: Allocating new SIP dialog for 2af187547b91c4192a7958f443f3efb6@222.185.245.254 - INVITE (With RTP) Feb 15 14:37:35 DEBUG[19350] chan_sip.c: Setting NAT on RTP to 524288 Feb 15 14:37:35 DEBUG[19350] chan_sip.c: Checking SIP call limits for device Feb 15 14:37:35 DEBUG[19350] chan_sip.c: build_route: Contact hop: Feb 15 14:37:35 DEBUG[19698] pbx.c: Launching 'Dial' Feb 15 14:37:35 VERBOSE[19698] logger.c: -- Executing Dial("SIP/222.185.245.254-081c9810", "SIP/8888|60|HL(57000:60000:30000)") in new stack Feb 15 14:37:35 VERBOSE[19698] logger.c: -- Limit Data for this call: Feb 15 14:37:35 VERBOSE[19698] logger.c: -- - timelimit = 57000 Feb 15 14:37:35 VERBOSE[19698] logger.c: -- - play_warning = 60000 Feb 15 14:37:35 VERBOSE[19698] logger.c: -- - play_to_caller= yes Feb 15 14:37:35 VERBOSE[19698] logger.c: -- - play_to_callee= no Feb 15 14:37:35 VERBOSE[19698] logger.c: -- - warning_freq = 30000 Feb 15 14:37:35 VERBOSE[19698] logger.c: -- - start_sound = UNDEF Feb 15 14:37:35 VERBOSE[19698] logger.c: -- - warning_sound = timeleft Feb 15 14:37:35 VERBOSE[19698] logger.c: -- - end_sound = UNDEF Feb 15 14:37:35 DEBUG[19698] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Feb 15 14:37:35 DEBUG[19698] chan_sip.c: Setting NAT on RTP to 524288 Feb 15 14:37:35 DEBUG[19699] app_queue.c: Device 'SIP/222.185.245.254' changed to state '2' (In use) Feb 15 14:37:35 DEBUG[19698] channel.c: Not copying variable STACK-pbx-8863-1. Feb 15 14:37:35 DEBUG[19698] channel.c: Not copying variable SIPCALLID. Feb 15 14:37:35 DEBUG[19698] channel.c: Not copying variable SIPUSERAGENT. Feb 15 14:37:35 DEBUG[19698] channel.c: Not copying variable SIPDOMAIN. Feb 15 14:37:35 DEBUG[19698] channel.c: Not copying variable SIPURI. Feb 15 14:37:35 DEBUG[19698] chan_sip.c: Outgoing Call for 8888 Feb 15 14:37:35 VERBOSE[19698] logger.c: -- Called 8888 Feb 15 14:37:35 DEBUG[19698] channel.c: Set channel SIP/8888-2274 to read format slin Feb 15 14:37:35 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format slin Feb 15 14:37:35 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to read format slin Feb 15 14:37:35 DEBUG[19698] channel.c: Set channel SIP/8888-2274 to write format slin Feb 15 14:37:35 DEBUG[19350] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6534da1174157f9148f71c7a6f0f7ce3@61.132.91.74' Request 102: Found Feb 15 14:37:35 VERBOSE[19698] logger.c: -- SIP/8888-2274 is ringing Feb 15 14:37:35 DEBUG[19700] app_queue.c: Device 'SIP/8888' changed to state '6' (Ringing) Feb 15 14:37:37 DEBUG[19698] rtp.c: RTCP NAT: Got RTCP from other end. Now sending to address 222.188.133.5:10109 Feb 15 14:37:37 DEBUG[19698] rtp.c: Got RTCP report of 72 bytes Feb 15 14:37:37 DEBUG[19350] chan_sip.c: Acked pending invite 102 Feb 15 14:37:37 DEBUG[19350] chan_sip.c: Stopping retransmission on '6534da1174157f9148f71c7a6f0f7ce3@61.132.91.74' of Request 102: Match Found Feb 15 14:37:37 DEBUG[19350] chan_sip.c: build_route: Contact hop: Feb 15 14:37:37 VERBOSE[19698] logger.c: -- SIP/8888-2274 answered SIP/222.185.245.254-081c9810 Feb 15 14:37:37 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to read format slin Feb 15 14:37:37 DEBUG[19698] channel.c: Set channel SIP/8888-2274 to write format slin Feb 15 14:37:37 DEBUG[19698] channel.c: Set channel SIP/8888-2274 to read format slin Feb 15 14:37:37 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format slin Feb 15 14:37:37 DEBUG[19698] chan_sip.c: SIP answering channel: SIP/222.185.245.254-081c9810 Feb 15 14:37:37 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format gsm Feb 15 14:37:37 DEBUG[19698] rtp.c: Ooh, format changed from unknown to g729 Feb 15 14:37:37 DEBUG[19698] channel.c: Scheduling timer at 160 sample intervals Feb 15 14:37:37 VERBOSE[19698] logger.c: -- Playing 'vm-youhave' (language 'en') Feb 15 14:37:37 DEBUG[19701] app_queue.c: Device 'SIP/8888' changed to state '2' (In use) Feb 15 14:37:37 DEBUG[19702] app_queue.c: Device 'SIP/222.185.245.254' changed to state '2' (In use) Feb 15 14:37:37 DEBUG[19350] chan_sip.c: Stopping retransmission on '2af187547b91c4192a7958f443f3efb6@222.185.245.254' of Response 102: Match Found Feb 15 14:37:37 DEBUG[19514] rtp.c: RTP NAT: Got audio from other end. Now sending to address 222.188.133.5:10108 Feb 15 14:37:38 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:37:38 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:37:38 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format slin Feb 15 14:37:38 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format gsm Feb 15 14:37:38 DEBUG[19698] channel.c: Scheduling timer at 160 sample intervals Feb 15 14:37:38 VERBOSE[19698] logger.c: -- Playing 'digits/50' (language 'en') Feb 15 14:37:39 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:37:39 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:37:39 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format slin Feb 15 14:37:39 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format gsm Feb 15 14:37:39 DEBUG[19698] channel.c: Scheduling timer at 160 sample intervals Feb 15 14:37:39 VERBOSE[19698] logger.c: -- Playing 'digits/7' (language 'en') Feb 15 14:37:39 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:37:39 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:37:39 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format slin Feb 15 14:37:39 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format gsm Feb 15 14:37:39 DEBUG[19698] channel.c: Scheduling timer at 160 sample intervals Feb 15 14:37:39 VERBOSE[19698] logger.c: -- Playing 'queue-seconds' (language 'en') Feb 15 14:37:40 DEBUG[19514] rtp.c: RTCP NAT: Got RTCP from other end. Now sending to address 222.188.133.5:10109 Feb 15 14:37:40 DEBUG[19514] rtp.c: Got RTCP report of 28 bytes Feb 15 14:37:40 DEBUG[19514] rtp.c: Got RTCP report of 72 bytes Feb 15 14:37:40 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:37:40 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:37:40 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format slin Feb 15 14:37:40 DEBUG[19698] rtp.c: Ooh, format changed from unknown to gsm Feb 15 14:37:50 DEBUG[19698] rtp.c: Got RTCP report of 52 bytes Feb 15 14:37:50 DEBUG[19698] rtp.c: Got RTCP report of 72 bytes Feb 15 14:37:56 DEBUG[19698] rtp.c: Got RTCP report of 52 bytes Feb 15 14:37:56 DEBUG[19698] rtp.c: Got RTCP report of 72 bytes Feb 15 14:38:04 DEBUG[19698] channel.c: Nobody there, continuing... Feb 15 14:38:04 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format gsm Feb 15 14:38:04 DEBUG[19698] channel.c: Scheduling timer at 160 sample intervals Feb 15 14:38:04 VERBOSE[19698] logger.c: -- Playing 'vm-youhave' (language 'en') Feb 15 14:38:05 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:38:05 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:38:05 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format slin Feb 15 14:38:05 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format gsm Feb 15 14:38:05 DEBUG[19698] channel.c: Scheduling timer at 160 sample intervals Feb 15 14:38:05 VERBOSE[19698] logger.c: -- Playing 'digits/30' (language 'en') Feb 15 14:38:06 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:38:06 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:38:06 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format slin Feb 15 14:38:06 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format gsm Feb 15 14:38:06 DEBUG[19698] channel.c: Scheduling timer at 160 sample intervals Feb 15 14:38:06 VERBOSE[19698] logger.c: -- Playing 'queue-seconds' (language 'en') Feb 15 14:38:06 DEBUG[19514] rtp.c: Got RTCP report of 52 bytes Feb 15 14:38:06 DEBUG[19514] rtp.c: Got RTCP report of 72 bytes Feb 15 14:38:06 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:38:06 DEBUG[19698] channel.c: Scheduling timer at 0 sample intervals Feb 15 14:38:06 DEBUG[19698] channel.c: Set channel SIP/222.185.245.254-081c9810 to write format slin Feb 15 14:38:14 DEBUG[19698] rtp.c: Got RTCP report of 52 bytes Feb 15 14:38:22 DEBUG[19698] rtp.c: Got RTCP report of 52 bytes Feb 15 14:38:30 DEBUG[19698] rtp.c: Got RTCP report of 52 bytes Feb 15 14:38:34 DEBUG[19698] channel.c: Nobody there, continuing... Feb 15 14:38:38 DEBUG[19698] rtp.c: Got RTCP report of 52 bytes Feb 15 14:38:47 DEBUG[19698] rtp.c: Got RTCP report of 52 bytes Feb 15 14:38:49 VERBOSE[19335] logger.c: -- Remote UNIX connection Feb 15 14:38:56 DEBUG[19698] rtp.c: Got RTCP report of 52 bytes Feb 15 14:39:02 DEBUG[19698] rtp.c: Got RTCP report of 52 bytes Feb 15 14:39:04 DEBUG[19698] channel.c: Nobody there, continuing... Feb 15 14:39:04 DEBUG[19698] channel.c: Bridge stops bridging channels SIP/222.185.245.254-081c9810 and SIP/8888-2274 Feb 15 14:39:04 DEBUG[19698] channel.c: Hanging up channel 'SIP/8888-2274' Feb 15 14:39:04 DEBUG[19698] app_dial.c: Exiting with DIALSTATUS=ANSWER. Feb 15 14:39:04 DEBUG[19698] pbx.c: Spawn extension (pbx,8863,1) exited non-zero on 'SIP/222.185.245.254-081c9810' Feb 15 14:39:04 DEBUG[19726] app_queue.c: Device 'SIP/8888' changed to state '1' (Not in use) Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is '"8863" <8863>' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is '8863' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is '8863' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is 'pbx' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is 'SIP/222.185.245.254-081c9810' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is 'SIP/8888-2274' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is 'Dial' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is 'SIP/8888|60|HL(57000:60000:30000)' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is '2006-02-15 14:37:35' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is '2006-02-15 14:37:37' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is '2006-02-15 14:39:04' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is '89' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is '87' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is 'ANSWERED' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is 'DOCUMENTATION' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is '' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is '1139985455.20' Feb 15 14:39:04 DEBUG[19698] pbx.c: Function result is '' Feb 15 14:39:04 DEBUG[19698] channel.c: Hanging up channel 'SIP/222.185.245.254-081c9810' Feb 15 14:39:04 DEBUG[19727] app_queue.c: Device 'SIP/222.185.245.254' changed to state '1' (Not in use) Feb 15 14:39:04 DEBUG[19350] chan_sip.c: Stopping retransmission on '2af187547b91c4192a7958f443f3efb6@222.185.245.254' of Request 102: Match Found Feb 15 14:39:04 DEBUG[19350] chan_sip.c: Stopping retransmission on '6534da1174157f9148f71c7a6f0f7ce3@61.132.91.74' of Request 103: Match Found