Digium phones can't play listed voicemail messages

Correct logs for a NEW message:

== Spawn extension (dpma_message_context, digium_phone_module, 7) exited non-zero on ‘Message/ast_msg_queue’
– Executing [[email protected]_message_context:1] Set(“Message/ast_msg_queue”, “MESSAGE(custom_data)=mark_all_outbound”) in new stack
– Executing [[email protected]_message_context:2] Set(“Message/ast_msg_queue”, “MESSAGE_DATA(X-Digium-AppServer-Response-URI)=sip:10.0.0.51:5060”) in new stack
– Executing [[email protected]_message_context:3] Set(“Message/ast_msg_queue”, “MESSAGE_DATA(X-Digium-AppServer-Response-FullContact)=sip:10.0.0.51:5060;ob”) in new stack
– Executing [[email protected]_message_context:4] MessageSend(“Message/ast_msg_queue”, “digium_phone:blah”) in new stack
– Executing [[email protected]_message_context:5] Hangup(“Message/ast_msg_queue”, “”) in new stack
== Spawn extension (dpma_message_context, proxy, 5) exited non-zero on ‘Message/ast_msg_queue’
== Parsing ‘/var/spool/asterisk/voicemail/default/201/INBOX/msg0000.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/INBOX/msg0001.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/INBOX/msg0002.txt’: Found
– Executing [[email protected]_message_context:1] Set(“Message/ast_msg_queue”, “MESSAGE(custom_data)=mark_all_outbound”) in new stack
– Executing [[email protected]_message_context:2] Set(“Message/ast_msg_queue”, “TMP_RESPONSE_URI=sip:10.0.0.51:5060”) in new stack
– Executing [[email protected]_message_context:3] Set(“Message/ast_msg_queue”, “MESSAGE_DATA(Request-URI)=sip:10.0.0.51:5060;ob”) in new stack
– Executing [[email protected]_message_context:4] Set(“Message/ast_msg_queue”, “MESSAGE_DATA(X-Digium-AppServer-Response-URI)=”) in new stack
– Executing [[email protected]_message_context:5] Set(“Message/ast_msg_queue”, “MESSAGE_DATA(X-Digium-AppServer-Response-FullContact)=”) in new stack
– Executing [[email protected]_message_context:6] MessageSend(“Message/ast_msg_queue”, “sip:10.0.0.51:5060,proxy”) in new stack
– Executing [[email protected]_message_context:7] Hangup(“Message/ast_msg_queue”, “”) in new stack
== Spawn extension (dpma_message_context, digium_phone_module, 7) exited non-zero on ‘Message/ast_msg_queue’

Log from checking OLD messages

