Voicemail 'mailcmd' string being ingnored?

Hi,
I’ve just recently installed FreePBX. I’ve had success configuring Postfix such that FreePBX has no problem sending root notifications and voicemail alerts to users. However, I’m having no luck applying modifications to the outbound voicemail emails by using the ‘mailcmd’ string in the configuration. (My hope is to be able to process HTML content and eventually integrate speech to text.) The system appears to be simply ignoring anything I put in the ‘mailcmd’ field. (Settings → Voicemail Admin → Settings → Email Config)

PBX Version: 15.0.23.25
PBX Distro: 12.7.8-2104-1.sng7
Asterisk Version: 18.3.0

Any help appreciated.

Michael Keen
Burr & Burton Academy
Manchester, VT

And what are you puttimg there?

Thanks, BlazeStudios, for responding. Here’s what’s in there:

/usr/local/bin/emailproc

This is the current contents of that file:

#!/bin/bash
#VALUE=$(cat)
#NEWVAL=$(sed 's/Content-Type: text\/plain/Content-Type: text\/html/g' <<< "$VALUE")
#echo "$NEWVAL" > out.put
#echo "$VALUE" | /usr/local/bin/sttparse | /usr/sbin/sendmail -t -v
echo "Subject: sendmail test" | sendmail -v [email protected]

As you can see, all but the last line is commented out. I would think that last line should send me an test email regardless of what voicemail box is called or what message is left, but we simply get the standard VM email.

What happens when you parse the contents of the email? Sounds like the email content is overriding your echo statement because you’re just calling on sendmail, which is the default already being used.

I had a rough time with trying to do all this via mailcmd, so I wrote something that uses the externalnotify setting that fires a script and on a new message, it grabs the last message left in the inbox sends it off to get transcribed, converts the wav to mp3, builds the email notice with the transcript in the body and the mp3 as the attachment and will also delete the voicemail in the system.

This, of course, overrides what is in the Voicemail section of the GUI for an extension since you can’t add an email there (stops the voicemail app from sending its own email) and you can’t delete=yes because it will delete the message before the external script. I had to create a voicemail user backend for this but it gives me more flexibility.

I did this with a php script rather than bash. Adding voicemail transcription with Azure Cognitive Services - Speech Service

Asterisk just expects to be able to dump a full email message (complete with base64 attachment) into the STDIN of whatever you specify for mailcmd.

I can’t help with your bash script but maybe something from the simple php script I wrote will help you move ahead.

1 Like

Bill, I am so much more comfortable with PHP than I am with Bash. If you would be so kind as to share your PHP script, I’d appreciate it.

Edit: I didn’t notice the link. I will give that a try on Monday. Thanks so much.

Hi again, Bill.

I tried your PHP solution. I still feel like the mailcmd parameter is just being ignored. I added this line to the top of your php script:

> file_put_contents('out.txt','Running');

No such file was created, and the voicemail email arrived with {TRANSCIPTION} and most other tokens unchanged.
The email just arrived like this:

Michael Keen,

There is a new voicemail in mailbox 100:

From (Name): ${VM_CIDNAME}
From (Number): ${VM_CIDNUM}
Length: 9 seconds
Date: Wed Oct 5 05:07:08 PM UTC 2022
Transcription: {TRANSCRIPTION}

Dial *98 to access your voicemail by phone.

Any ideas?

Verify that mailcmd=... is in the /etc/asterisk/voicemail.conf file and that the command listed is executable by the asterisk user. There might be a clue in /var/log/asterisk/full. If not you can try increasing the debug level for voicemail.

I can confirm that the voicemail.conf file matches the command in the FreePBX gui. The PHP file now has 777 (full permissions). The asterisk log had nothing useful. I will try increasing the debug level next.

Use core set debug 10 app_voicemail.so

[2022-10-10 15:18:59] DEBUG[2665] app_voicemail.c: Queueing event for mailbox [email protected] New: 19 Old: 0
[2022-10-10 15:18:59] DEBUG[2665] app_voicemail.c: Found alias mapping: [email protected][email protected]

There is going to be way more than that. It’s going to show the mailcmd and any emails to send notices to along with if the voicemail should be deleted afterwards.

You need execute permission on the whole directory path as well. Also world write on a script (or any directory leading to it - special rules apply to /tmp or other directories marked as sticky) is a privilege escalation vulnerability. Some programs will actually check the whole path for write permission to other than root and the user using the file, and fault if it is found, although I suspect that is not the case here.

Here’s where we are now with permissions…

[[email protected] local]# ls /usr/local/bin/. -l
total 24
-rwxrwxrwx 1 root     root      270 Oct  6 09:31 emailproc
-rwxrwxrwx 1 root     root     8076 Sep 30 14:42 pnp_server
-rwxrwxrwx 1 root     root     6859 Oct  5 14:35 sttparse
-rwxrwxrwx 1 asterisk asterisk 1610 Oct 10 10:34 transcribe.php
[[email protected] local]# 
[[email protected] local]# pwd
/usr/local
[[email protected] local]# 
[[email protected] local]# ls -l
total 0
drwxr-xr-x. 3 asterisk asterisk 38 Oct  1 05:36 asterisk
drwxrwxrwx. 2 asterisk asterisk 79 Oct 10 13:33 bin

