[asterisk-users] pulling my hair out over voicemail

Thu Jan 31 00:35:57 CST 2008

Tried it, but no change.

A few updates. Even though I dont hear anything, if I hit a keys on the 
phone and then hang up, message log says:

[Jan 30 21:26:57] WARNING[7917] app_voicemail.c: Unable to read password

I enabled logging of everything, and the below is the snippet for when 
my SIP/6001 phone dial extension 1000 for Voicemail:

[Jan 30 21:26:35] DEBUG[7917] pbx.c: Launching 'Ringing'
[Jan 30 21:26:35] VERBOSE[7917] logger.c:     -- Executing 
[1000 at default:1] Ringing("SIP/6001-081de7a8", "") in new stack
[Jan 30 21:26:35] DEBUG[7917] pbx.c: Launching 'Wait'
[Jan 30 21:26:35] VERBOSE[7917] logger.c:     -- Executing 
[1000 at default:2] Wait("SIP/6001-081de7a8", "2") in new stack
[Jan 30 21:26:37] DEBUG[7917] pbx.c: Launching 'VoiceMailMain'
[Jan 30 21:26:37] VERBOSE[7917] logger.c:     -- Executing 
[1000 at default:3] VoiceMailMain("SIP/6001-081de7a8", "1000 at default") in 
new stack
[Jan 30 21:26:37] DEBUG[7917] app_voicemail.c: Before ast_answer
[Jan 30 21:26:37] DEBUG[7917] devicestate.c: Notification of state 
change to be queued on device/channel SIP/6001-081de7a8
[Jan 30 21:26:37] DEBUG[7890] chan_sip.c: Checking device state for 
peer 6001
[Jan 30 21:26:37] DEBUG[7890] devicestate.c: Changing state for 
SIP/6001 - state 5 (Unavailable)
[Jan 30 21:26:37] DEBUG[7890] chan_sip.c: Checking device state for 
peer 6001
[Jan 30 21:26:37] DEBUG[7917] chan_sip.c: SIP answering channel: 
SIP/6001-081de7a8
[Jan 30 21:26:37] DEBUG[7917] chan_sip.c: Setting framing from config 
on incoming call
[Jan 30 21:26:37] DEBUG[7917] chan_sip.c: ** Our capability: 0x4 (ulaw) 
Video flag: True
[Jan 30 21:26:37] DEBUG[7917] chan_sip.c: ** Our prefcodec: 0x0 
(nothing)
[Jan 30 21:26:37] DEBUG[7917] chan_sip.c: -- Done with adding codecs to 
SDP
[Jan 30 21:26:37] DEBUG[7917] chan_sip.c: Done building SDP. Settling 
with this capability: 0x4 (ulaw)
[Jan 30 21:26:37] DEBUG[7917] channel.c: Set channel SIP/6001-081de7a8 
to write format gsm
[Jan 30 21:26:37] DEBUG[7917] rtp.c: Ooh, format changed from unknown 
to ulaw
[Jan 30 21:26:37] DEBUG[7917] rtp.c: Created smoother: format: 4 ms: 20 
len: 160
[Jan 30 21:26:37] VERBOSE[7917] logger.c:     -- <SIP/6001-081de7a8> 
Playing 'vm-login' (language 'en')
[Jan 30 21:26:37] DEBUG[7910] app_queue.c: Device 'SIP/6001' changed to 
state '5' (Unavailable) but we don't care because they're not a member 
of any queue.
[Jan 30 21:26:37] DEBUG[7893] chan_sip.c: Stopping retransmission on 
'3735eef706fa0b2a at 192.168.1.112' of Response 12349: Match Not Found
[Jan 30 21:26:39] DEBUG[7917] channel.c: Set channel SIP/6001-081de7a8 
to write format ulaw
[Jan 30 21:26:50] DEBUG[7917] app_voicemail.c: Before find user for 
mailbox 8563682102
[Jan 30 21:26:50] DEBUG[7917] channel.c: Set channel SIP/6001-081de7a8 
to write format gsm
[Jan 30 21:26:50] DEBUG[7917] rtp.c: Difference is 82416, ms is 10322
[Jan 30 21:26:50] VERBOSE[7917] logger.c:     -- <SIP/6001-081de7a8> 
Playing 'vm-password' (language 'en')
[Jan 30 21:26:50] DEBUG[7917] channel.c: Set channel SIP/6001-081de7a8 
to write format ulaw
[Jan 30 21:26:53] DEBUG[7893] chan_sip.c: Auto destroying SIP dialog 
'76c69e4258ca84fe7837717768a08e8c at 208.82.128.10'
[Jan 30 21:26:53] DEBUG[7893] chan_sip.c: Destroying SIP dialog 
76c69e4258ca84fe7837717768a08e8c at 208.82.128.10
[Jan 30 21:26:53] VERBOSE[7893] logger.c: Really destroying SIP dialog 
'76c69e4258ca84fe7837717768a08e8c at 208.82.128.10' Method: REGISTER
[Jan 30 21:26:55] DEBUG[7917] rtp.c: - RTP 2833 Event: 00000005 (len = 
4)
[Jan 30 21:26:55] DEBUG[7917] rtp.c: Sending dtmf: 53 (5), at 
76.161.192.192
[Jan 30 21:26:55] DTMF[7917] channel.c: DTMF begin '5' received on 
SIP/6001-081de7a8
[Jan 30 21:26:55] DTMF[7917] channel.c: DTMF begin ignored '5' on 
SIP/6001-081de7a8
[Jan 30 21:26:55] DEBUG[7917] rtp.c: - RTP 2833 Event: 00000005 (len = 
4)
[Jan 30 21:26:55] DEBUG[7917] rtp.c: - RTP 2833 Event: 00000005 (len = 
4)
[Jan 30 21:26:55] DEBUG[7917] rtp.c: - RTP 2833 Event: 00000005 (len = 
4)
[Jan 30 21:26:55] DEBUG[7917] rtp.c: - RTP 2833 Event: 00000005 (len = 
4)
[Jan 30 21:26:55] DEBUG[7917] rtp.c: - RTP 2833 Event: 00000005 (len = 
4)
[Jan 30 21:26:55] DEBUG[7917] rtp.c: - RTP 2833 Event: 00000005 (len = 
4)
[Jan 30 21:26:55] DEBUG[7917] rtp.c: - RTP 2833 Event: 00000005 (len = 
4)
[Jan 30 21:26:55] DEBUG[7917] rtp.c: - RTP 2833 Event: 00000005 (len = 
4)
[Jan 30 21:26:55] DEBUG[7917] rtp.c: Sending dtmf: 53 (5), at 
76.161.192.192
[Jan 30 21:26:55] DTMF[7917] channel.c: DTMF end '5' received on 
SIP/6001-081de7a8, duration 120 ms
[Jan 30 21:26:55] DTMF[7917] channel.c: DTMF end passthrough '5' on 
SIP/6001-081de7a8
[Jan 30 21:26:55] DEBUG[7917] rtp.c: - RTP 2833 Event: 00000005 (len = 
4)
[Jan 30 21:26:55] DEBUG[7917] rtp.c: - RTP 2833 Event: 00000005 (len = 
4)
[Jan 30 21:26:57] DEBUG[7893] chan_sip.c: Setting SIP_ALREADYGONE on 
dialog 3735eef706fa0b2a at 192.168.1.112
[Jan 30 21:26:57] DEBUG[7893] chan_sip.c: Received bye, issuing owner 
hangup
[Jan 30 21:26:57] WARNING[7917] app_voicemail.c: Unable to read password
[Jan 30 21:26:57] DEBUG[7917] app_voicemail.c: After vm_authenticate
[Jan 30 21:26:57] DEBUG[7917] pbx.c: Extension 1000, priority 3 
returned normally even though call was hung up
[Jan 30 21:26:57] DEBUG[7917] channel.c: Soft-Hanging up channel 
'SIP/6001-081de7a8'
[Jan 30 21:26:57] DEBUG[7917] channel.c: Hanging up channel 
'SIP/6001-081de7a8'
[Jan 30 21:26:57] DEBUG[7917] chan_sip.c: Hangup call 
SIP/6001-081de7a8, SIP callid 3735eef706fa0b2a at 192.168.1.112)
[Jan 30 21:26:57] DEBUG[7917] devicestate.c: Notification of state 
change to be queued on device/channel SIP/6001-081de7a8

On Jan 31, 2008, at 12:41 AM, Paul Hales wrote:

> (${EXTEN}@default)