[asterisk-bugs] [Asterisk 0018685]: [REGRESSION]: Files based voicemail message re-sequencing still not working as expected.

Asterisk Bug Tracker noreply at bugs.digium.com
Tue Feb 8 11:14:00 CST 2011


A NOTE has been added to this issue. 
====================================================================== 
https://issues.asterisk.org/view.php?id=18685 
====================================================================== 
Reported By:                aragon
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   18685
Category:                   Applications/app_voicemail
Reproducibility:            always
Severity:                   minor
Priority:                   normal
Status:                     feedback
Asterisk Version:           SVN 
JIRA:                        
Regression:                 No 
Reviewboard Link:            
SVN Branch (only for SVN checkouts, not tarball releases): N/A 
SVN Revision (number only!): 303676 
Request Review:              
====================================================================== 
Date Submitted:             2011-01-26 11:48 CST
Last Modified:              2011-02-08 11:13 CST
====================================================================== 
Summary:                    [REGRESSION]: Files based voicemail message
re-sequencing still not working as expected.
Description: 
Files based voicemail message re-sequencing still not working as expected.
Cannot listed to new messages by using the following steps to reproduce.

check new messages and then press 9 to save the message and choose 0 to
save it to new messages (which puts it in INBOX again). Changes the file
names from 0000 to 0001 assuming there is only one message in the folder.

This problem still occurs after upgrading to revision 303676
====================================================================== 

---------------------------------------------------------------------- 
 (0131678) aragon (reporter) - 2011-02-08 11:13
 https://issues.asterisk.org/view.php?id=18685#c131678 
---------------------------------------------------------------------- 
I ran the same test setup again and noticed that mailbox 6010 is not
re-sequenced until a new message is left and user logs into mailbox 6010
again.  Therefore it is not possible to listen to any messages in INBOX
folder until another message is left in this folder and user logs in
again.
I captured the CLI and disconnected from the Asterisk console between
testing stages to display status of files in
/var/spool/asterisk/voicemail/default/6010/INBOX
I started with a dir command to show that mailbox was empty prior to any
tests.

[root at lab INBOX]# dir
[root at lab INBOX]# asterisk -vvvvvvvvvr
  == Parsing '/etc/asterisk/asterisk.conf': Found