– Executing [[email protected]_message_context:1] Set(“Message/ast_msg_queue”, “MESSAGE(custom_data)=mark_all_outbound”) in new stack
– Executing [[email protected]_message_context:2] Set(“Message/ast_msg_queue”, “TMP_RESPONSE_URI=sip:10.0.0.51:5060”) in new stack
– Executing [[email protected]_message_context:3] Set(“Message/ast_msg_queue”, “MESSAGE_DATA(Request-URI)=sip:10.0.0.51:5060;ob”) in new stack
– Executing [[email protected]_message_context:4] Set(“Message/ast_msg_queue”, “MESSAGE_DATA(X-Digium-AppServer-Response-URI)=”) in new stack
– Executing [[email protected]_message_context:5] Set(“Message/ast_msg_queue”, “MESSAGE_DATA(X-Digium-AppServer-Response-FullContact)=”) in new stack
– Executing [[email protected]_message_context:6] MessageSend(“Message/ast_msg_queue”, “sip:10.0.0.51:5060,proxy”) in new stack
– Executing [[email protected]_message_context:7] Hangup(“Message/ast_msg_queue”, “”) in new stack
== Spawn extension (dpma_message_context, digium_phone_module, 7) exited non-zero on ‘Message/ast_msg_queue’
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
== Extension Changed auto_hint_201[from-internal] new state Ringing for Notify User 201
== Extension Changed auto_hint_201[from-internal] new state Ringing for Notify User 202
== Extension Changed auto_hint_201[from-internal] new state Ringing for Notify User 203
> 0x7f86fc06d970 – Probation passed - setting RTP source address to 10.0.0.51:4050
> Channel SIP/201-00000075 was answered.
== Extension Changed auto_hint_201[from-internal] new state InUse for Notify User 201
> Launching DigiumVoicemailPlayback([email protected],Old,1415126694-00000062) on SIP/201-00000075
== Extension Changed auto_hint_201[from-internal] new state InUse for Notify User 202
== Extension Changed auto_hint_201[from-internal] new state InUse for Notify User 203
== Parsing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0000.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0001.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0002.txt’: Found
(truncated for posting purposes)
== Parsing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0091.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0092.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0092.txt’: Found
– <SIP/201-00000075> Playing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0092.slin’ (language ‘en’)
> 0x7f86fc06d970 – Probation passed - setting RTP source address to 10.0.0.51:4050
== Extension Changed auto_hint_201[from-internal] new state Idle for Notify User 201
== Extension Changed auto_hint_201[from-internal] new state Idle for Notify User 202
== Extension Changed auto_hint_201[from-internal] new state Idle for Notify User 203
– Executing [[email protected]_message_context:1] Set(“Message/ast_msg_queue”, “MESSAGE(custom_data)=mark_all_outbound”) in new stack
– Executing [[email protected]_message_context:2] Set(“Message/ast_msg_queue”, “MESSAGE_DATA(X-Digium-AppServer-Response-URI)=sip:10.0.0.51:5060”) in new stack
– Executing [[email protected]_message_context:3] Set(“Message/ast_msg_queue”, “MESSAGE_DATA(X-Digium-AppServer-Response-FullContact)=sip:10.0.0.51:5060;ob”) in new stack
– Executing [[email protected]_message_context:4] MessageSend(“Message/ast_msg_queue”, “digium_phone:blah”) in new stack
– Executing [[email protected]_message_context:5] Hangup(“Message/ast_msg_queue”, “”) in new stack
== Spawn extension (dpma_message_context, proxy, 5) exited non-zero on ‘Message/ast_msg_queue’
== Parsing ‘/var/spool/asterisk/voicemail/default/201/INBOX/msg0000.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/INBOX/msg0001.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/INBOX/msg0002.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0000.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0001.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0002.txt’: Found
(truncated for posting purposes)
== Parsing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0097.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0098.txt’: Found
== Parsing ‘/var/spool/asterisk/voicemail/default/201/Old/msg0099.txt’: Found

Ok, did a *98 + extension + password and played new mail. Also did a *97 + password and played new mail no problem.

Can you go over for me the exact sequence, make sure I have this correct:

  1. new message is left for extension
  2. extension’s new message light is on
  3. press messages button
  4. see new message on screen, use arrows if needed to select it, press play softkey
    … then what?

Does the error message show immediately, or is there a delay? Do you have to press anything else that I missed?

How frequently does it occur - i.e. just occasionally, about half the time, nearly all the time?

Is there any other symptoms - long delays, having to press a button twice, sometimes the phone responds differently than normal even though you don’t see an error message, etc.?

Correct, then the error pops up immediately (see attached pic)

it occurs every time, on all phones (all Digium D40’s)

UPDATE:

I’ve been working with Digium tech support and they have been able to reproduce similar behavior in the lab, but not exact. They have ssh access to the FreePBX box and have done some debug logging this morning. I’ll post more as I get information from them. They also confirmed I’m not the only FreePBX user having this issue with digium phones. They have at least one other report in the last few days.

From digium:

Jeff,

Due to this issue being considered a bug, it is now being investigated by our development group. As of yet, there is no an ETA for a fix, however the case linked to an open engineering ticket. I will be working with you in regards to this development ticket, when information is requested, or testing is required. As this migration has taken place, I will be closing the support case.

This action is being taken to ensure support can focus exclusively on open, actionable cases. You will be updated regarding your issue no less than once per month until the issue is resolved by our development team. So once again, while your support issue is being closed your issue will remain open in our development system and it will be closely monitored. You will automatically receive notification the day a fix is available for download. Thank you for bringing this issue to our attention and all your help diagnosing and troubleshooting. If you have any additional questions please just reply to this email.

I have recently reported the same issue to digium. I’ve experienced it on multiple installs of freepbx distro… It seems to pop up on different extensions periodically then a day or two later begins to work correctly… I’ve tried updating the phone firmware, dpma to 2.1.1, and reconfiguring the phone. Waiting to see if digium can pinpoint the issue.

The tech I worked with an reported it to seemed to indicate that they have pinpointed the problem and it turned it over to a bug report. There’s no ETA currently for the bug fix but they are aware of it and it is officially entered as a bug in the DPMA software.

Good day
I was battling with this problem again this morning and found that there were too many messages under new. Once I deleted some, it worked again. Not sure if this will help anyone else.