[Home]

Summary:ASTERISK-25231: Set Music AGI command with class argument fails silently - need user level log message
Reporter:Michael Cargile (mcargile)Labels:
Date Opened:2015-07-07 11:31:39Date Closed:2015-07-20 09:16:31
Priority:MinorRegression?
Status:Closed/CompleteComponents:Resources/res_agi Resources/res_musiconhold
Versions:SVN 11.18.0 13.4.0 Frequency of
Occurrence
Related
Issues:
Environment:OpenSuSE 13.1 running on a quad core intel with 4 gigs of ram.Attachments:( 0) moh_not_found_notice.patch
Description:Our script is sending 'SET MUSIC ON ast11test' to standard out and yet the music on hold that is played is default:

2015-07-07 12:19:17|12:19:28|agi-VDAD_ALL_inbound.agi|MOH Context = ast11test
2015-07-07 12:19:17|12:19:28|agi-VDAD_ALL_inbound.agi|MOH Command = SET MUSIC ON ast11test
   -- [Jul  7 12:19:28]     -- Started music on hold, class 'default', on SIP/sgw1-00000040
2015-07-07 12:19:17|12:19:28|agi-VDAD_ALL_inbound.agi|MOH Result = 200 result=0

no error is given.

[Edit by Rusty - adding the below debug.. a DEBUG message is present, but we need something user level, a NOTICE or WARNING would be nice]

{noformat}
<PJSIP/ALICE-00000002>AGI Rx << SET MUSIC ON ast11test
[Jul 15 09:09:08] DEBUG[25190][C-00000002]: res_musiconhold.c:884 _get_mohbyname: Music on Hold class 'ast11test' not found in memory
   -- Started music on hold, class 'default', on channel 'PJSIP/ALICE-00000002'
[Jul 15 09:09:08] DEBUG[25190][C-00000002]: channel.c:3402 ast_settimeout_full: Scheduling timer at (50 requested / 50 actual) timer ticks per second
<PJSIP/ALICE-00000002>AGI Tx >> 200 result=0
{noformat}
Comments:By: Asterisk Team (asteriskteam) 2015-07-07 11:31:40.325-0500

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].
By: Rusty Newton (rnewton) 2015-07-08 15:20:26.908-0500

We require additional debug to continue with triage of your issue. Please follow the instructions on the wiki [1] for how to collect debugging information from Asterisk. For expediency, where possible, attach the debug with a '.txt' file extension so that the debug will be usable for further analysis.

Thanks!

[1] https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information


By: Rusty Newton (rnewton) 2015-07-08 15:21:02.594-0500

In addition to a debug log as specified in the link above, please provide your full music on hold configuration file.
By: Michael Cargile (mcargile) 2015-07-08 16:17:14.770-0500

The debug file pointed me to the actual issue. Asterisk is only reloading the musiconhold.conf file once on a 'moh reload'. If the moh class exists in the file but is not created yet it throws an error and then ignores the class. Subsequent 'moh reload's do not reparse the musiconhold.conf file. Instead it just reloads the classes it knows about. After I started Asterisk 11 back up with the debug options enabled like you asked it worked fine.

Our software has two processes one that auto generates config files and one that builds the moh directory and loads the files. Both call 'moh rebuild'. If the config file process finishes before the moh gets built by the second process the moh class will not work till I either restart Asterisk or touch the config files. This does not seem like the proper way 'moh reload' should work but I fixed the issue in our software by putting a 'touch /etc/asterisk/musiconhold.conf' command at the end of the process that creates the directory and loads the files.
By: Michael Cargile (mcargile) 2015-07-08 16:22:52.968-0500

Also is it proper for AGI to issue a 200 response if the music on hold class does not even exist?
By: Rusty Newton (rnewton) 2015-07-08 17:14:32.958-0500

{quote}Subsequent 'moh reload's do not reparse the musiconhold.conf file.{quote}

{quote}This does not seem like the proper way 'moh reload' should work but I fixed the issue in our software by putting a 'touch /etc/asterisk/musiconhold.conf' command at the end of the process that creates the directory and loads the files.{quote}

This is currently the way reload works for most modules. That is, the module's configuration will not be re-parsed unless the configuration file has been modified. It is not a bug, but may not be optimal in some cases.

If you wanted to submit a patch to change this behavior for Music on Hold - there is a good chance it would get accepted due to the scenario you have run into.

Are you interested in submitting a patch? If you need guidance on where to start in the source code, you could ask on the asterisk-dev[1] mailing list.

[1]: http://lists.digium.com/mailman/listinfo/asterisk-dev
By: Michael Cargile (mcargile) 2015-07-09 12:10:27.237-0500

Touching the file seems to have fixed the issue for our software so I can work with the current behavior. What does seem troublesome though is that there wasnt an Notice, Warning, or Error thrown in the CLI for trying to play a missing moh class and that the AGI command 'SET MUSIC ON ast11test' returned a 200 indicating that it was successful when in fact a completely different moh class was played instead.
By: Rusty Newton (rnewton) 2015-07-15 09:12:49.732-0500

You are right. There should be a Notice, Warning or Error message to help the user identify what is happening.

I did see a debug message
{noformat}
<PJSIP/ALICE-00000002>AGI Rx << SET MUSIC ON ast11test
[Jul 15 09:09:08] DEBUG[25190][C-00000002]: res_musiconhold.c:884 _get_mohbyname: Music on Hold class 'ast11test' not found in memory
   -- Started music on hold, class 'default', on channel 'PJSIP/ALICE-00000002'
[Jul 15 09:09:08] DEBUG[25190][C-00000002]: channel.c:3402 ast_settimeout_full: Scheduling timer at (50 requested / 50 actual) timer ticks per second
<PJSIP/ALICE-00000002>AGI Tx >> 200 result=0
{noformat}

The debug message tells you exactly what is happening, but there really should be something higher level too.

By: Michael Cargile (mcargile) 2015-07-15 09:23:34.016-0500

"Music on Hold class 'ast11test' not found in memory" would basically be the perfect Notice, Warning, or Error message for this.
By: Michael Cargile (mcargile) 2015-07-15 09:29:24.513-0500

adding:

ast_log(LOG_NOTICE, "Music on Hold class '%s' not found in memory\n", name);

to line 896 of res_musiconhold.c seems to do it. Want a patch file?
By: Rusty Newton (rnewton) 2015-07-15 09:35:48.018-0500

That would be amazing and speed things along. What about:

ast_log(LOG_NOTICE, "Music on Hold class '%s' not found in memory. Check your configuration!\n", name);

If you want, after posting the patch here, you could post to Gerrit and it would probably get merged in quickly.

https://wiki.asterisk.org/wiki/display/AST/Gerrit+Usage

Thanks!
By: Michael Cargile (mcargile) 2015-07-15 10:07:21.232-0500

patch to add a notice to MOH for when the the class was not found in memory.
By: Michael Cargile (mcargile) 2015-07-15 10:08:25.979-0500

Patch added. Currently looking into Gerrit. Seem a bit confusing but I'll see about getting an account setup.
By: Michael Cargile (mcargile) 2015-07-15 11:25:07.739-0500

Gerrit will require me putting my private SSH key on a system I dont trust putting it on at the moment. I am putting together virtual machine on my PC that I can do that with but it might be a few days.
By: Michael Cargile (mcargile) 2015-07-16 09:17:51.257-0500

Okay I think I got it submitted to Gerrit for review