[Feb  8 11:18:48] Running as group 'scopserv'
[Feb  8 11:18:48] Connected to Asterisk 1.4.40 currently running on lab
(pid = 20077)
Verbosity is at least 3
Core debug is at least 3
[2011-02-08 11:18:52]     -- Executing [*9806010 at default-super:1]
Dial("SIP/6010-0000000d", "Local/6010 at default-local-voicemail") in new
stack
[2011-02-08 11:18:52]     -- Called 6010 at default-local-voicemail
[2011-02-08 11:18:52]     -- Executing [6010 at default-local-voicemail:1]
Set("Local/6010 at default-local-voicemail-f737,2",
"VMOPERATOR=Local/s at default-aa-operator-6010") in new stack
[2011-02-08 11:18:52]     -- Executing [6010 at default-local-voicemail:2]
VoiceMail("Local/6010 at default-local-voicemail-f737,2", "6010 at default|b") in
new stack
[2011-02-08 11:18:52]     -- Local/6010 at default-local-voicemail-f737,1
answered SIP/6010-0000000d
[2011-02-08 11:18:52]     -- <Local/6010 at default-local-voicemail-f737,2>
Playing '/var/spool/asterisk/voicemail/default/6010/busy' (language 'en')
[2011-02-08 11:18:53]     -- <Local/6010 at default-local-voicemail-f737,2>
Playing 'beep' (language 'en')
[2011-02-08 11:18:54]     -- Recording the message
[2011-02-08 11:18:54]     -- x=0, open writing: 
/var/spool/asterisk/voicemail/default/6010/tmp/LMxWWD format: wav49,
0x9496a08
[2011-02-08 11:19:01]     -- User hung up
[2011-02-08 11:19:01]   == Spawn extension (default-super, *9806010, 1)
exited non-zero on 'SIP/6010-0000000d'
[2011-02-08 11:19:01]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0000.txt': [2011-02-08
11:19:01] Found
[2011-02-08 11:19:01]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0000.txt': [2011-02-08
11:19:01] Found
[2011-02-08 11:19:01]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0000.txt': [2011-02-08
11:19:01] Found
[2011-02-08 11:19:01]   == Spawn extension (default-local-voicemail, 6010,
2) exited non-zero on 'Local/6010 at default-local-voicemail-f737,2'
[2011-02-08 11:19:03]   == Parsing '/etc/asterisk/manager.conf':
[2011-02-08 11:19:03] Found
[2011-02-08 11:19:07]     -- Executing [*9806010 at default-super:1]
Dial("SIP/6010-0000000e", "Local/6010 at default-local-voicemail") in new
stack
[2011-02-08 11:19:07]     -- Called 6010 at default-local-voicemail
[2011-02-08 11:19:07]     -- Executing [6010 at default-local-voicemail:1]
Set("Local/6010 at default-local-voicemail-3481,2",
"VMOPERATOR=Local/s at default-aa-operator-6010") in new stack
[2011-02-08 11:19:07]     -- Executing [6010 at default-local-voicemail:2]
VoiceMail("Local/6010 at default-local-voicemail-3481,2", "6010 at default|b") in
new stack
[2011-02-08 11:19:07]     -- Local/6010 at default-local-voicemail-3481,1
answered SIP/6010-0000000e
[2011-02-08 11:19:07]     -- <Local/6010 at default-local-voicemail-3481,2>
Playing '/var/spool/asterisk/voicemail/default/6010/busy' (language 'en')
[2011-02-08 11:19:11]     -- <Local/6010 at default-local-voicemail-3481,2>
Playing 'beep' (language 'en')
[2011-02-08 11:19:11]     -- Recording the message
[2011-02-08 11:19:11]     -- x=0, open writing: 
/var/spool/asterisk/voicemail/default/6010/tmp/0r9X2c format: wav49,
0x9495a28
[2011-02-08 11:19:17]   == Spawn extension (default-super, *9806010, 1)
exited non-zero on 'SIP/6010-0000000e'
[2011-02-08 11:19:17]     -- User hung up
[2011-02-08 11:19:17]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0001.txt': [2011-02-08
11:19:17] Found
[2011-02-08 11:19:17]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0001.txt': [2011-02-08
11:19:17] Found
[2011-02-08 11:19:17]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0001.txt': [2011-02-08
11:19:17] Found
[2011-02-08 11:19:17]   == Spawn extension (default-local-voicemail, 6010,
2) exited non-zero on 'Local/6010 at default-local-voicemail-3481,2'
[2011-02-08 11:19:21]     -- Executing [*9806010 at default-super:1]
Dial("SIP/6010-0000000f", "Local/6010 at default-local-voicemail") in new
stack
[2011-02-08 11:19:21]     -- Called 6010 at default-local-voicemail
[2011-02-08 11:19:21]     -- Executing [6010 at default-local-voicemail:1]
Set("Local/6010 at default-local-voicemail-9230,2",
"VMOPERATOR=Local/s at default-aa-operator-6010") in new stack
[2011-02-08 11:19:21]     -- Executing [6010 at default-local-voicemail:2]
VoiceMail("Local/6010 at default-local-voicemail-9230,2", "6010 at default|b") in
new stack
[2011-02-08 11:19:21]     -- Local/6010 at default-local-voicemail-9230,1
answered SIP/6010-0000000f
[2011-02-08 11:19:21]     -- <Local/6010 at default-local-voicemail-9230,2>
Playing '/var/spool/asterisk/voicemail/default/6010/busy' (language 'en')
[2011-02-08 11:19:25]     -- <Local/6010 at default-local-voicemail-9230,2>
Playing 'beep' (language 'en')
[2011-02-08 11:19:25]     -- Recording the message
[2011-02-08 11:19:25]     -- x=0, open writing: 
/var/spool/asterisk/voicemail/default/6010/tmp/Fd0OuP format: wav49,
0x9496040
[2011-02-08 11:19:32]     -- User hung up
[2011-02-08 11:19:32]   == Spawn extension (default-super, *9806010, 1)
exited non-zero on 'SIP/6010-0000000f'
[2011-02-08 11:19:32]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0002.txt': [2011-02-08
11:19:32] Found
[2011-02-08 11:19:32]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0002.txt': [2011-02-08
11:19:32] Found
[2011-02-08 11:19:32]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0002.txt': [2011-02-08
11:19:32] Found
[2011-02-08 11:19:32]   == Spawn extension (default-local-voicemail, 6010,
2) exited non-zero on 'Local/6010 at default-local-voicemail-9230,2'
lab*CLI> 
Disconnected from Asterisk server
[Feb  8 11:19:40] Executing last minute cleanups
Asterisk ending (0).
[root at lab INBOX]# dir
msg0000.txt  msg0000.WAV  msg0001.txt  msg0001.WAV  msg0002.txt 
msg0002.WAV
[root at lab INBOX]# asterisk -vvvvvvvvvr
  == Parsing '/etc/asterisk/asterisk.conf': Found