I realize it’s too loose at the moment; I was trying to eliminate permissions as a possibility. Please let. me know what problems you see there.

I also just issued this command…

php transcribe.php

That command successfully writes the “out.txt” file in response to the

file_put_contents(‘out.txt’,‘Running’);

which I’ve added to the PHP file.


This is all I get in the log…

tail /var/log/asterisk/full
[2022-10-10 13:30:10] VERBOSE[2542] asterisk.c: Remote UNIX connection
[2022-10-10 13:30:10] VERBOSE[29852] asterisk.c: Remote UNIX connection disconnected
[2022-10-10 13:30:10] VERBOSE[2542] asterisk.c: Remote UNIX connection
[2022-10-10 13:30:10] VERBOSE[29854] asterisk.c: Remote UNIX connection disconnected
[2022-10-10 13:30:10] VERBOSE[2542] asterisk.c: Remote UNIX connection
[2022-10-10 13:30:10] VERBOSE[29856] asterisk.c: Remote UNIX connection disconnected
[2022-10-10 15:18:59] DEBUG[2665] app_voicemail.c: Queueing event for mailbox [email protected]  New: 19   Old: 0
[2022-10-10 15:18:59] DEBUG[2665] app_voicemail.c: Found alias mapping: [email protected] -> [email protected]
[2022-10-10 15:41:39] DEBUG[2665] app_voicemail.c: Queueing event for mailbox [email protected]  New: 20   Old: 0
[2022-10-10 15:41:39] DEBUG[2665] app_voicemail.c: Found alias mapping: [email protected] -> [email protected]

You have to turn it on and then leave a voicemail. You’ll see things like this:

[2022-10-10 20:05:44.825] DEBUG[10351][C-0007e671]: app_voicemail.c:6768 leave_voicemail: Before find_user
[2022-10-10 20:05:44.825] DEBUG[10351][C-0007e671]: app_voicemail.c:6890 leave_voicemail: /var/spool/asterisk/voicemail/amioffice/1504/busy doesn't exist, doing what we can
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[17] = 1, count = 1
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[12] = 1, count = 2
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[11] = 1, count = 3
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[22] = 1, count = 4
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[8] = 1, count = 5
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[19] = 1, count = 6
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[15] = 1, count = 7
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[13] = 1, count = 8
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[14] = 1, count = 9
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[7] = 1, count = 10
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[16] = 1, count = 11
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[18] = 1, count = 12
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[20] = 1, count = 13
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[23] = 1, count = 14
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[10] = 1, count = 15
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:4697 last_message_index: /var/spool/asterisk/voicemail/amioffice/1504/INBOX map[9] = 1, count = 16
[2022-10-10 20:06:08.982] DEBUG[10351][C-0007e671]: app_voicemail.c:5652 sendmail: Attaching file '/var/spool/asterisk/voicemail/amioffice/1504/INBOX/msg0024', format 'wav', uservm is '0', global is 2048
[2022-10-10 20:06:09.076] DEBUG[10351][C-0007e671]: app_voicemail.c:5663 sendmail: Sent mail to [email protected] with command '/usr/sbin/sendmail -t'
[2022-10-10 20:06:09.076] DEBUG[10351][C-0007e671]: app_voicemail.c:8212 queue_mwi_event: Queueing event for mailbox [email protected]  New: 17   Old: 4
[2022-10-10 20:06:09.077] DEBUG[10351][C-0007e671]: app_voicemail.c:6370 run_externnotify: Executing /var/lib/cvn/voicemail_notify.php amioffice 1504 17 4 0 &

Hi Tom,
You are correct. I didn’t actually leave a voicemail; rather, I was forwarding a prior voicemail to myself which also triggers the email.
Here is the log from an actual new voicemail…

