*CLI> Nov  6 03:00:21 DEBUG[6922]: chan_sip.c:3082 sip_alloc: Allocating new SIP dialog for 8da90746-28186de0-e9d627b1@198.151.161.137 - INVITE (With RTP)
Nov  6 03:00:21 DEBUG[6922]: chan_sip.c:1005 parse_sip_options: * SIP extension value: 2 for call 8da90746-28186de0-e9d627b1@198.151.161.137
Nov  6 03:00:21 DEBUG[6922]: chan_sip.c:6990 check_user_full: Setting NAT on RTP to 0
Nov  6 03:00:21 DEBUG[6922]: chan_sip.c:1370 __sip_ack: Stopping retransmission on '8da90746-28186de0-e9d627b1@198.151.161.137' of Response 1: Match Found
Nov  6 03:00:21 DEBUG[6922]: chan_sip.c:6990 check_user_full: Setting NAT on RTP to 0
Nov  6 03:00:21 DEBUG[6922]: chan_sip.c:10298 handle_request_invite: Checking SIP call limits for device 2000
Nov  6 03:00:21 DEBUG[6922]: chan_sip.c:6005 build_route: build_route: Contact hop: <sip:2000@198.151.161.137>
Nov  6 03:00:21 DEBUG[6955]: app_queue.c:443 changethread: Device 'SIP/2000' changed to state '2' (In use)
Nov  6 03:00:21 DEBUG[6954]: pbx.c:1682 pbx_extension_helper: Launching 'Answer'
    -- Executing Answer("SIP/2000-5f72", "") in new stack
Nov  6 03:00:21 DEBUG[6954]: chan_sip.c:2486 sip_answer: sip_answer(SIP/2000-5f72)
Nov  6 03:00:21 DEBUG[6916]: channel.c:769 channel_find_locked: Avoiding initial deadlock for 'SIP/2000-5f72'
Nov  6 03:00:21 DEBUG[6954]: pbx.c:1682 pbx_extension_helper: Launching 'AGI'
    -- Executing AGI("SIP/2000-5f72", "agi-test.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-test.agi
Nov  6 03:00:21 DEBUG[6957]: app_queue.c:443 changethread: Device 'SIP/2000' changed to state '2' (In use)
AGI Environment Dump:
 -- accountcode = 
 -- callerid = 2000
 -- calleridname = 2000
 -- callingani2 = 0
 -- callingpres = 0
 -- callingtns = 0
 -- callington = 0
 -- channel = SIP/2000-5f72
 -- context = internal
 -- dnid = 622
 -- enhanced = 0.0
 -- extension = 622
 -- language = en
 -- priority = 2
 -- rdnis = unknown
 -- request = agi-test.agi
 -- type = SIP
 -- uniqueid = 1131274821.4
1.  Testing 'sendfile'...Nov  6 03:00:21 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:21 DEBUG[6954]: rtp.c:1339 ast_rtp_write: Ooh, format changed from unknown to ulaw
Nov  6 03:00:21 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
Nov  6 03:00:21 DEBUG[6922]: chan_sip.c:1370 __sip_ack: Stopping retransmission on '8da90746-28186de0-e9d627b1@198.151.161.137' of Response 2: Match Found
Nov  6 03:00:22 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:22 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:22 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
PASS (0)
2.  Testing 'sendtext'...PASS (0)
3.  Testing 'sendimage'...PASS (0)
4.  Testing 'saynumber'...Nov  6 03:00:22 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:22 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/1' (language 'en')
Nov  6 03:00:22 DEBUG[6922]: chan_sip.c:1370 __sip_ack: Stopping retransmission on '8da90746-28186de0-e9d627b1@198.151.161.137' of Request 102: Match Found
Nov  6 03:00:22 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:22 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:22 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:22 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:22 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/hundred' (language 'en')
Nov  6 03:00:23 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:23 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:23 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:23 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:23 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/90' (language 'en')
Nov  6 03:00:24 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:24 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:24 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:24 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:24 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/2' (language 'en')
Nov  6 03:00:24 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:24 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:24 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:24 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:24 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/million' (language 'en')
Nov  6 03:00:25 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:25 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:25 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:25 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:25 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/8' (language 'en')
Nov  6 03:00:26 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:26 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:26 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:26 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:26 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/hundred' (language 'en')
Nov  6 03:00:26 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:26 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:26 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:26 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:26 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/30' (language 'en')
Nov  6 03:00:27 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:27 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:27 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:27 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:27 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/7' (language 'en')
Nov  6 03:00:27 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:27 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:27 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:27 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:27 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/thousand' (language 'en')
Nov  6 03:00:28 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:28 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:28 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:28 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:28 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/4' (language 'en')
Nov  6 03:00:29 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:29 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:29 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:29 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:29 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/hundred' (language 'en')
Nov  6 03:00:29 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:29 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:29 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:29 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:29 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/60' (language 'en')
Nov  6 03:00:30 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:30 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:30 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:30 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:30 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/5' (language 'en')
Nov  6 03:00:31 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:31 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:31 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
PASS (0)
5.  Testing 'waitdtmf'...Nov  6 03:00:31 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:31 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/1' (language 'en')
Nov  6 03:00:31 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:31 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:31 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:31 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:31 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/hundred' (language 'en')
Nov  6 03:00:32 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:32 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:32 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:32 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:32 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/90' (language 'en')
Nov  6 03:00:33 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:33 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:33 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:33 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:33 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/2' (language 'en')
Nov  6 03:00:33 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:33 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:33 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:33 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:33 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/million' (language 'en')
Nov  6 03:00:34 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:34 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:34 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:34 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:34 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/8' (language 'en')
Nov  6 03:00:35 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:35 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:35 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:35 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:35 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/hundred' (language 'en')
Nov  6 03:00:35 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:35 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:35 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:35 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:35 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/30' (language 'en')
Nov  6 03:00:36 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:36 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:36 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:36 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:36 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/7' (language 'en')
Nov  6 03:00:37 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:37 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:37 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:37 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:37 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/thousand' (language 'en')
Nov  6 03:00:37 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:37 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:37 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:37 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:37 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/4' (language 'en')
Nov  6 03:00:38 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:38 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:38 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:38 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:38 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/hundred' (language 'en')
Nov  6 03:00:39 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:39 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:39 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:39 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:39 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/60' (language 'en')
Nov  6 03:00:39 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:39 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:39 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
Nov  6 03:00:39 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format gsm
Nov  6 03:00:39 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
    -- Playing 'digits/5' (language 'en')
Nov  6 03:00:40 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:40 DEBUG[6954]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov  6 03:00:40 DEBUG[6954]: channel.c:2330 set_format: Set channel SIP/2000-5f72 to write format ulaw
PASS (0)
6.  Testing 'record'...PASS (1)
6a.  Testing 'record' playback...