[Feb  8 11:19:45] Running as group 'scopserv'
[Feb  8 11:19:45] Connected to Asterisk 1.4.40 currently running on lab
(pid = 20077)
Verbosity is at least 3
Core debug is at least 3
[2011-02-08 11:19:47]  Extension Changed 6010[default-local] new state
InUse for Notify User 6001 
[2011-02-08 11:19:47]     -- Executing [*981 at default-super:1]
Goto("SIP/6010-00000010", "default-app-voicemail-main|s|1") in new stack
[2011-02-08 11:19:47]     -- Goto (default-app-voicemail-main,s,1)
[2011-02-08 11:19:47]     -- Executing [s at default-app-voicemail-main:1]
NoOp("SIP/6010-00000010", "Voicemail Main") in new stack
[2011-02-08 11:19:47]     -- Executing [s at default-app-voicemail-main:2]
Answer("SIP/6010-00000010", "") in new stack
[2011-02-08 11:19:47]     -- Executing [s at default-app-voicemail-main:3]
AGI("SIP/6010-00000010", "agi://127.0.0.1:4573/extension") in new stack
[2011-02-08 11:19:48]   agi://127.0.0.1:4573/extension: Variable
'PHONE_EXTEN_HD' result is not defined!!!
[2011-02-08 11:19:48]   agi://127.0.0.1:4573/extension: Variable
'CHECK_HOTDESK' result is not defined!!!
[2011-02-08 11:19:48]     -- AGI Script agi://127.0.0.1:4573/extension
completed, returning 0
[2011-02-08 11:19:48]     -- Executing [s at default-app-voicemail-main:4]
Wait("SIP/6010-00000010", "1") in new stack
[2011-02-08 11:19:49]     -- Executing [s at default-app-voicemail-main:5]
Set("SIP/6010-00000010", "GROUP(OUTGOING)=6010") in new stack
[2011-02-08 11:19:49]     -- Executing [s at default-app-voicemail-main:6]
Set("SIP/6010-00000010", "TIMEOUT(absolute)=1200") in new stack
[2011-02-08 11:19:49]     -- Channel will hangup at 2011-02-08 16:39:49
UTC.
[2011-02-08 11:19:49]     -- Executing [s at default-app-voicemail-main:7]
Set("SIP/6010-00000010", "TIMEOUT(digit)=5") in new stack
[2011-02-08 11:19:49]     -- Digit timeout set to 5
[2011-02-08 11:19:49]     -- Executing [s at default-app-voicemail-main:8]
Set("SIP/6010-00000010", "TIMEOUT(response)=10") in new stack
[2011-02-08 11:19:49]     -- Response timeout set to 10
[2011-02-08 11:19:49]     -- Executing [s at default-app-voicemail-main:9]
Set("SIP/6010-00000010", "DBKEY=/Voicemail/default/6010") in new stack
[2011-02-08 11:19:49]     -- Executing [s at default-app-voicemail-main:10]
GotoIf("SIP/6010-00000010", "0?11:14") in new stack
[2011-02-08 11:19:49]     -- Goto (default-app-voicemail-main,s,14)
[2011-02-08 11:19:49]     -- Executing [s at default-app-voicemail-main:14]
Set("SIP/6010-00000010", "SCOPSERV_DBDEL(/Voicemail/default/6010)=") in new
stack
[2011-02-08 11:19:49]     -- Executing [s at default-app-voicemail-main:15]
VoiceMailMain("SIP/6010-00000010", "6010 at default") in new stack
[2011-02-08 11:19:49]     -- <SIP/6010-00000010> Playing 'vm-password'
(language 'en')
[2011-02-08 11:19:53] NOTICE[30237]: app_voicemail.c:6114 open_mailbox:
Resequencing Mailbox: /var/spool/asterisk/voicemail/default/6010/INBOX,
expected 100 but found 3 message(s) in box with max threshold of 100.
[2011-02-08 11:19:53]     -- <SIP/6010-00000010> Playing 'vm-youhave'
(language 'en')
[2011-02-08 11:19:53]     -- <SIP/6010-00000010> Playing 'digits/3'
(language 'en')
[2011-02-08 11:19:54]     -- <SIP/6010-00000010> Playing 'vm-INBOX'
(language 'en')
[2011-02-08 11:19:54]     -- <SIP/6010-00000010> Playing 'vm-first'
(language 'en')
[2011-02-08 11:19:55]     -- <SIP/6010-00000010> Playing 'vm-message'
(language 'en')
[2011-02-08 11:19:56]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0000.txt': [2011-02-08
11:19:56] Found
[2011-02-08 11:19:56]     -- <SIP/6010-00000010> Playing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0000' (language 'en')
[2011-02-08 11:19:57]     -- <SIP/6010-00000010> Playing 'vm-deleted'
(language 'en')
[2011-02-08 11:19:59]     -- <SIP/6010-00000010> Playing 'vm-advopts'
(language 'en')
[2011-02-08 11:20:00]     -- <SIP/6010-00000010> Playing 'vm-message'
(language 'en')
[2011-02-08 11:20:01]     -- <SIP/6010-00000010> Playing 'digits/2'
(language 'en')
[2011-02-08 11:20:02]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0001.txt': [2011-02-08
11:20:02] Found
[2011-02-08 11:20:02]     -- <SIP/6010-00000010> Playing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0001' (language 'en')
[2011-02-08 11:20:03]   == Parsing '/etc/asterisk/manager.conf':
[2011-02-08 11:20:03] Found
[2011-02-08 11:20:04]     -- <SIP/6010-00000010> Playing 'vm-deleted'
(language 'en')
[2011-02-08 11:20:05]     -- <SIP/6010-00000010> Playing 'vm-prev'
(language 'en')
[2011-02-08 11:20:07]     -- <SIP/6010-00000010> Playing 'vm-last'
(language 'en')
[2011-02-08 11:20:07]     -- <SIP/6010-00000010> Playing 'vm-message'
(language 'en')
[2011-02-08 11:20:08]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0002.txt': [2011-02-08
11:20:08] Found
[2011-02-08 11:20:08]     -- <SIP/6010-00000010> Playing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0002' (language 'en')
[2011-02-08 11:20:09]     -- <SIP/6010-00000010> Playing 'vm-savefolder'
(language 'en')
[2011-02-08 11:20:12]     -- <SIP/6010-00000010> Playing 'vm-press'
(language 'en')
[2011-02-08 11:20:12]     -- <SIP/6010-00000010> Playing 'vm-message'
(language 'en')
[2011-02-08 11:20:13]     -- <SIP/6010-00000010> Playing 'digits/3'
(language 'en')
[2011-02-08 11:20:14]     -- <SIP/6010-00000010> Playing 'vm-savedto'
(language 'en')
[2011-02-08 11:20:15]     -- <SIP/6010-00000010> Playing 'vm-INBOX'
(language 'en')
[2011-02-08 11:20:16]     -- <SIP/6010-00000010> Playing 'vm-messages'
(language 'en')
[2011-02-08 11:20:17]     -- <SIP/6010-00000010> Playing 'vm-prev'
(language 'en')
[2011-02-08 11:20:18]   == Spawn extension (default-app-voicemail-main, s,
15) exited non-zero on 'SIP/6010-00000010'
[2011-02-08 11:20:18]     -- Executing [h at default-app-voicemail-main:1]
ResetCDR("SIP/6010-00000010", "w") in new stack
[2011-02-08 11:20:18]     -- Executing [h at default-app-voicemail-main:2]
NoCDR("SIP/6010-00000010", "") in new stack
[2011-02-08 11:20:18]     -- Executing [h at default-app-voicemail-main:3]
DeadAGI("SIP/6010-00000010",
"agi://127.0.0.1:4573/cdr?arg1=1297181987.58&arg2=dst&arg3=*981") in new
stack
[2011-02-08 11:20:18]     -- AGI Script
agi://127.0.0.1:4573/cdr?arg1=1297181987.58&arg2=dst&arg3=*981 completed,
returning 0
[2011-02-08 11:20:18]  Extension Changed 6010[default-local] new state
Idle for Notify User 6001 
[2011-02-08 11:20:19]   == Refreshing DNS lookups.
lab*CLI> 
Disconnected from Asterisk server
[Feb  8 11:20:22] Executing last minute cleanups
Asterisk ending (0).
[root at lab INBOX]# dir
msg0003.txt  msg0003.WAV
[root at lab INBOX]# asterisk -vvvvvvvvvr
  == Parsing '/etc/asterisk/asterisk.conf': Found