[[email protected] bin]# tail /var/log/asterisk/full -n50
[2022-10-11 13:09:07] VERBOSE[1059][C-00004c39] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)
[2022-10-11 13:09:07] VERBOSE[1059][C-00004c39] pbx.c: Executing [[email protected]:300] NoOp("PJSIP/110-00004c41", "") in new stack
[2022-10-11 13:09:07] VERBOSE[1059][C-00004c39] pbx.c: Executing [[email protected]:2] VoiceMail("PJSIP/110-00004c41", "[email protected],u") in new stack
[2022-10-11 13:09:08] DEBUG[1059][C-00004c39] app_voicemail.c: Before find_user
[2022-10-11 13:09:08] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/unavail doesn't exist, doing what we can
[2022-10-11 13:09:08] VERBOSE[1059][C-00004c39] file.c: <PJSIP/110-00004c41> Playing 'vm-theperson.ulaw' (language 'en')
[2022-10-11 13:09:10] VERBOSE[1059][C-00004c39] file.c: <PJSIP/110-00004c41> Playing 'digits/1.ulaw' (language 'en')
[2022-10-11 13:09:11] VERBOSE[1059][C-00004c39] file.c: <PJSIP/110-00004c41> Playing 'digits/0.ulaw' (language 'en')
[2022-10-11 13:09:11] VERBOSE[1059][C-00004c39] file.c: <PJSIP/110-00004c41> Playing 'digits/0.ulaw' (language 'en')
[2022-10-11 13:09:12] VERBOSE[1059][C-00004c39] file.c: <PJSIP/110-00004c41> Playing 'vm-isunavail.ulaw' (language 'en')
[2022-10-11 13:09:14] VERBOSE[1059][C-00004c39] file.c: <PJSIP/110-00004c41> Playing 'vm-intro.ulaw' (language 'en')
[2022-10-11 13:09:19] VERBOSE[1059][C-00004c39] file.c: <PJSIP/110-00004c41> Playing 'beep.ulaw' (language 'en')
[2022-10-11 13:09:20] VERBOSE[1059][C-00004c39] app_voicemail.c: Recording the message
[2022-10-11 13:09:20] VERBOSE[1059][C-00004c39] app.c: x=0, open writing:  /var/spool/asterisk/voicemail/default/100/tmp/pYq2E0 format: wav, 0x7f6c10006370
[2022-10-11 13:09:26] VERBOSE[1059][C-00004c39] app.c: User hung up
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[10] = 1, count = 1
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[11] = 1, count = 2
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[12] = 1, count = 3
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[16] = 1, count = 4
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[17] = 1, count = 5
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[0] = 1, count = 6
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[1] = 1, count = 7
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[2] = 1, count = 8
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[3] = 1, count = 9
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[4] = 1, count = 10
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[5] = 1, count = 11
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[6] = 1, count = 12
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[7] = 1, count = 13
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[8] = 1, count = 14
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[9] = 1, count = 15
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[13] = 1, count = 16
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[14] = 1, count = 17
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[15] = 1, count = 18
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[18] = 1, count = 19
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: /var/spool/asterisk/voicemail/default/100/INBOX map[19] = 1, count = 20
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: Attaching file '/var/spool/asterisk/voicemail/default/100/INBOX/msg0020', format 'wav', uservm is '2048', global is 2048
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: creating attachment filename msg0020.wav, no second attachment.
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: Sent mail to [email protected] with command '/usr/local/bin/transcribe.php'
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: Queueing event for mailbox [email protected]  New: 21   Old: 0
[2022-10-11 13:09:26] DEBUG[1059][C-00004c39] app_voicemail.c: Found alias mapping: [email protected] -> [email protected]
[2022-10-11 13:09:26] VERBOSE[1059][C-00004c39] app_macro.c: Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'PJSIP/110-00004c41' in macro 'vm'
[2022-10-11 13:09:26] VERBOSE[1059][C-00004c39] app_macro.c: Spawn extension (macro-exten-vm, s, 45) exited non-zero on 'PJSIP/110-00004c41' in macro 'exten-vm'
[2022-10-11 13:09:26] VERBOSE[1059][C-00004c39] pbx.c: Spawn extension (ext-local, 100, 3) exited non-zero on 'PJSIP/110-00004c41'
[2022-10-11 13:09:26] VERBOSE[1059][C-00004c39] pbx.c: Executing [[email protected]:1] Macro("PJSIP/110-00004c41", "hangupcall,") in new stack
[2022-10-11 13:09:26] VERBOSE[1059][C-00004c39] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/110-00004c41", "1?theend") in new stack
[2022-10-11 13:09:26] VERBOSE[1059][C-00004c39] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2022-10-11 13:09:26] VERBOSE[1059][C-00004c39] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/110-00004c41", "0?Set(CDR(recordingfile)=)") in new stack
[2022-10-11 13:09:26] VERBOSE[1059][C-00004c39] pbx.c: Executing [[email protected]:4] Hangup("PJSIP/110-00004c41", "") in new stack
[2022-10-11 13:09:26] VERBOSE[1059][C-00004c39] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'PJSIP/110-00004c41' in macro 'hangupcall'
[2022-10-11 13:09:26] VERBOSE[1059][C-00004c39] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'PJSIP/110-00004c41'
[[email protected] bin]# 

MK

It says there that it is running your script… but it’s not? Are you sure? I noticed that in post 7 you had the token as {TRANSCRIPTION} but if you were using my script it’s parentheses, not curly braces: (TRANSCRIPTION)

I think the php script is running but is passing the email through unchanged to the sendmail -t at the bottom of the script.

Good catch on the parentheses vs. curly braces. I had started out with a different transcription script that used parentheses, and didn’t notice the difference with this script. The script actually seems to be running. That out.txt file I was expecting to see in the /usr/local/bin directory was actually being written to the /tmp directory.

I got as far as getting “No transcription availabile.” in my email which proves the script is actually running. (The word available is misspelled in the PHP code.)

Thanks so much for the guidance.

That’s one of my favorite typos. Fixed!