[Home]

Summary:ASTERISK-24463: Voicemail email address corrupt or not sent when message is in the process of being recorded during reload
Reporter:John Campbell (Sc00by)Labels:
Date Opened:2014-10-28 03:31:45Date Closed:2016-05-04 16:09:10
Priority:CriticalRegression?
Status:Closed/CompleteComponents:Applications/app_voicemail
Versions:11.14.1 Frequency of
Occurrence
Related
Issues:
Environment:FreePBX 2.11 Platform 64-bit running Asterisk 11.13.1Attachments:( 0) AST-24463.patch
( 1) Failed_email
( 2) How_to_Replicate_off_ISO.txt
( 3) myDebugLog
( 4) Successful
( 5) voicemail.conf
Description:I have been testing a custom script today which has involved a lot of reloads and came across the following situation (the script I have been testing has nothing to do with email or anything that would affect the below):

When someone is in the process of leaving a voicemail and Asterisk is reloaded when they hang up after the reload the email that it generated has a corrupt To: field or not sent at all.

The Postfix log contains the corrupt address which is direct from Asterisk and looks similar to this:

to=<P??$3?@mydomain.com>

Running deliberate tests here just now has not yielded the corrupt To address but I have found that it does not send the email at all. After a reload when the person hangs up asterisk ends with 'User hung up' and no email is generated.

UPDATE - Messages that I thought were not sent (from my test above) were (however still not all) but they went to the wrong email address (still valid on the system)! - This is starting to get a bit more critical now if personal messages are starting to go to random addresses.
Comments:By: Matt Jordan (mjordan) 2014-10-28 11:35:07.569-0500

We require a complete debug log to help triage the issue. This document will provide instructions on how to collect debugging logs from an Asterisk machine for the purpose of helping bug marshals troubleshoot an issue: https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information


By: John Campbell (Sc00by) 2014-10-28 15:44:10.557-0500

Debug attached.

This was calling from one phone to another and letting it time out to voicemail.  While message was being recorded I reloaded asterisk.  On hanging up, voicemail is available via *97 and the LED blinks on the phone but no email is sent.

The trend is either no email, email TO: corrupt or it's sent to the wrong address.

By: John Campbell (Sc00by) 2014-11-02 16:36:53.924-0600

Is there any movement with this as I'm finding it quite critical due to a new system install. Over 500 ext and lots of reloads is causing private voicemails to go to the wrong people or not at all
By: Rusty Newton (rnewton) 2014-11-05 15:02:38.376-0600

[~Sc00by] I don't see that anyone has started working this issue yet. Anyone who is working on this issue should make an update to the issue status or comments which you would see here.

If you can't provide a patch yourself. You may want to pique the interest of developers in the issue by posting a [bounty on the Asterisk-dev mailing list|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Bug+Bounties].

Can you post debug logs demonstrating your other failure scenarios? From what I understand you have posted a log showing an example where an E-mail fails to send, but not when the TO is corrupt or it is sent to the wrong address.
By: John Campbell (Sc00by) 2014-11-07 13:38:26.474-0600

I have added another two debug's

One is a successful voicemail - No Reload done, all is well and does what it is supposed to.

The other is another failed email.  This was a call to a mailbox and when the message starts to record I reloaded asterisk.  Hanging up generated an email with the following TO: address

[2014-11-07 18:58:39] DEBUG[45481][C-000021f0] app_voicemail.c: Sent mail to CSS_SETUP=TRUE) with command '/usr/sbin/sendmail -t'

Postfix Log:
<CSS_SETUP=TRUE)@mydomain.org.uk>
By: John Campbell (Sc00by) 2014-12-03 09:26:11.413-0600

I've just finished building a test setup consisting of an old server with an image of our live backup with a couple of phones.  I updated it to 11.14.1 and the problem is still there.
By: Rusty Newton (rnewton) 2014-12-18 09:41:34.306-0600

{quote}
The other is another failed email. This was a call to a mailbox and when the message starts to record I reloaded asterisk. Hanging up generated an email with the following TO: address
{quote}

I've tried reproducing this in the latest SVN of Asterisk 11(SVN-branch-11-r428417), but I can't get it to occur. I basically call a voicemail box and while recording I reload asterisk ('reload' from the CLI). Out of a few dozen attempts, the E-mail address is always correct.

I even tried crazy things like reloading a few dozen times during one recording.

Can you attach your voicemail.conf and related config files?

How many test calls with a reload does it take to finally get a failure?