[Feb  8 11:20:26] Running as group 'scopserv'
[Feb  8 11:20:26] Connected to Asterisk 1.4.40 currently running on lab
(pid = 20077)
Verbosity is at least 3
Core debug is at least 3
[2011-02-08 11:20:29]     -- Executing [*981 at default-super:1]
Goto("SIP/6010-00000011", "default-app-voicemail-main|s|1") in new stack
[2011-02-08 11:20:29]     -- Goto (default-app-voicemail-main,s,1)
[2011-02-08 11:20:29]     -- Executing [s at default-app-voicemail-main:1]
NoOp("SIP/6010-00000011", "Voicemail Main") in new stack
[2011-02-08 11:20:29]     -- Executing [s at default-app-voicemail-main:2]
Answer("SIP/6010-00000011", "") in new stack
[2011-02-08 11:20:29]     -- Executing [s at default-app-voicemail-main:3]
AGI("SIP/6010-00000011", "agi://127.0.0.1:4573/extension") in new stack
[2011-02-08 11:20:29]  Extension Changed 6010[default-local] new state
InUse for Notify User 6001 
[2011-02-08 11:20:29]   agi://127.0.0.1:4573/extension: Variable
'PHONE_EXTEN_HD' result is not defined!!!
[2011-02-08 11:20:29]   agi://127.0.0.1:4573/extension: Variable
'CHECK_HOTDESK' result is not defined!!!
[2011-02-08 11:20:29]     -- AGI Script agi://127.0.0.1:4573/extension
completed, returning 0
[2011-02-08 11:20:29]     -- Executing [s at default-app-voicemail-main:4]
Wait("SIP/6010-00000011", "1") in new stack
[2011-02-08 11:20:30]     -- Executing [s at default-app-voicemail-main:5]
Set("SIP/6010-00000011", "GROUP(OUTGOING)=6010") in new stack
[2011-02-08 11:20:30]     -- Executing [s at default-app-voicemail-main:6]
Set("SIP/6010-00000011", "TIMEOUT(absolute)=1200") in new stack
[2011-02-08 11:20:30]     -- Channel will hangup at 2011-02-08 16:40:30
UTC.
[2011-02-08 11:20:30]     -- Executing [s at default-app-voicemail-main:7]
Set("SIP/6010-00000011", "TIMEOUT(digit)=5") in new stack
[2011-02-08 11:20:30]     -- Digit timeout set to 5
[2011-02-08 11:20:30]     -- Executing [s at default-app-voicemail-main:8]
Set("SIP/6010-00000011", "TIMEOUT(response)=10") in new stack
[2011-02-08 11:20:30]     -- Response timeout set to 10
[2011-02-08 11:20:30]     -- Executing [s at default-app-voicemail-main:9]
Set("SIP/6010-00000011", "DBKEY=/Voicemail/default/6010") in new stack
[2011-02-08 11:20:30]     -- Executing [s at default-app-voicemail-main:10]
GotoIf("SIP/6010-00000011", "0?11:14") in new stack
[2011-02-08 11:20:30]     -- Goto (default-app-voicemail-main,s,14)
[2011-02-08 11:20:30]     -- Executing [s at default-app-voicemail-main:14]
Set("SIP/6010-00000011", "SCOPSERV_DBDEL(/Voicemail/default/6010)=") in new
stack
[2011-02-08 11:20:30]     -- Executing [s at default-app-voicemail-main:15]
VoiceMailMain("SIP/6010-00000011", "6010 at default") in new stack
[2011-02-08 11:20:30]     -- <SIP/6010-00000011> Playing 'vm-password'
(language 'en')
[2011-02-08 11:20:33]     -- <SIP/6010-00000011> Playing 'vm-youhave'
(language 'en')
[2011-02-08 11:20:34]     -- <SIP/6010-00000011> Playing 'digits/1'
(language 'en')
[2011-02-08 11:20:35]     -- <SIP/6010-00000011> Playing 'vm-INBOX'
(language 'en')
[2011-02-08 11:20:36]     -- <SIP/6010-00000011> Playing 'vm-message'
(language 'en')
[2011-02-08 11:20:36]     -- <SIP/6010-00000011> Playing 'vm-onefor'
(language 'en')
[2011-02-08 11:20:37]     -- <SIP/6010-00000011> Playing 'vm-first'
(language 'en')
[2011-02-08 11:20:37]     -- <SIP/6010-00000011> Playing 'vm-message'
(language 'en')
[2011-02-08 11:20:38] WARNING[30815]: app_voicemail.c:6026 play_message:
No message attribute file?!!
(/var/spool/asterisk/voicemail/default/6010/INBOX/msg0000.txt)
[2011-02-08 11:20:38]     -- <SIP/6010-00000011> Playing 'vm-advopts'
(language 'en')
[2011-02-08 11:20:40]     -- <SIP/6010-00000011> Playing 'vm-repeat'
(language 'en')
[2011-02-08 11:20:40]   == Spawn extension (default-app-voicemail-main, s,
15) exited non-zero on 'SIP/6010-00000011'
[2011-02-08 11:20:40]     -- Executing [h at default-app-voicemail-main:1]
ResetCDR("SIP/6010-00000011", "w") in new stack
[2011-02-08 11:20:40]     -- Executing [h at default-app-voicemail-main:2]
NoCDR("SIP/6010-00000011", "") in new stack
[2011-02-08 11:20:40]     -- Executing [h at default-app-voicemail-main:3]
DeadAGI("SIP/6010-00000011",
"agi://127.0.0.1:4573/cdr?arg1=1297182029.59&arg2=dst&arg3=*981") in new
stack
[2011-02-08 11:20:41]     -- AGI Script
agi://127.0.0.1:4573/cdr?arg1=1297182029.59&arg2=dst&arg3=*981 completed,
returning 0
[2011-02-08 11:20:41]  Extension Changed 6010[default-local] new state
Idle for Notify User 6001 
lab*CLI> 
Disconnected from Asterisk server
[Feb  8 11:20:50] Executing last minute cleanups
Asterisk ending (0).
[root at lab INBOX]# dir
msg0003.txt  msg0003.WAV
[root at lab INBOX]# asterisk -vvvvvvvvvr
  == Parsing '/etc/asterisk/asterisk.conf': Found
