rendered paste bodyMay 31 07:36:10] DEBUG[2270] chan_sip.c: Setting NAT on RTP to Off
[May 31 07:36:10] DEBUG[2270] chan_sip.c: Allocating new SIP dialog for 1536432007-839465162063105682@208.51.102.30 - INVITE (With RTP)
[May 31 07:36:10] DEBUG[2270] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[May 31 07:36:10] DEBUG[2270] chan_sip.c: Setting NAT on RTP to Off
[May 31 07:36:10] DEBUG[2270] chan_sip.c: T38 state changed to 0 on channel <none>
[May 31 07:36:10] DEBUG[2270] chan_sip.c: We're settling with these formats: 0x4 (ulaw)
[May 31 07:36:10] DEBUG[2270] chan_sip.c: Checking SIP call limits for device
[May 31 07:36:10] DEBUG[2270] chan_sip.c: Updating call counter for incoming call
[May 31 07:36:10] DEBUG[2270] chan_sip.c: *** Our native formats are 0x4 (ulaw)
[May 31 07:36:10] DEBUG[2270] chan_sip.c: *** Joint capabilities are 0x4 (ulaw)
[May 31 07:36:10] DEBUG[2270] chan_sip.c: *** Our capabilities are 0x8000d (g723|ulaw|alaw|h263)
[May 31 07:36:10] DEBUG[2270] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
[May 31 07:36:10] DEBUG[2270] chan_sip.c: This channel will not be able to handle video.
[May 31 07:36:10] DEBUG[2270] chan_sip.c: build_route: Contact hop: <sip:208.51.102.30:5080>
[May 31 07:36:10] DEBUG[2270] chan_sip.c: SIP/5080-09587fa8: New call is still down.... Trying...
[May 31 07:36:10] DEBUG[2270] devicestate.c: Notification of state change to be queued on device/channel SIP/5080-09587fa8
[May 31 07:36:10] DEBUG[2267] devicestate.c: No provider found, checking channel drivers for SIP - 5080
[May 31 07:36:10] DEBUG[2267] chan_sip.c: Checking device state for peer 5080
[May 31 07:36:10] DEBUG[2267] devicestate.c: Changing state for SIP/5080 - state 4 (Invalid)
[May 31 07:36:10] VERBOSE[9864] logger.c: [May 31 07:36:10] -- Executing NoOp("SIP/5080-09587fa8", "EXTEN is 18666777934")
[May 31 07:36:10] VERBOSE[9864] logger.c: [May 31 07:36:10] -- Executing NoOp("SIP/5080-09587fa8", "CHANNEL is SIP/5080-09587fa8")
[May 31 07:36:10] VERBOSE[9864] logger.c: [May 31 07:36:10] -- Executing NoOp("SIP/5080-09587fa8", "CONTEXT is inbound")
[May 31 07:36:10] VERBOSE[9864] logger.c: [May 31 07:36:10] -- Executing NoOp("SIP/5080-09587fa8", "CALLERIDNUM is ")
[May 31 07:36:10] VERBOSE[9864] logger.c: [May 31 07:36:10] -- Executing NoOp("SIP/5080-09587fa8", "CALLERID is ")
[May 31 07:36:10] VERBOSE[9864] logger.c: [May 31 07:36:10] -- Executing NoOp("SIP/5080-09587fa8", "Sending to voicemailbox '18666777934'")
[May 31 07:36:10] VERBOSE[9864] logger.c: [May 31 07:36:10] -- Executing Answer("SIP/5080-09587fa8", "")
[May 31 07:36:10] DEBUG[9864] devicestate.c: Notification of state change to be queued on device/channel SIP/5080-09587fa8
[May 31 07:36:10] DEBUG[9864] chan_sip.c: SIP answering channel: SIP/5080-09587fa8
[May 31 07:36:10] DEBUG[9864] chan_sip.c: Setting framing from config on incoming call
[May 31 07:36:10] DEBUG[9864] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: True
[May 31 07:36:10] DEBUG[9864] chan_sip.c: ** Our prefcodec: 0x0 (nothing)
[May 31 07:36:10] DEBUG[9864] chan_sip.c: -- Done with adding codecs to SDP
[May 31 07:36:10] DEBUG[9864] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[May 31 07:36:10] DEBUG[9864] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw)
[May 31 07:36:10] DEBUG[2267] devicestate.c: No provider found, checking channel drivers for SIP - 5080
[May 31 07:36:10] DEBUG[2267] chan_sip.c: Checking device state for peer 5080
[May 31 07:36:10] DEBUG[2267] devicestate.c: Changing state for SIP/5080 - state 4 (Invalid)
[May 31 07:36:10] VERBOSE[9864] logger.c: [May 31 07:36:10] -- Executing Voicemail("SIP/5080-09587fa8", "u18666777934@customer")
[May 31 07:36:10] DEBUG[9864] app_voicemail.c: Before find_user
[May 31 07:36:10] DEBUG[9864] channel.c: Set channel SIP/5080-09587fa8 to write format gsm
[May 31 07:36:10] DEBUG[9864] rtp.c: Ooh, format changed from unknown to ulaw
[May 31 07:36:10] DEBUG[9864] rtp.c: Created smoother: format: 4 ms: 20 len: 160
[May 31 07:36:10] VERBOSE[9864] logger.c: [May 31 07:36:10] -- <SIP/5080-09587fa8> Playing '/var/spool/asterisk/voicemail/customer/18666777934/unavail' (language 'en')
[May 31 07:36:10] DEBUG[2270] chan_sip.c: = Found Their Call ID: 1536432007-839465162063105682@208.51.102.30 Their Tag GR52RWG346-34 Our tag: as41ff4030
[May 31 07:36:10] DEBUG[2270] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[May 31 07:36:10] DEBUG[2270] chan_sip.c: Stopping retransmission on '1536432007-839465162063105682@208.51.102.30' of Response 1: Match Not Found
[May 31 07:36:12] DEBUG[9864] channel.c: Set channel SIP/5080-09587fa8 to write format ulaw
[May 31 07:36:12] VERBOSE[9864] logger.c: [May 31 07:36:12] -- <SIP/5080-09587fa8> Playing 'vm-intro' (language 'en')
[May 31 07:36:18] VERBOSE[9864] logger.c: [May 31 07:36:18] -- <SIP/5080-09587fa8> Playing 'beep' (language 'en')
[May 31 07:36:18] VERBOSE[9864] logger.c: [May 31 07:36:18] -- Recording the message
[May 31 07:36:18] DEBUG[9864] app.c: play_and_record: <None>, /var/spool/asterisk/voicemail/customer/18666777934/tmp/mCD0QO, 'wav49|wav'
[May 31 07:36:18] DEBUG[9864] app.c: Recording Formats: sfmts=wav49
[May 31 07:36:18] VERBOSE[9864] logger.c: [May 31 07:36:18] -- x=0, open writing: /var/spool/asterisk/voicemail/customer/18666777934/tmp/mCD0QO format: wav49, 0x9586cb8
[May 31 07:36:18] VERBOSE[9864] logger.c: [May 31 07:36:18] -- x=1, open writing: /var/spool/asterisk/voicemail/customer/18666777934/tmp/mCD0QO format: wav, 0x9584710
[May 31 07:36:18] DEBUG[9864] channel.c: Set channel SIP/5080-09587fa8 to read format slin
[May 31 07:36:20] DEBUG[9864] app.c: One waitfor failed, trying another
[May 31 07:36:22] WARNING[9864] app.c: No audio available on SIP/5080-09587fa8??
[May 31 07:36:22] VERBOSE[9864] logger.c: [May 31 07:36:22] -- User hung up
[May 31 07:36:22] DEBUG[9864] channel.c: Set channel SIP/5080-09587fa8 to read format ulaw
[May 31 07:36:22] DEBUG[9864] app.c: Locked path '/var/spool/asterisk/voicemail/customer/18666777934/INBOX'
[May 31 07:36:22] DEBUG[9864] app.c: Unlocked path '/var/spool/asterisk/voicemail/customer/18666777934/INBOX'
[May 31 07:36:22] VERBOSE[9864] logger.c: [May 31 07:36:22] == Parsing '/var/spool/asterisk/voicemail/customer/18666777934/INBOX/msg0014.txt': [May 31 07:36:22] DEBUG[9864] config.c: Parsing /var/spool/asterisk/voicemail/customer/18666777934/INBOX/msg0014.txt
[May 31 07:36:22] VERBOSE[9864] logger.c: [May 31 07:36:22] Found
[May 31 07:36:22] DEBUG[9864] app_voicemail.c: Attaching file '/var/spool/asterisk/voicemail/customer/18666777934/INBOX/msg0014', format 'WAV', uservm is '2048', global is 2048
[May 31 07:36:22] DEBUG[9864] devicestate.c: Notification of state change to be queued on device/channel **Unknown**
[May 31 07:36:22] DEBUG[9864] devicestate.c: Notification of state change to be queued on device/channel **Unknown**
[May 31 07:36:22] DEBUG[9864] devicestate.c: Notification of state change to be queued on device/channel **Unknown**
[May 31 07:36:22] DEBUG[9864] app_voicemail.c: newtmp: /var/spool/asterisk/voicemail/customer/18666777934/tmp/1DiyQA
[May 31 07:36:22] DEBUG[9864] app_voicemail.c: Sent mail to mbaker@i2telecom.com with command '/usr/sbin/sendmail -t'
[May 31 07:36:22] DEBUG[2267] devicestate.c: Checking if I can find provider for "**Unknown**" - number: (null)
[May 31 07:36:22] DEBUG[2267] devicestate.c: Checking provider Park with **Unknown**
[May 31 07:36:22] DEBUG[2267] devicestate.c: Changing state for **Unknown** - state 4 (Invalid)
[May 31 07:36:22] DEBUG[2267] devicestate.c: Checking if I can find provider for "**Unknown**" - number: (null)
[May 31 07:36:22] DEBUG[2267] devicestate.c: Checking provider Park with **Unknown**
[May 31 07:36:22] DEBUG[2267] devicestate.c: Changing state for **Unknown** - state 4 (Invalid)
[May 31 07:36:22] DEBUG[2267] devicestate.c: Checking if I can find provider for "**Unknown**" - number: (null)
[May 31 07:36:22] DEBUG[2267] devicestate.c: Checking provider Park with **Unknown**
[May 31 07:36:22] DEBUG[2267] devicestate.c: Changing state for **Unknown** - state 4 (Invalid)
[May 31 07:36:22] DEBUG[9864] pbx.c: Spawn extension (inbound,18666777934,8) exited non-zero on 'SIP/5080-09587fa8'
[May 31 07:36:22] VERBOSE[9864] logger.c: [May 31 07:36:22] == Spawn extension (inbound, 18666777934, 8) exited non-zero on 'SIP/5080-09587fa8'
[May 31 07:36:22] VERBOSE[9864] logger.c: [May 31 07:36:22] > cdr_odbc: Connected to astvmail
[May 31 07:36:22] VERBOSE[9864] logger.c: [May 31 07:36:22] > cdr_odbc: Query Successful!
[May 31 07:36:22] DEBUG[9864] channel.c: Hanging up channel 'SIP/5080-09587fa8'
[May 31 07:36:22] DEBUG[9864] chan_sip.c: Hangup call SIP/5080-09587fa8, SIP callid 1536432007-839465162063105682@208.51.102.30)
[May 31 07:36:22] DEBUG[9864] devicestate.c: Notification of state change to be queued on device/channel SIP/5080-09587fa8
[May 31 07:36:22] DEBUG[2267] devicestate.c: No provider found, checking channel drivers for SIP - 5080
[May 31 07:36:22] DEBUG[2267] chan_sip.c: Checking device state for peer 5080
[May 31 07:36:22] DEBUG[2267] devicestate.c: Changing state for SIP/5080 - state 4 (Invalid)
[May 31 07:36:22] DEBUG[2270] chan_sip.c: = Found Their Call ID: 1536432007-839465162063105682@208.51.102.30 Their Tag GR52RWG346-34 Our tag: as41ff4030
[May 31 07:36:22] DEBUG[2270] chan_sip.c: Stopping retransmission on '1536432007-839465162063105682@208.51.102.30' of Request 102: Match Not Found
[May 31 07:36:22] VERBOSE[2270] logger.c: [May 31 07:36:22] Really destroying SIP dialog '1536432007-839465162063105682@208.51.102.30' Method: ACK