When the background application is run on a channel that just came out of a ConfBridge, the audio starts to be heard several seconds after the (AMI) AGIExecStartEvent, indicating background application is started, arrives.
When using Asterisk 11 the behavior is ok.
When using Meetme before background application the behavior is ok in Asterisk 11 and 13.
The problem occurs using Asterisk 13 and ConfBridge just before executing the background application.
CLI> core show version:
Asterisk 13.12.1 built by mockbuild @ jenkins2.schmoozecom.net on a i686 running Linux on 2016-10-28 03:56:25 UTC
Some application log lines:
// Event. Channel is joining the conference
10:46:55.978 ConfbridgeJoin_Event. Channel: SIP/ADL8256-000000eb, ConferenceId: 107
// Application sending ConfbridgeKick order to Asterisk for that channel. Response: Success
10:47:01.530 ConfbridgeKick Channel: SIP/ADL8256-000000eb, Conference: 107. Response:Success Message:User kicked
// Event. Channel leaves the conference
10:47:01.534 ConfbridgeLeave_Event. Channel: SIP/ADL8256-000000eb, ConferenceId: 107
// AGI Command Background order sent to Asterisk. Response: Success
10:47:01.654 AGI Command Background, IdPetición: 12, Channel: SIP/ADL8256-000000eb, Response:Success Message:Added AGI command to queue
// Event. Background app is running
10:47:01.656 AGIExecStart event. Command: EXEC Background tiphone/MusicaEspera_es, Channel: SIP/ADL8256-000000eb
// When user start hearing the audio
10:47:12.375 Trace. User click on application button when starts hearing audio
// 10 seconds delay.
Your version of Asterisk is over a year old, many things have changed since then. You’d need to upgrade before anyone really invests the time in digging in.
Thanks for your answer, jcolp.
We have same problem with Asterisk version 13.18.3
CLI>core show version
Asterisk 13.18.3 built by mockbuild @ jenkins2.schmoozecom.net on a i686 running Linux on 2017-12-01
aprox. 10 seconds delay
What is the console output for the call? Have you looked at the “rtp set debug on” to see the media flow?
After a more detailed analysis, I discovered that the problem is not with the Background application.
Problem occurs immediately after the channel leaves the ConfBridge, at that moment you begin to hear white noise at the other end of the call. If you try to run the background application just after the channel leaves the Confbridge, the audio does not starts hearing until the end of that noise.
The duration of the noise is approximately 10 seconds and its volume decreases progressively.
Asterisk version: 13.18.3
Steps to reproduce:
//We have a ConfBridge (id 107) created previously for a call to an Asterisk extension (107), channel is: SIP/107-0000001f
11:23:14.905 Executing AGI Command: EXEC ConfBridge 107,default_bridge,regular_user
11:23:14.949 AGI Command ConfBridge, IdPetición: 1, Response:Success Message:Added AGI command to queue
// Channel joined the conference
11:23:14.954 ConfbridgeJoin_Event. Channel: SIP/107-0000001f, ConferenceId: 107
// An incoming call is received and we want connect that channel with the existing conference using ConfBridge. So we need starts an AGI session for the channel
// Channel starts AGI Session: SIP/ADL8256-00000022
11:27:40.063 AsyncAgiStart_Event. . Channel: SIP/ADL8256-00000022, UniqueId: 1515493526.438
11:27:40.063 AGI Session stated. Channel: CanalSIP/ADL8256-00000022
// In AGI Session, app executes AGI Command ConfBridge
11:27:40.063 Executing AGI Command: EXEC ConfBridge 107,default_bridge,regular_user
11:27:40.080 AGI Command ConfBridge, IdPetición: 11, Response:Success Message:Added AGI command to queue
// Channel joined the conference. Caller can talk to the person in the extension
11:27:40.082 ConfbridgeJoin_Event. Channel: SIP/ADL8256-00000022, ConferenceId: 107
// In AGI Session, app executes ConfBridgeKick
11:27:42.256 ConfbridgeKick Channel: SIP/ADL8256-00000022, Conference: 107. Response:Success Message:User kicked
// Channel leaves the conference. Noise is hearing in the caller phone (the other end of the call)
11:27:42.308 ConfbridgeLeave_Event. Channel: SIP/ADL8256-00000022, ConferenceId: 107
// We want to play some messages to the caller, so we need execute Background AGI Command
11:27:42.410 AGI Command Background, IdPetición: 12, Channel: SIP/ADL8256-00000022, Response:Success Message:Added AGI command to queue
// We receive AGIExecStart event for the background command. No sound, only noise for 10 seconds
11:27:42.461 AGIExecStart event. Command: EXEC Background tiphone/MusicaEspera_es, Channel: SIP/ADL8256-00000022
// 10 seconds after, tiphone/MusicaEspera_es starts
11:27:52.254 10 seconds after, caller starts to hear our sound file
Asterisk full log for the case: (Asterisk time is different that App time)
[2018-01-09 11:25:43] VERBOSE[20517][C-00000022] pbx.c: Executing [0@queues-agi:2] AGI(“SIP/ADL8256-00000022”, “agi:async”) in new stack
[2018-01-09 11:25:43] VERBOSE[20517][C-00000022] res_agi.c: AGI Script Executing Application: (ConfBridge) Options: (107,default_bridge,regular_user)
[2018-01-09 11:25:43] VERBOSE[20517][C-00000022] bridge_channel.c: Channel SIP/ADL8256-00000022 joined ‘softmix’ base-bridge
[2018-01-09 11:25:43] VERBOSE[20517][C-00000022] bridge_channel.c: Channel SIP/ADL8256-00000022 joined ‘softmix’ base-bridge
[2018-01-09 11:25:45] VERBOSE[20517][C-00000022] bridge_channel.c: Channel SIP/ADL8256-00000022 left ‘softmix’ base-bridge
[2018-01-09 11:25:45] VERBOSE[20517][C-00000022] pbx.c: Spawn extension (salir-agi, 0, 1) exited non-zero on ‘SIP/ADL8256-00000022’
[2018-01-09 11:25:45] VERBOSE[20517][C-00000022] pbx.c: Executing [0@salir-agi:1] AGI(“SIP/ADL8256-00000022”, “agi:async”) in new stack
[2018-01-09 11:25:45] VERBOSE[20517][C-00000022] res_agi.c: AGI Script Executing Application: (Background) Options: (tiphone/MusicaEspera_es)
[2018-01-09 11:25:45] VERBOSE[20517][C-00000022] file.c: <SIP/ADL8256-00000022> Playing ‘tiphone/MusicaEspera_es.slin’ (language ‘en’)
[2018-01-09 11:25:55] VERBOSE[20517][C-00000022] pbx.c: Spawn extension (stop-play, 0, 1) exited non-zero on ‘SIP/ADL8256-00000022’
Some devices react badly to jumps in the RTP timestamps without a corresponding change in the source ID. Asterisk sends a constant source ID, rather than changing when the source actually changes, or at least that used to be the case.
Capture the signalling a media an use wireshark on it, it will tell you whether there are timestamp jumps without corresponding source changes.
Thanks david551.
As i said in my first message. This only ocurrs using Confbridge for conferencing and Asterisk 13.
If i use Meetme for conferencing and Asterisk 13 or 11, the issue does not occurs.
If I use Confbridge and Asterisk 11 the problem does not happen either.
Our customers are asking us to use Asterisk 13 and we need to be sure that our application can work correctly as it has done so far.
If the behavior we have observed using Confbridge + Asterisk 13 is not wrong, we will not be able to use Confbridge for conferencing but, honestly, we would like to continue using ConfBridge
I’d still wireshark it and find out what is actually being sent in the RTP.
Wireshark shows 3 audio segments. 2 of them from the Asterisk address to the caller’s address. These 2 segments have the same source but different TimeStamp.
Source Address: 192.168.1.116:17580, Destination Address: 192.168.1.47:5350, TimeStamp:27.5-46.3(18.8)
Source Address: 192.168.1.116:17580, Destination Address: 192.168.1.47:5350, TimeStamp:2.47-27.3(24.8)
I have done another test calling with another device and the operation has been correct. From the first moment the correct audio has been heard.
You were right.
Thank you very much.
Do these segments contain the correct audio, and do they completely cover the time.
yes, the segments contains the correct and complete audio.
That does suggest the device doesn’t like the discontinuities.
In a fork that I worked on before retiring, we added an option that caused a new source ID to be faked every time a source change was signalled. That worked for some devices but actually caused problems for other devices.
What chan_sip did and maybe still does, was to set the marker bit on RTP frames, but the official semantics of this are that it indicates a good place to resynchronised jitter buffers, not that it indicates a change in source and a likely huge change in timestamps.
The session IDs were not propagated through the core of Asterisk in the versions we used, so actually sending the session ID that matched the time stamp sequence would have been difficult.
Ideally, you would have everything synchronised to the same time source, so there wouldn’t be jumps.