[Feb  8 11:20:54] Running as group 'scopserv'
[Feb  8 11:20:54] Connected to Asterisk 1.4.40 currently running on lab
(pid = 20077)
Verbosity is at least 3
Core debug is at least 3
[2011-02-08 11:21:01]     -- Executing [*9806010 at default-super:1]
Dial("SIP/6002-00000012", "Local/6010 at default-local-voicemail") in new
stack
[2011-02-08 11:21:01]     -- Called 6010 at default-local-voicemail
[2011-02-08 11:21:01]  Extension Changed 6002[default-local] new state
InUse for Notify User 6001 
[2011-02-08 11:21:01]     -- Executing [6010 at default-local-voicemail:1]
Set("Local/6010 at default-local-voicemail-8b97,2",
"VMOPERATOR=Local/s at default-aa-operator-6010") in new stack
[2011-02-08 11:21:01]     -- Executing [6010 at default-local-voicemail:2]
VoiceMail("Local/6010 at default-local-voicemail-8b97,2", "6010 at default|b") in
new stack
[2011-02-08 11:21:01]     -- Local/6010 at default-local-voicemail-8b97,1
answered SIP/6002-00000012
[2011-02-08 11:21:01]     -- <Local/6010 at default-local-voicemail-8b97,2>
Playing '/var/spool/asterisk/voicemail/default/6010/busy' (language 'en')
[2011-02-08 11:21:02]     -- <Local/6010 at default-local-voicemail-8b97,2>
Playing 'beep' (language 'en')
[2011-02-08 11:21:03]     -- Recording the message
[2011-02-08 11:21:03]     -- x=0, open writing: 
/var/spool/asterisk/voicemail/default/6010/tmp/7Yjlup format: wav49,
0x94967b8
[2011-02-08 11:21:03]   == Parsing '/etc/asterisk/manager.conf':
[2011-02-08 11:21:03] Found
[2011-02-08 11:21:12]   == Spawn extension (default-super, *9806010, 1)
exited non-zero on 'SIP/6002-00000012'
[2011-02-08 11:21:12]     -- User hung up
[2011-02-08 11:21:12]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0000.txt': [2011-02-08
11:21:12] Found
[2011-02-08 11:21:12]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0000.txt': [2011-02-08
11:21:12] Found
[2011-02-08 11:21:12]   == Parsing
'/var/spool/asterisk/voicemail/default/6010/INBOX/msg0000.txt': [2011-02-08
11:21:12] Found
[2011-02-08 11:21:12]  Extension Changed 6002[default-local] new state
Idle for Notify User 6002 
[2011-02-08 11:21:12]  Extension Changed 6002[default-local] new state
Idle for Notify User 6001 
[2011-02-08 11:21:12]   == Spawn extension (default-local-voicemail, 6010,
2) exited non-zero on 'Local/6010 at default-local-voicemail-8b97,2'
lab*CLI> 
Disconnected from Asterisk server
[Feb  8 11:21:21] Executing last minute cleanups
Asterisk ending (0).
[root at lab INBOX]# dir
msg0000.txt  msg0000.WAV  msg0003.txt  msg0003.WAV
[root at lab INBOX]# asterisk -vvvvvvvvvr
  == Parsing '/etc/asterisk/asterisk.conf': Found