What sort of config changes have been made before the reload?
By: Rusty Newton (rnewton) 2014-12-18 10:04:38.984-0600

Same results (unable to reproduce) in 11.13.1.
By: John Campbell (Sc00by) 2014-12-18 11:16:21.434-0600

I have just replicated it again by calling a mailbox and issuing 'core reload' from the CLI this time

When hanging up it attempted to email :

zI$3?@mydomain.com

As mentioned before, I'm running the FreePBX platform 2.11 with all updates on Asterisk 11.13.1

No config changes were done, just a simple reload while recording.

I have attached my voicemail.conf (email addresses edited).  What other files would you like?

I can replicate this every single time, guaranteed.

What's also the best way to upload these privately, I did set private on the above debugs but I can still download and view them while logged out of this system! - Which is not very private.

By: John Campbell (Sc00by) 2014-12-19 05:33:18.839-0600

Got an update on the situation.

I have found that when deleting vm_email.inc the email is sent perfect every time however restarting asterisk stops the voicemail module loading with this file missing.

What makes it even more wierd is having this file there but empty produces the fault.  

The only way I can get it to work is to start Asterisk with everything as it should be then rename vm_email.inc to something else, it will then work fine.  The file would then need to be renamed back for an asterisk or server restart

If I take the include out of voicemail.conf makes no difference.  If i move emailBody to voicemail.conf makes no difference, the only fix so far is to rename the .inc
By: Matt Jordan (mjordan) 2014-12-19 07:31:24.355-0600

What is {{vm_email.inc}}? And why would you manipulate it externally, outside of both Asterisk and FreePBX?
By: John Campbell (Sc00by) 2014-12-19 07:33:55.627-0600

vm_email.inc is what FreePBX uses to add the emailBody.  It's listed as an include in voicemail.conf

I don't manipulate is externally, it's all done via the GUI however in my new wave is experiments this morning I found that renaming this file after asterisk has started fixes my problem (until asterisk restarts, it fails to load the voicemail due to the missing file)
By: Matt Jordan (mjordan) 2014-12-19 09:42:02.500-0600

I don't think this is a bug in Asterisk then.

# If you provide Asterisk with missing configuration files, then it will have issues. Not loading {{app_voicemail}} is actually the correct thing to do in that situation.
# If you provide Asterisk with a bad configuration file, then it will have issues. Not knowing the contents of {{vm_email.inc}}, I'm not sure what the issue is inside of it - however, if it includes characters that Asterisk can't handle (ASCII only; {{app_voicemail}} can't handle Unicode) or other such things, then I'm not surprised this would occur.
# If you tamper with the configuration files during a reload operation, then you will probably run into problems. That isn't a bug; you shouldn't be manipulating the configuration files while Asterisk is trying to load them into memory.

As it is, I'm not sure how the situation you're facing is anything we can or would attempt to fix in Asterisk.
By: John Campbell (Sc00by) 2014-12-22 10:54:52.389-0600

I have put this back to freepbx who have said its an Asterisk issue

I have managed to replicate on a clean off the ISO install - see info on the ticket (below) plus their comments.  I dont think I have explained myself correctly but perhaps the attached document can shed clearer light on what I am trying to get across.

http://issues.freepbx.org/browse/FREEPBX-8176

Can this ticket be reopened and examined please?
By: John Campbell (Sc00by) 2014-12-22 14:35:04.866-0600

I would add that removing the include for vm_email.inc does not solve the problem so it has nothing to do with that file.  There is no corruption.

I have tested it with Asterisk 12 and cannot replicate, if i move back to 11 I can replicate it every time.  I don't want to move to 12 as 11 is the LTS and for production use

I can also replicate with the latest AsteriskNOW install following the same procedure as my attached txt
By: Matt Jordan (mjordan) 2014-12-23 09:48:17.602-0600

I'm reopening, but you *must* provide all of the information to reproduce this on a clean Asterisk system. That includes:
* All configuration files
* All scripts involved in the process
* Explicit steps to perform that cause the issue you are seeing

If we can't reproduce this, it will be closed out again.
By: John Campbell (Sc00by) 2014-12-23 11:14:38.376-0600

Thank you for re-opening!

By clean do you mean a freshly compiled asterisk from source (which I have never done before) or through a distro?

