[Home]

Summary:ASTERISK-05555: [patch] app_voicemail fails when copying to multiple mailboxes
Reporter:Chris Hozian (chozian)Labels:
Date Opened:2005-11-10 11:21:40.000-0600Date Closed:2008-01-15 15:55:52.000-0600
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Applications/app_voicemail
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) copy_message.patch
Description:Receive "Failed to lock path '': File exists" when app_voicemail attempts to copy to multiple mailboxes.  Voicemail does not get successfully get copied to any mailbox other than the first one specified.

****** ADDITIONAL INFORMATION ******

The number of mailboxes specified did not seem to change the behavior.  The first attempt worked fine.  It never worked properly afterwards.

----

Asterisk CLI Output:

   -- Accepted AUTHENTICATED TBD call from 192.168.254.4
   -- Accepting DIAL from 192.168.254.4, formats = 0x4
   -- Executing VoiceMail("IAX2/testiaxy-5", "1003&1004&1005") in new stack
Nov 10 11:18:32 DEBUG[12367]: channel.c:769 channel_find_locked: Avoiding initial deadlock for 'IAX2/testiaxy-5'
Nov 10 11:18:32 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-intro' (language 'en')
Nov 10 11:18:32 DEBUG[12374]: chan_iax2.c:6647 socket_read: Ooh, voice format changed to 4
Nov 10 11:18:37 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov 10 11:18:37 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov 10 11:18:37 DEBUG[12555]: app.c:1175 ast_lock_path: Locked path '/var/spool/asterisk/voicemail/default/1003/INBOX'
Nov 10 11:18:37 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'beep' (language 'en')
Nov 10 11:18:38 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov 10 11:18:38 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Recording the message
Nov 10 11:18:38 DEBUG[12555]: app.c:577 ast_play_and_record: play_and_record: <None>, /var/spool/asterisk/voicemail/default/1003/INBOX/msg0000, 'wav49|gsm'
Nov 10 11:18:38 DEBUG[12555]: app.c:594 ast_play_and_record: Recording Formats: sfmts=wav49
   -- x=0, open writing:  /var/spool/asterisk/voicemail/default/1003/INBOX/msg0000 format: wav49, 0x81bbf08
   -- x=1, open writing:  /var/spool/asterisk/voicemail/default/1003/INBOX/msg0000 format: gsm, 0x82120d0
Nov 10 11:18:38 DEBUG[12555]: app.c:1187 ast_unlock_path: Unlocked path '/var/spool/asterisk/voicemail/default/1003/INBOX'
   -- User ended message by pressing #
Nov 10 11:18:42 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'auth-thankyou' (language 'en')
Nov 10 11:18:43 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov 10 11:18:43 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov 10 11:18:43 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-review' (language 'en')
Nov 10 11:18:50 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
   -- Saving message as is
Nov 10 11:18:50 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 160 sample intervals
   -- Playing 'vm-msgsaved' (language 'en')
Nov 10 11:18:52 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov 10 11:18:52 DEBUG[12555]: channel.c:1695 ast_settimeout: Scheduling timer at 0 sample intervals
Nov 10 11:18:52 NOTICE[12555]: app_voicemail.c:2283 copy_message: Copying message from 1003@default to 1004@default
Nov 10 11:18:53 DEBUG[12374]: chan_iax2.c:6938 socket_read: Immediately destroying 5, having received hangup
Nov 10 11:18:57 WARNING[12555]: app.c:1171 ast_lock_path: Failed to lock path '': File exists
Nov 10 11:18:57 NOTICE[12555]: app_voicemail.c:2283 copy_message: Copying message from 1003@default to 1005@default
Nov 10 11:19:02 WARNING[12555]: app.c:1171 ast_lock_path: Failed to lock path '': File exists
Nov 10 11:19:02 DEBUG[12555]: pbx.c:2348 __ast_pbx_run: Extension 3029, priority 1 returned normally even though call was hung up
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '"My IAXy" <1000>'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '1000'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '3029'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'from-internal'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'IAX2/testiaxy-5'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'VoiceMail'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '1003&1004&1005'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2005-11-10 11:18:32'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2005-11-10 11:18:32'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2005-11-10 11:19:02'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '30'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '30'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'ANSWERED'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '1131643112.1'
Nov 10 11:19:02 DEBUG[12555]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '(null)'
Nov 10 11:19:02 DEBUG[12555]: chan_iax2.c:3047 iax2_hangup: We're hanging up IAX2/testiaxy-5 now...
Nov 10 11:19:02 DEBUG[12555]: chan_iax2.c:3057 iax2_hangup: Really destroying IAX2/testiaxy-5 now...
   -- Hungup 'IAX2/testiaxy-5'


----

/etc/asterisk/voicemail.conf default section:

[default]
1003 => 9999,Test 1
1004 => 9999,Test 2
1005 => 9999,Test 3

----

/etc/asterisk/extensons.conf extension section:

exten => 3029,1,Voicemail(1003&1004&1005)

----

Contents of /var/spool/asterisk/voicemail/default:

1003/:
total 0
drwx------  3 root root  72 Nov 10 10:57 .
drwxr-xr-x  9 root root 216 Nov 10 10:58 ..
drwx------  2 root root 144 Nov 10 10:57 INBOX

1003/INBOX:
total 28K
drwx------  2 root root 144 Nov 10 10:57 .
drwx------  3 root root  72 Nov 10 10:57 ..
-rwx------  1 root root 12K Nov 10 10:57 msg0000.WAV
-rwx------  1 root root 12K Nov 10 10:57 msg0000.gsm
-rw-r--r--  1 root root 252 Nov 10 10:58 msg0000.txt

1004/:
total 0
drwx------  3 root root  72 Nov 10 10:58 .
drwxr-xr-x  9 root root 216 Nov 10 10:58 ..
drwx------  2 root root  48 Nov 10 10:58 INBOX

1004/INBOX:
total 0
drwx------  2 root root 48 Nov 10 10:58 .
drwx------  3 root root 72 Nov 10 10:58 ..

1005/:
total 0
drwx------  3 root root  72 Nov 10 10:58 .
drwxr-xr-x  9 root root 216 Nov 10 10:58 ..
drwx------  2 root root  48 Nov 10 10:58 INBOX

1005/INBOX:
total 0
drwx------  2 root root 48 Nov 10 10:58 .
drwx------  3 root root 72 Nov 10 10:58 ..
Comments:By: BJ Weschke (bweschke) 2005-11-11 21:45:49.000-0600

we were trying to lock a path that was supposed to be in a variable that was not yet initialized. patch attached to fix. disclaimer on file.
By: Kevin P. Fleming (kpfleming) 2005-11-11 21:48:53.000-0600

Committed to CVS HEAD, thanks!
By: Digium Subversion (svnbot) 2008-01-15 15:55:52.000-0600

Repository: asterisk
Revision: 7085

U   trunk/ChangeLog
U   trunk/apps/app_voicemail.c

------------------------------------------------------------------------
r7085 | kpfleming | 2008-01-15 15:55:51 -0600 (Tue, 15 Jan 2008) | 2 lines

issue ASTERISK-5555

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=7085