Cannot retrieve voice mail

General Help
1

Recently we’ve started having a random problem getting voice mail. The message indicator lights up on the phone. When you dial *97 it tells you that you have 1 new message. When you press 1 for new messages it goes straight to the menu for deleting the call and other options. When you press 7 to delete the message and hangup the message indicator does not go off.

There is a message in /var/spool/asterisk/voicemail/default/2001 or whatever the extensions is. It’s not just 1 extension that has the problem. It randomly happens on different ext’s.

The system is running asterisk 1.6.2.16 with freepbx 2.8.1.4

The phones are Aastra 9143i’s

Any help or thoughts would be greatly appreciated

I thought the problem was a fluke because it hadn’t happened for about a week since I 1st posted but it’s back and I’m still stumped.

2

I thought the problem was a fluke because it hadn’t happened for about a week since I 1st posted but it’s back and I’m still stumped.

I am not using IMAP this is staight, vanilla voicemail.

I noticed that if you send another voicemail to that extension you can then retrieve the mystery message and the new one.

3

I see something fishy in the log but don’t know what to make of it.

[Jul 18 08:22:16] VERBOSE[18352] pbx.c: – Executing [*97@from-internal:1] Answer(“SIP/3101-00001247”, “”) in new stack
[Jul 18 08:22:16] VERBOSE[18352] pbx.c: – Executing [*97@from-internal:2] Wait(“SIP/3101-00001247”, “1”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [*97@from-internal:3] Macro(“SIP/3101-00001247”, “user-callerid,”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/3101-00001247”, “AMPUSER=3101”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/3101-00001247”, “0?report”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/3101-00001247”, “1?Set(REALCALLERIDNUM=3101)”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/3101-00001247”, “AMPUSER=3101”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/3101-00001247”, “AMPUSERCIDNAME=Intern 1 HRC”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/3101-00001247”, “0?report”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/3101-00001247”, “AMPUSERCID=3101”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:8] Set(“SIP/3101-00001247”, “CALLERID(all)=“Intern 1 HRC” <3101>”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:9] ExecIf(“SIP/3101-00001247”, “0?Set(CHANNEL(language)=)”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/3101-00001247”, “0?continue”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:11] Set(“SIP/3101-00001247”, “__TTL=64”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/3101-00001247”, “1?continue”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Goto (macro-user-callerid,s,19)
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:19] Set(“SIP/3101-00001247”, “CALLERID(number)=3101”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:20] Set(“SIP/3101-00001247”, “CALLERID(name)=Intern 1 HRC”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-user-callerid:21] NoOp(“SIP/3101-00001247”, “Using CallerID “Intern 1 HRC” <3101>”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [*97@from-internal:4] Macro(“SIP/3101-00001247”, “get-vmcontext,3101”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-get-vmcontext:1] Set(“SIP/3101-00001247”, “VMCONTEXT=default”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-get-vmcontext:2] GotoIf(“SIP/3101-00001247”, “0?200:300”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Goto (macro-get-vmcontext,s,300)
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [s@macro-get-vmcontext:300] NoOp(“SIP/3101-00001247”, “”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [*97@from-internal:5] Set(“SIP/3101-00001247”, “VMBOXEXISTSSTATUS=SUCCESS”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [*97@from-internal:6] GotoIf(“SIP/3101-00001247”, “1?mbexist”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Goto (from-internal,*97,106)
[Jul 18 08:22:17] VERBOSE[18352] pbx.c: – Executing [*97@from-internal:106] VoiceMailMain(“SIP/3101-00001247”, “3101@default”) in new stack
[Jul 18 08:22:17] VERBOSE[18352] file.c: – <SIP/3101-00001247> Playing ‘vm-password.gsm’ (language ‘en’)
[Jul 18 08:22:19] NOTICE[18352] app_voicemail.c: Mailbox: /var/spool/asterisk/voicemail/default/3101/INBOX, expected 0 but found 1 message(s) in box with max threshold of 100.
[Jul 18 08:22:19] NOTICE[18352] app_voicemail.c: Mailbox: /var/spool/asterisk/voicemail/default/3101/INBOX, expected 0 but found 1 message(s) in box with max threshold of 100.
[Jul 18 08:22:19] VERBOSE[18352] file.c: – <SIP/3101-00001247> Playing ‘vm-youhave.gsm’ (language ‘en’)
[Jul 18 08:22:20] VERBOSE[18352] file.c: – <SIP/3101-00001247> Playing ‘digits/1.gsm’ (language ‘en’)
[Jul 18 08:22:20] VERBOSE[18352] file.c: – <SIP/3101-00001247> Playing ‘vm-INBOX.gsm’ (language ‘en’)
[Jul 18 08:22:21] VERBOSE[18352] file.c: – <SIP/3101-00001247> Playing ‘vm-and.gsm’ (language ‘en’)
[Jul 18 08:22:21] VERBOSE[18352] file.c: – <SIP/3101-00001247> Playing ‘vm-first.gsm’ (language ‘en’)
[Jul 18 08:22:22] WARNING[18352] app_voicemail.c: No message attribute file?!! (/var/spool/asterisk/voicemail/default/3101/INBOX/msg0000.txt)
[Jul 18 08:22:22] VERBOSE[18352] file.c: – <SIP/3101-00001247> Playing ‘vm-advopts.gsm’ (language ‘en’)
[Jul 18 08:22:24] VERBOSE[18352] file.c: – <SIP/3101-00001247> Playing ‘vm-repeat.gsm’ (language ‘en’)
[Jul 18 08:22:24] VERBOSE[18352] file.c: – <SIP/3101-00001247> Playing ‘vm-deleted.gsm’ (language ‘en’)
[Jul 18 08:22:26] VERBOSE[18352] file.c: – <SIP/3101-00001247> Playing ‘vm-advopts.gsm’ (language ‘en’)
[Jul 18 08:22:28] VERBOSE[18352] file.c: – <SIP/3101-00001247> Playing ‘vm-repeat.gsm’ (language ‘en’)
[Jul 18 08:22:29] WARNING[18352] file.c: Failed to write frame
[Jul 18 08:22:29] VERBOSE[18352] pbx.c: == Spawn extension (from-internal, *97, 106) exited non-zero on ‘SIP/3101-00001247’
[Jul 18 08:22:29] VERBOSE[18352] pbx.c: – Executing [h@from-internal:1] Macro(“SIP/3101-00001247”, “hangupcall”) in new stack
[Jul 18 08:22:29] VERBOSE[18352] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/3101-00001247”, “1?skiprg”) in new stack
[Jul 18 08:22:29] VERBOSE[18352] pbx.c: – Goto (macro-hangupcall,s,4)
[Jul 18 08:22:29] VERBOSE[18352] pbx.c: – Executing [s@macro-hangupcall:4] GotoIf(“SIP/3101-00001247”, “1?skipblkvm”) in new stack
[Jul 18 08:22:29] VERBOSE[18352] pbx.c: – Goto (macro-hangupcall,s,7)
[Jul 18 08:22:29] VERBOSE[18352] pbx.c: – Executing [s@macro-hangupcall:7] GotoIf(“SIP/3101-00001247”, “1?theend”) in new stack
[Jul 18 08:22:29] VERBOSE[18352] pbx.c: – Goto (macro-hangupcall,s,9)
[Jul 18 08:22:29] VERBOSE[18352] pbx.c: – Executing [s@macro-hangupcall:9] Hangup(“SIP/3101-00001247”, “”) in new stack
[Jul 18 08:22:29] VERBOSE[18352] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/3101-00001247’ in macro ‘hangupcall’
[Jul 18 08:22:29] VERBOSE[18352] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/3101-00001247’