I can replicate it every time with the FreePBX and AsteriskNOW distros (on Asterisk 1.8 and 11, I can't replicate on 12 using the same distros) but have never compiled Asterisk from scratch before, I wouldn't know where to start.
By: Schmooze Com (schmoozecom) 2014-12-23 12:08:44.629-0600

Guys

The line that I think causes the issue is this.
{noformat}
emailbody = ${VM_NAME},\n\nThere is a new voicemail in mailbox ${VM_MAILBOX}:\n\n\tFrom:\t${VM_CALLERID}\n\tLength:\t${VM_DUR} seconds\n\tDate:\t${VM_DATE}\n\nDial *98 to access your voicemail by phone.\n
{noformat}

We put that in the vm_email.inc  file which voicemail.conf includes.

If you call into your system and leave a VM at the same time of leaving at VM do a core reload and the email will usually mess up the to address.
By: Matt Jordan (mjordan) 2014-12-23 12:45:01.838-0600

[~schmoozecom]: Thanks for the information. With the previous attachments/logs, that should be enough information for a developer to look at the issue.
By: Martial Brochu (martialb) 2016-03-02 13:33:33.042-0600

we are running Xivo 16.02 with Asterisk 13.7.2 and we have the same problem. We can reproduce the problem with the same steps and we need to have assistance! We had emails that were sent to valid but wrong addresses and other emails sent to bad addresses.

Mar  2 13:48:31 server postfix/pickup[9346]: 6F591802047: uid=105 from=<asterisk>
Mar  2 13:48:31 server postfix/cleanup[9372]: 6F591802047: message-id=<Asterisk-25-2016508479-5920-25540@server>
Mar  2 13:48:31 server postfix/qmgr[8898]: 6F591802047: from=<asterisk@server.domain.com>, size=182483, nrcpt=1 (queue active)
Mar  2 13:48:31 server postfix/error[9374]: 6F591802047: to=<8V@?P????>, relay=none, delay=0.05, delays=0.05/0/0/0.01, dsn=5.1.3, status=bounced (bad address syntax)
Mar  2 13:48:31 server postfix/bounce[9375]: 6F591802047: sender non-delivery notification: 72E1C80204C
Mar  2 13:48:31 server postfix/qmgr[8898]: 6F591802047: removed

By: John Campbell (Sc00by) 2016-03-02 13:57:30.799-0600

I am so glad someone else is having this issue as when i first raised this no-one could replicate.  I had given up on this ticket as it's well over a year now since I raised it and I'm still having the problem on my system.  I've just got into a routine to check if a VM is being left before i reload!
By: Etienne Lessard (hexanol) 2016-03-04 11:07:50.828-0600

Hello,

I've taken a look at the problem, and here's what I found.

The problem comes from the fact that on "voicemail reload" / "module reload app_voicemail", the list of all VM users (struct ast_vm_user) from the "users" AST_LIST are freed. These struct contains pointers to dynamically allocated memory to hold the email, emailbody and emailsubject. When a message is being leaved in a voicemail, app_voicemail creates a copy of the struct from the list onto the thread's stack (via the find_user function), but it doesn't copy the dynamically allocated part of the struct, e.g. email. So if a reload happens when someone is leaving a message, then the copy's email pointer points to memory that has been freed, which could cause really a lot of problem, but in this case seems to mostly yield garbage.

A simple solution is to always create a copy of email / emailbody / emailsubject in the find_user function, and always free them when the struct is freed (they shouldn't be shared, so I believe it's safe to free them inconditionally, even though I'm not 100% sure). I'm attaching a small patch that fix the issue. I've only tested it on a really simple setup (i.e. voicemail configuration not stored in realtime, no IMAP storage or whatever). It probably works fine for these cases too, but I've not tested it.

I've done my patch/test on Asterisk 13.7.2.
By: Andrew Nagy (tm1000) 2016-03-16 17:14:14.438-0500

[~hexanol]

Did you sign the digium contributor agreement? *IF* so I'd like to get this pushed though and will make the appropriate commits to gerrit. Just need to verify you signed the agreement.
By: Etienne Lessard (hexanol) 2016-03-17 06:47:18.443-0500

Yes I did sign it.

Thanks.
By: Andrew Nagy (tm1000) 2016-04-20 16:10:49.394-0500

Work was attempted here: https://gerrit.asterisk.org/#/c/2433/5

Joshua and Richard and I both tried to get it to work but with lots of memory leaks. We tried to cleanup the memory leaks but ran into pointer issues. If anyone wants to provide more input please apply patches or changes to gerrit above.
By: Andrew Nagy (tm1000) 2016-05-04 16:01:10.696-0500

Work has been completed: https://github.com/asterisk/asterisk/commit/b5223a8cfc9f57a7cd12918aa84a1cceb61ea653