When a user tries to transfer a voicemail to another user via “Press 8” to forward the message it never gets to the other mailbox. I checked all of the destination voicemail folders /var/spool/asterisk/voicemail/default/2001 and they were all empty.
I also checked the source extension’s voicemail folders and found the missing message in /var/spool/asterisk/voicemail/default/2000/old
I did a snapshot test to get the whole sequence in the logs
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Goto (macro-user-callerid,s,19)
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:19] Set(“SIP/2001-00000e3c”, “CALLERID(number)=2001”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:20] Set(“SIP/2001-00000e3c”, “CALLERID(name)=Rene Wright”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:21] NoOp(“SIP/2001-00000e3c”, “Using CallerID “Rene Wright” <2001>”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:2] Set(“SIP/2001-00000e3c”, “VMGAIN=”"") in new stack
[Aug 2 11:14:57] WARNING[31670] func_db.c: DB requires an argument, DB(/)
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:3] GotoIf(“SIP/2001-00000e3c”, “1?vmx,1”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Goto (macro-vm,vmx,1)
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:1] Set(“SIP/2001-00000e3c”, “MEXTEN=2000”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:2] Set(“SIP/2001-00000e3c”, “MMODE=NOANSWER”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:3] Set(“SIP/2001-00000e3c”, “RETVM=”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:4] Set(“SIP/2001-00000e3c”, “MODE=unavail”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:5] GotoIf(“SIP/2001-00000e3c”, “1?chknomsg”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Goto (macro-vm,vmx,7)
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:7] GotoIf(“SIP/2001-00000e3c”, “0?s-NOANSWER,1”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:8] GotoIf(“SIP/2001-00000e3c”, “1?notdirect”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Goto (macro-vm,vmx,10)
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:10] NoOp(“SIP/2001-00000e3c”, “Checking if ext 2000 is enabled: “) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:11] GotoIf(“SIP/2001-00000e3c”, “1?s-NOANSWER,1”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Goto (macro-vm,s-NOANSWER,1)
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:1] Macro(“SIP/2001-00000e3c”, “get-vmcontext,2000”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:1] Set(“SIP/2001-00000e3c”, “VMCONTEXT=default”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:2] GotoIf(“SIP/2001-00000e3c”, “0?200:300”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Goto (macro-get-vmcontext,s,300)
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:300] NoOp(“SIP/2001-00000e3c”, “”) in new stack
[Aug 2 11:14:57] VERBOSE[31670] pbx.c: – Executing [[email protected]:2] VoiceMail(“SIP/2001-00000e3c”, “[email protected],u”””) in new stack
[Aug 2 11:14:57] VERBOSE[31670] file.c: – <SIP/2001-00000e3c> Playing ‘vm-theperson.gsm’ (language ‘en’)
[Aug 2 11:14:58] VERBOSE[31670] file.c: – <SIP/2001-00000e3c> Playing ‘digits/2.gsm’ (language ‘en’)
[Aug 2 11:14:59] VERBOSE[31670] file.c: – <SIP/2001-00000e3c> Playing ‘digits/0.gsm’ (language ‘en’)
[Aug 2 11:15:00] VERBOSE[31670] file.c: – <SIP/2001-00000e3c> Playing ‘digits/0.gsm’ (language ‘en’)
[Aug 2 11:15:01] VERBOSE[31670] file.c: – <SIP/2001-00000e3c> Playing ‘digits/0.gsm’ (language ‘en’)
[Aug 2 11:15:01] VERBOSE[31670] file.c: – <SIP/2001-00000e3c> Playing ‘vm-isunavail.gsm’ (language ‘en’)
[Aug 2 11:15:02] VERBOSE[31670] file.c: – <SIP/2001-00000e3c> Playing ‘vm-intro.gsm’ (language ‘en’)
[Aug 2 11:15:08] VERBOSE[31670] file.c: – <SIP/2001-00000e3c> Playing ‘beep.gsm’ (language ‘en’)
[Aug 2 11:15:08] VERBOSE[31670] app_voicemail.c: – Recording the message
[Aug 2 11:15:08] VERBOSE[31670] app.c: – x=0, open writing: /var/spool/asterisk/voicemail/default/2000/tmp/6AbQ67 format: wav49, 0x9958fc8
[Aug 2 11:15:08] VERBOSE[31670] app.c: – x=1, open writing: /var/spool/asterisk/voicemail/default/2000/tmp/6AbQ67 format: gsm, 0x99d8928
[Aug 2 11:15:08] VERBOSE[31670] app.c: – x=2, open writing: /var/spool/asterisk/voicemail/default/2000/tmp/6AbQ67 format: wav, 0x9ce7ad0
[Aug 2 11:15:13] VERBOSE[31670] app.c: – User hung up
[Aug 2 11:15:13] VERBOSE[31670] app_macro.c: == Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on ‘SIP/2001-00000e3c’ in macro ‘vm’
[Aug 2 11:15:13] VERBOSE[31670] app_macro.c: == Spawn extension (macro-exten-vm, s, 18) exited non-zero on ‘SIP/2001-00000e3c’ in macro ‘exten-vm’
[Aug 2 11:15:13] VERBOSE[31670] pbx.c: == Spawn extension (ext-local, 2000, 1) exited non-zero on ‘SIP/2001-00000e3c’
[Aug 2 11:15:13] VERBOSE[31670] pbx.c: – Executing [[email protected]:1] Macro(“SIP/2001-00000e3c”, “hangupcall,”) in new stack
[Aug 2 11:15:13] VERBOSE[31670] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/2001-00000e3c”, “1?skiprg”) in new stack
[Aug 2 11:15:13] VERBOSE[31670] pbx.c: – Goto (macro-hangupcall,s,4)
[Aug 2 11:15:13] VERBOSE[31670] pbx.c: – Executing [[email protected]:4] GotoIf(“SIP/2001-00000e3c”, “1?skipblkvm”) in new stack
[Aug 2 11:15:13] VERBOSE[31670] pbx.c: – Goto (macro-hangupcall,s,7)
[Aug 2 11:15:13] VERBOSE[31670] pbx.c: – Executing [[email protected]:7] GotoIf(“SIP/2001-00000e3c”, “1?theend”) in new stack
[Aug 2 11:15:13] VERBOSE[31670] pbx.c: – Goto (macro-hangupcall,s,9)
[Aug 2 11:15:13] VERBOSE[31670] pbx.c: – Executing [[email protected]:9] Hangup(“SIP/2001-00000e3c”, “”) in new stack
[Aug 2 11:15:13] VERBOSE[31670] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/2001-00000e3c’ in macro ‘hangupcall’
[Aug 2 11:15:13] VERBOSE[31670] pbx.c: == Spawn extension (ext-local, h, 1) exited non-zero on ‘SIP/2001-00000e3c’
[Aug 2 11:15:32] VERBOSE[31669] pbx.c: – Executing [[email protected]:1] Macro(“SIP/2030-00000e3b”, “hangupcall,”) in new stack
[Aug 2 11:15:32] VERBOSE[31669] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/2030-00000e3b”, “1?skiprg”) in new stack
[Aug 2 11:15:32] VERBOSE[31669] pbx.c: – Goto (macro-hangupcall,s,4)
[Aug 2 11:15:32] VERBOSE[31669] pbx.c: – Executing [[email protected]:4] GotoIf(“SIP/2030-00000e3b”, “1?skipblkvm”) in new stack
[Aug 2 11:15:32] VERBOSE[31669] pbx.c: – Goto (macro-hangupcall,s,7)
[Aug 2 11:15:32] VERBOSE[31669] pbx.c: – Executing [[email protected]:7] GotoIf(“SIP/2030-00000e3b”, “1?theend”) in new stack
[Aug 2 11:15:32] VERBOSE[31669] pbx.c: – Goto (macro-hangupcall,s,9)
[Aug 2 11:15:32] VERBOSE[31669] pbx.c: – Executing [[email protected]:9] Hangup(“SIP/2030-00000e3b”, “”) in new stack
[Aug 2 11:15:32] VERBOSE[31669] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/2030-00000e3b’ in macro ‘hangupcall’
[Aug 2 11:15:32] VERBOSE[31669] chan_dahdi.c: – Hungup ‘DAHDI/1-1’
[Aug 2 11:15:32] VERBOSE[31669] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/2030-00000e3b’ in macro ‘dialout-trunk’
[Aug 2 11:15:32] VERBOSE[31669] pbx.c: == Spawn extension (from-internal, 8596539288, 6) exited non-zero on ‘SIP/2030-00000e3b’
[Aug 2 11:15:32] VERBOSE[1695] netsock.c: == Using SIP RTP TOS bits 184
[Aug 2 11:15:32] VERBOSE[1695] netsock.c: == Using SIP RTP CoS mark 5
[Aug 2 11:15:32] VERBOSE[1695] netsock.c: == Using UDPTL TOS bits 184
[Aug 2 11:15:32] VERBOSE[1695] netsock.c: == Using UDPTL CoS mark 5
[Aug 2 11:15:32] VERBOSE[31672] pbx.c: – Executing [*[email protected]:1] Answer(“SIP/2000-00000e3e”, “”) in new stack
[Aug 2 11:15:33] VERBOSE[31672] pbx.c: – Executing [*[email protected]:2] Wait(“SIP/2000-00000e3e”, “1”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [*[email protected]:3] Macro(“SIP/2000-00000e3e”, “user-callerid,”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:1] Set(“SIP/2000-00000e3e”, “AMPUSER=2000”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:2] GotoIf(“SIP/2000-00000e3e”, “0?report”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:3] ExecIf(“SIP/2000-00000e3e”, “1?Set(REALCALLERIDNUM=2000)”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:4] Set(“SIP/2000-00000e3e”, “AMPUSER=2000”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:5] Set(“SIP/2000-00000e3e”, “AMPUSERCIDNAME=Ken Carbonell”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:6] GotoIf(“SIP/2000-00000e3e”, “0?report”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:7] Set(“SIP/2000-00000e3e”, “AMPUSERCID=2000”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:8] Set(“SIP/2000-00000e3e”, “CALLERID(all)=“Ken Carbonell” <2000>”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:9] ExecIf(“SIP/2000-00000e3e”, “0?Set(CHANNEL(language)=)”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:10] GotoIf(“SIP/2000-00000e3e”, “0?continue”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:11] Set(“SIP/2000-00000e3e”, “__TTL=64”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:12] GotoIf(“SIP/2000-00000e3e”, “1?continue”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Goto (macro-user-callerid,s,19)
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:19] Set(“SIP/2000-00000e3e”, “CALLERID(number)=2000”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:20] Set(“SIP/2000-00000e3e”, “CALLERID(name)=Ken Carbonell”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:21] NoOp(“SIP/2000-00000e3e”, “Using CallerID “Ken Carbonell” <2000>”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [*[email protected]:4] Macro(“SIP/2000-00000e3e”, “get-vmcontext,2000”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:1] Set(“SIP/2000-00000e3e”, “VMCONTEXT=default”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:2] GotoIf(“SIP/2000-00000e3e”, “0?200:300”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Goto (macro-get-vmcontext,s,300)
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [[email protected]:300] NoOp(“SIP/2000-00000e3e”, “”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [*[email protected]:5] Set(“SIP/2000-00000e3e”, “VMBOXEXISTSSTATUS=SUCCESS”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [*[email protected]:6] GotoIf(“SIP/2000-00000e3e”, “1?mbexist”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Goto (from-internal,*97,106)
[Aug 2 11:15:34] VERBOSE[31672] pbx.c: – Executing [*[email protected]:106] VoiceMailMain(“SIP/2000-00000e3e”, “[email protected]”) in new stack
[Aug 2 11:15:34] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-password.gsm’ (language ‘en’)
[Aug 2 11:15:39] VERBOSE[31672] app_voicemail.c: – Incorrect password ‘2’ for user ‘2000’ (context = default)
[Aug 2 11:15:39] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-incorrect.gsm’ (language ‘en’)
[Aug 2 11:15:40] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-password.gsm’ (language ‘en’)
[Aug 2 11:15:45] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-youhave.gsm’ (language ‘en’)
[Aug 2 11:15:46] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘digits/1.gsm’ (language ‘en’)
[Aug 2 11:15:46] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-INBOX.gsm’ (language ‘en’)
[Aug 2 11:15:47] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-message.gsm’ (language ‘en’)
[Aug 2 11:15:48] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-onefor.gsm’ (language ‘en’)
[Aug 2 11:15:48] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-first.gsm’ (language ‘en’)
[Aug 2 11:15:48] VERBOSE[31672] config.c: == Parsing ‘/var/spool/asterisk/voicemail/default/2000/INBOX/msg0000.txt’: [Aug 2 11:15:48] VERBOSE[31672] config.c: == Found
[Aug 2 11:15:48] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-message.gsm’ (language ‘en’)
[Aug 2 11:15:49] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-received.gsm’ (language ‘en’)
[Aug 2 11:15:50] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘digits/at.gsm’ (language ‘en’)
[Aug 2 11:15:51] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘digits/11.gsm’ (language ‘en’)
[Aug 2 11:15:52] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘digits/15.gsm’ (language ‘en’)
[Aug 2 11:15:53] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘digits/a-m.gsm’ (language ‘en’)
[Aug 2 11:15:54] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘/var/spool/asterisk/voicemail/default/2000/INBOX/msg0000.slin’ (language ‘en’)
[Aug 2 11:15:57] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-advopts.gsm’ (language ‘en’)
[Aug 2 11:16:00] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-repeat.gsm’ (language ‘en’)
[Aug 2 11:16:02] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-delete.gsm’ (language ‘en’)
[Aug 2 11:16:04] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-toforward.gsm’ (language ‘en’)
[Aug 2 11:16:07] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-savemessage.gsm’ (language ‘en’)
[Aug 2 11:16:08] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-extension.gsm’ (language ‘en’)
[Aug 2 11:16:14] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘digits/2.gsm’ (language ‘en’)
[Aug 2 11:16:15] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘digits/0.gsm’ (language ‘en’)
[Aug 2 11:16:16] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘digits/0.gsm’ (language ‘en’)
[Aug 2 11:16:17] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘digits/1.gsm’ (language ‘en’)
[Aug 2 11:16:17] VERBOSE[31672] config.c: == Parsing ‘/var/spool/asterisk/voicemail/default/2000/INBOX/msg0000.txt’: [Aug 2 11:16:17] VERBOSE[31672] config.c: == Found
[Aug 2 11:16:17] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-forwardoptions.gsm’ (language ‘en’)
[Aug 2 11:16:22] NOTICE[31672] app_voicemail.c: Copying message from [email protected] to [email protected]
[Aug 2 11:16:22] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-msgsaved.gsm’ (language ‘en’)
[Aug 2 11:16:24] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-advopts.gsm’ (language ‘en’)
[Aug 2 11:16:26] VERBOSE[31672] file.c: – <SIP/2000-00000e3e> Playing ‘vm-repeat.gsm’ (language ‘en’)
[Aug 2 11:16:27] VERBOSE[31672] pbx.c: == Spawn extension (from-internal, *97, 106) exited non-zero on ‘SIP/2000-00000e3e’
[Aug 2 11:16:27] VERBOSE[31672] pbx.c: – Executing [[email protected]:1] Macro(“SIP/2000-00000e3e”, “hangupcall”) in new stack
[Aug 2 11:16:27] VERBOSE[31672] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/2000-00000e3e”, “1?skiprg”) in new stack
[Aug 2 11:16:27] VERBOSE[31672] pbx.c: – Goto (macro-hangupcall,s,4)
[Aug 2 11:16:27] VERBOSE[31672] pbx.c: – Executing [[email protected]:4] GotoIf(“SIP/2000-00000e3e”, “1?skipblkvm”) in new stack
[Aug 2 11:16:27] VERBOSE[31672] pbx.c: – Goto (macro-hangupcall,s,7)
[Aug 2 11:16:27] VERBOSE[31672] pbx.c: – Executing [[email protected]:7] GotoIf(“SIP/2000-00000e3e”, “1?theend”) in new stack
[Aug 2 11:16:27] VERBOSE[31672] pbx.c: – Goto (macro-hangupcall,s,9)
[Aug 2 11:16:27] VERBOSE[31672] pbx.c: – Executing [[email protected]:9] Hangup(“SIP/2000-00000e3e”, “”) in new stack
[Aug 2 11:16:27] VERBOSE[31672] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/2000-00000e3e’ in macro ‘hangupcall’
[Aug 2 11:16:27] VERBOSE[31672] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/2000-00000e3e’