[Feb  8 11:21:28] Running as group 'scopserv'
[Feb  8 11:21:28] Connected to Asterisk 1.4.40 currently running on lab
(pid = 20077)
Verbosity is at least 3
Core debug is at least 3
[2011-02-08 11:21:29]     -- Executing [*981 at default-super:1]
Goto("SIP/6010-00000013", "default-app-voicemail-main|s|1") in new stack
[2011-02-08 11:21:29]     -- Goto (default-app-voicemail-main,s,1)
[2011-02-08 11:21:29]     -- Executing [s at default-app-voicemail-main:1]
NoOp("SIP/6010-00000013", "Voicemail Main") in new stack
[2011-02-08 11:21:29]     -- Executing [s at default-app-voicemail-main:2]
Answer("SIP/6010-00000013", "") in new stack
[2011-02-08 11:21:29]     -- Executing [s at default-app-voicemail-main:3]
AGI("SIP/6010-00000013", "agi://127.0.0.1:4573/extension") in new stack
[2011-02-08 11:21:29]   agi://127.0.0.1:4573/extension: Variable
'PHONE_EXTEN_HD' result is not defined!!!
[2011-02-08 11:21:29]   agi://127.0.0.1:4573/extension: Variable
'CHECK_HOTDESK' result is not defined!!!
[2011-02-08 11:21:29]     -- AGI Script agi://127.0.0.1:4573/extension
completed, returning 0
[2011-02-08 11:21:29]     -- Executing [s at default-app-voicemail-main:4]
Wait("SIP/6010-00000013", "1") in new stack
[2011-02-08 11:21:29]  Extension Changed 6010[default-local] new state
InUse for Notify User 6010 
[2011-02-08 11:21:29]  Extension Changed 6010[default-local] new state
InUse for Notify User 6002 
[2011-02-08 11:21:29]  Extension Changed 6010[default-local] new state
InUse for Notify User 6001 
[2011-02-08 11:21:30]     -- Executing [s at default-app-voicemail-main:5]
Set("SIP/6010-00000013", "GROUP(OUTGOING)=6010") in new stack
[2011-02-08 11:21:30]     -- Executing [s at default-app-voicemail-main:6]
Set("SIP/6010-00000013", "TIMEOUT(absolute)=1200") in new stack
[2011-02-08 11:21:30]     -- Channel will hangup at 2011-02-08 16:41:30
UTC.
[2011-02-08 11:21:31]     -- Executing [s at default-app-voicemail-main:7]
Set("SIP/6010-00000013", "TIMEOUT(digit)=5") in new stack
[2011-02-08 11:21:31]     -- Digit timeout set to 5
[2011-02-08 11:21:31]     -- Executing [s at default-app-voicemail-main:8]
Set("SIP/6010-00000013", "TIMEOUT(response)=10") in new stack
[2011-02-08 11:21:31]     -- Response timeout set to 10
[2011-02-08 11:21:31]     -- Executing [s at default-app-voicemail-main:9]
Set("SIP/6010-00000013", "DBKEY=/Voicemail/default/6010") in new stack
[2011-02-08 11:21:31]     -- Executing [s at default-app-voicemail-main:10]
GotoIf("SIP/6010-00000013", "0?11:14") in new stack
[2011-02-08 11:21:31]     -- Goto (default-app-voicemail-main,s,14)
[2011-02-08 11:21:31]     -- Executing [s at default-app-voicemail-main:14]
Set("SIP/6010-00000013", "SCOPSERV_DBDEL(/Voicemail/default/6010)=") in new
stack
[2011-02-08 11:21:31]     -- Executing [s at default-app-voicemail-main:15]
VoiceMailMain("SIP/6010-00000013", "6010 at default") in new stack
[2011-02-08 11:21:31]     -- <SIP/6010-00000013> Playing 'vm-password'
(language 'en')
[2011-02-08 11:21:34] NOTICE[31545]: app_voicemail.c:6114 open_mailbox:
Resequencing Mailbox: /var/spool/asterisk/voicemail/default/6010/INBOX,
expected 100 but found 2 message(s) in box with max threshold of 100.
[2011-02-08 11:21:34]     -- <SIP/6010-00000013> Playing 'vm-youhave'
(language 'en')
[2011-02-08 11:21:35]     -- <SIP/6010-00000013> Playing 'digits/2'
(language 'en')
[2011-02-08 11:21:36]     -- <SIP/6010-00000013> Playing 'vm-INBOX'
(language 'en')
[2011-02-08 11:21:36]     -- <SIP/6010-00000013> Playing 'vm-messages'
(language 'en')
[2011-02-08 11:21:37]     -- <SIP/6010-00000013> Playing 'vm-onefor'
(language 'en')
[2011-02-08 11:21:39]     -- <SIP/6010-00000013> Playing 'vm-INBOX'
(language 'en')
[2011-02-08 11:21:39]     -- <SIP/6010-00000013> Playing 'vm-messages'
(language 'en')
[2011-02-08 11:21:40]   == Spawn extension (default-app-voicemail-main, s,
15) exited non-zero on 'SIP/6010-00000013'
[2011-02-08 11:21:40]     -- Executing [h at default-app-voicemail-main:1]
ResetCDR("SIP/6010-00000013", "w") in new stack
[2011-02-08 11:21:40]     -- Executing [h at default-app-voicemail-main:2]
NoCDR("SIP/6010-00000013", "") in new stack
[2011-02-08 11:21:40]     -- Executing [h at default-app-voicemail-main:3]
DeadAGI("SIP/6010-00000013",
"agi://127.0.0.1:4573/cdr?arg1=1297182089.66&arg2=dst&arg3=*981") in new
stack
[2011-02-08 11:21:40]     -- AGI Script
agi://127.0.0.1:4573/cdr?arg1=1297182089.66&arg2=dst&arg3=*981 completed,
returning 0
[2011-02-08 11:21:40]  Extension Changed 6010[default-local] new state
Idle for Notify User 6010 
[2011-02-08 11:21:40]  Extension Changed 6010[default-local] new state
Idle for Notify User 6002 
[2011-02-08 11:21:40]  Extension Changed 6010[default-local] new state
Idle for Notify User 6001 
lab*CLI> 
Disconnected from Asterisk server
[Feb  8 11:21:41] Executing last minute cleanups
Asterisk ending (0).
[root at lab INBOX]# dir
msg0000.txt  msg0000.WAV  msg0001.txt  msg0001.WAV 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2011-02-08 11:13 aragon         Note Added: 0131678                          
======================================================================




More information about the asterisk-bugs mailing list