Voicemail cuts/swallows first words

Hey asterisk community,

could need some help in tracking down a voicemail issue.

I am running asterisk 11 and 13 on debian based boxes.
Both instances have a voicemail problem in common.

When dialing the mailbox to listen to recordings, the first few words are cut e.g.
"… … 1 messages!" Instead of “You have 1 messages”

This only happens the first time when the voicemail was not called for like 15-30 or more seconds.
If i dial it consecutively afterwards, always the full sound file is spoken. After waiting for a while again, the first response is messed up again.

Console gives “Playing ‘vm-youhave.gsm’ (language ‘us’)” without any further errors.(log/debug4)
Already tried inserting “Playback” and “Wait” but that does not change anything.

I further tried putting the whole voice-dirs into a ramdisk. To sort out delay by reading from storage device. No changes.
Other factors like RAM/CPU are far from utilized so i dont think that matters here.

Somehow it is like it needs a moment to cache/preload something, as its no problem on directly recurring retries. And later this is disposed again… which would cause it to reoccur after a while of voicemail-idle…

I also thought about this being RTP related somehow? But I think this should cause problems with the beginning of normal calls too. Which it does not.

I am NOT able to reproduce this when voicemail is played for outside calls, which are told to leave a message (the-person-at-extension…). No problems with the first words at all.

Any ideas how i could further track this down / reconfigure any settings?

Best Regards,
Tom

Uhm i just tried to capture a call where the first words are cut. Playing the capture-file also misses the words, so i would suspect the problem on the asterisk system itself. Otherwise i would have the complete message been send over the wire right?

Maybe the rtp ports are not open on the firewall, and while the first packets are exchanged, thus opening the return way, audio is lost

What is the output of “rtp set debug on” with a call attempt? That will show Asterisk receiving and sending media. If it takes a period of time to receive media then it is likely what @cerien.jean stated.

Hi, thanks for the input!

Here is a debug, where the client did not receive the first few words (stripped it down a bit).

Inbound client RTP packets before the Server plays its voicefiles. Using rfc3581 udp style should ensure the clients udp port is open right?

Will try and create a network capture on both, client and server as a next step

-- Registered SIP '2002' at 10.0.0.4:5060

== Using SIP RTP CoS mark 5
– Executing [2999@internal-og:1] Answer(“SIP/2002-000000fa”, “500”) in new stack
> 0xb6413b90 – Probation passed - setting RTP source address to 10.0.0.4:5062
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027594, ts 000180, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027595, ts 000340, len 000160)

Got RTP packet from 10.0.0.4:5062 (type 08, seq 027615, ts 003540, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027616, ts 003700, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027617, ts 003860, len 000160)
– Executing [2999@internal-og:2] Playback(“SIP/2002-000000fa”, “silence/1”) in new stack
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028107, ts 000160, len 000160)
– <SIP/2002-000000fa> Playing ‘silence/1.gsm’ (language ‘us’)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027618, ts 004020, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027619, ts 004180, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028108, ts 000320, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027620, ts 004340, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028109, ts 000480, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027621, ts 004500, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028110, ts 000640, len 000160)

Got RTP packet from 10.0.0.4:5062 (type 08, seq 027667, ts 011860, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028156, ts 008000, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027668, ts 012020, len 000160)
– Executing [2999@internal-og:3] VoiceMailMain(“SIP/2002-000000fa”, “2002,s”) in new stack
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028157, ts 008160, len 000160)
– <SIP/2002-000000fa> Playing ‘vm-youhave.gsm’ (language ‘us’)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027669, ts 012180, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027670, ts 012340, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028158, ts 008320, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027671, ts 012500, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028159, ts 008480, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027672, ts 012660, len 000160)

Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028200, ts 015040, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027713, ts 019220, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028201, ts 015200, len 000160)
– <SIP/2002-000000fa> Playing ‘digits/2.gsm’ (language ‘us’)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027714, ts 019380, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028202, ts 015360, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027715, ts 019540, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028203, ts 015520, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027716, ts 019700, len 000160)

Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028230, ts 019840, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027743, ts 024020, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028231, ts 020000, len 000160)
– <SIP/2002-000000fa> Playing ‘vm-Old.gsm’ (language ‘us’)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027744, ts 024180, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027745, ts 024340, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028232, ts 020160, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027746, ts 024500, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028233, ts 020320, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027747, ts 024660, len 000160)
Sent …
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028261, ts 024800, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027775, ts 029140, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028262, ts 024960, len 000160)
– <SIP/2002-000000fa> Playing ‘vm-messages.gsm’ (language ‘us’)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027776, ts 029300, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028263, ts 025120, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027777, ts 029460, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028264, ts 025280, len 000160)
Got RTP packet from 10.0.0.4:5062 (type 08, seq 027778, ts 029620, len 000160)

Got RTP packet from 10.0.0.4:5062 (type 08, seq 027795, ts 032340, len 000160)
Sent RTP packet to 10.0.0.4:5062 (type 08, seq 028282, ts 028160, len 000160)
== Spawn extension (internal-og, 2999, 3) exited non-zero on ‘SIP/2002-000000fa’

Hm…
server-to-client stream on clients capture file shows the full message (verified by playing it)

Which would mean it was correctly sent over the wire but the receiving machine messed it up during further processing. E.g. firewall/softphone etc

Let me do some more coordinated/comparable tests with several phones again and report back…

Hey, just wanted to update this one.
Still did not track down the REAL issue.

Tried the same sip clients on different PCs and had no problems…
Also tried other SIP clients on the PC in question and had no issues, so its not a general problem on the corresponding pc. Strange thing
No idea how to display the firewall state table in windows (like conntrack does in linux)

Thanks for the help provided, think I am going to skip troubleshooting here for the moment… :stuck_out_tongue: