[asterisk-bugs] [JIRA] (ASTERISK-29879) res_musiconhold: Music on hold restarts after positon announcement

ben kolodny (JIRA) noreply at issues.asterisk.org
Mon Feb 7 12:07:06 CST 2022


    [ https://issues.asterisk.org/jira/browse/ASTERISK-29879?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=257978#comment-257978 ] 

ben kolodny edited comment on ASTERISK-29879 at 2/7/22 12:06 PM:
-----------------------------------------------------------------

{code:title=musicon hold debug|borderStyle=solid}



[2022-02-07 19:17:45] DEBUG[4565][C-00000e4d] pbx.c: Launching 'Return'
[2022-02-07 19:17:45] VERBOSE[4565][C-00000e4d] pbx.c: Executing [~~s~~@callEnd:48] Return("Local/AG-000-CC-538 at fromotherpbx-00000d2c;2", "") in new stack
[2022-02-07 19:17:45] DEBUG[4565][C-00000e4d] channel.c: Channel 0x7fe64c0204b0 'Local/AG-000-CC-538 at fromotherpbx-00000d2c;2' hanging up.  Refs: 3
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] autochan.c: Removed autochan 0x7fe67000a2e0 from the list, about to free it
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] channel.c: Channel 0x7fe64c0204b0 'Local/AG-000-CC-538 at fromotherpbx-00000d2c;2' destroying
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] stasis.c: Destroying topic. name: channel:db02-1644254245.72706, detail: 
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] stasis.c: Topic 'channel:db02-1644254245.72706': 0x7fe64c005610 destroyed
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] channel_internal_api.c:  <initializing>: MultistreamFormats: (nothing)
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] channel_internal_api.c:  Channel is being initialized or destroyed
[2022-02-07 19:17:45] VERBOSE[4568][C-00000e4d] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2022-02-07 19:17:45] VERBOSE[4568][C-00000e4d] app_mixmonitor.c: End MixMonitor Recording Local/AG-000-CC-538 at fromotherpbx-00000d2c;2
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] app_mixmonitor.c: No recipients to forward monitor to, moving on.
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_odbc.c: Reusing ODBC handle 0x296b430 from class 'asterisk1'
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM queue_member WHERE interface LIKE ? AND queue_name = ? ORDER BY interface
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_config_odbc.c: Parameter 1 ('interface LIKE') = '%'
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_config_odbc.c: Parameter 2 ('queue_name') = '9'
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_odbc.c: Releasing ODBC handle 0x296b430 into pool
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] app_queue.c: There is 1 available member.
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] app_queue.c: It's our turn (SIP/oraclepbx-00000c08).
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_musiconhold.c: Destroying MOH class '457'
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_musiconhold.c: killing 4563!
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_musiconhold.c: Sent HUP to pid 4563 and all children
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_musiconhold.c: mpg123 pid 4563 and child died after 62592 bytes read
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] channel.c: Channel SIP/oraclepbx-00000c08 setting write format path: ulaw -> ulaw
[2022-02-07 19:17:46] VERBOSE[4560][C-00000e4d] res_musiconhold.c: Stopped music on hold on SIP/oraclepbx-00000c08
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] channel.c: Channel SIP/oraclepbx-00000c08 setting write format path: gsm -> ulaw
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_rtp_asterisk.c: (0x7fe7140f9b20) RTP audio difference is 768, ms is 116
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[2022-02-07 19:17:46] VERBOSE[4560][C-00000e4d] file.c: <SIP/oraclepbx-00000c08> Playing 'queue-youarenext.gsm' (language 'he')
[2022-02-07 19:17:50] DEBUG[4560][C-00000e4d] res_rtp_asterisk.c: (0x7fe7140f9b20) RTCP got report of 100 bytes from XXX.X.XXX.XX:19717
[2022-02-07 19:17:51] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:51] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:51] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:51] DEBUG[4560][C-00000e4d] channel.c: Channel SIP/oraclepbx-00000c08 setting write format path: ulaw -> ulaw
[2022-02-07 19:17:51] VERBOSE[4560][C-00000e4d] app_queue.c: Told SIP/oraclepbx-00000c08 in 9 their queue position (which was 1)
[2022-02-07 19:17:51] DEBUG[4560][C-00000e4d] channel.c: Channel SIP/oraclepbx-00000c08 setting write format path: gsm -> ulaw
[2022-02-07 19:17:51] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[2022-02-07 19:17:51] VERBOSE[4560][C-00000e4d] file.c: <SIP/oraclepbx-00000c08> Playing 'queue-thankyou.gsm' (language 'he')
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] channel.c: Channel SIP/oraclepbx-00000c08 setting write format path: ulaw -> ulaw
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] res_odbc.c: Reusing ODBC handle 0x296b430 from class 'asterisk1'
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM musiconhold WHERE name = ?
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] res_config_odbc.c: Parameter 1 ('name') = '457'
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] res_odbc.c: Releasing ODBC handle 0x296b430 into pool
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] channel.c: Channel SIP/oraclepbx-00000c08 setting write format path: slin -> ulaw
[2022-02-07 19:17:52] VERBOSE[4560][C-00000e4d] res_musiconhold.c: Started music on hold, class '457', on channel 'SIP/oraclepbx-00000c08'
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second

{code}
{color:red}
  

also the music on hold apllication is using  custom mode

{color}


was (Author: benphone):

{code:title=musicon hold debug|borderStyle=solid}



[2022-02-07 19:17:45] DEBUG[4565][C-00000e4d] pbx.c: Launching 'Return'
[2022-02-07 19:17:45] VERBOSE[4565][C-00000e4d] pbx.c: Executing [~~s~~@callEnd:48] Return("Local/AG-000-CC-538 at fromotherpbx-00000d2c;2", "") in new stack
[2022-02-07 19:17:45] DEBUG[4565][C-00000e4d] channel.c: Channel 0x7fe64c0204b0 'Local/AG-000-CC-538 at fromotherpbx-00000d2c;2' hanging up.  Refs: 3
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] autochan.c: Removed autochan 0x7fe67000a2e0 from the list, about to free it
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] channel.c: Channel 0x7fe64c0204b0 'Local/AG-000-CC-538 at fromotherpbx-00000d2c;2' destroying
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] stasis.c: Destroying topic. name: channel:db02-1644254245.72706, detail: 
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] stasis.c: Topic 'channel:db02-1644254245.72706': 0x7fe64c005610 destroyed
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] channel_internal_api.c:  <initializing>: MultistreamFormats: (nothing)
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] channel_internal_api.c:  Channel is being initialized or destroyed
[2022-02-07 19:17:45] VERBOSE[4568][C-00000e4d] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2022-02-07 19:17:45] VERBOSE[4568][C-00000e4d] app_mixmonitor.c: End MixMonitor Recording Local/AG-000-CC-538 at fromotherpbx-00000d2c;2
[2022-02-07 19:17:45] DEBUG[4568][C-00000e4d] app_mixmonitor.c: No recipients to forward monitor to, moving on.
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_odbc.c: Reusing ODBC handle 0x296b430 from class 'asterisk1'
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM queue_member WHERE interface LIKE ? AND queue_name = ? ORDER BY interface
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_config_odbc.c: Parameter 1 ('interface LIKE') = '%'
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_config_odbc.c: Parameter 2 ('queue_name') = '9'
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_odbc.c: Releasing ODBC handle 0x296b430 into pool
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] app_queue.c: There is 1 available member.
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] app_queue.c: It's our turn (SIP/oraclepbx-00000c08).
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_musiconhold.c: Destroying MOH class '457'
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_musiconhold.c: killing 4563!
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_musiconhold.c: Sent HUP to pid 4563 and all children
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_musiconhold.c: mpg123 pid 4563 and child died after 62592 bytes read
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] channel.c: Channel SIP/oraclepbx-00000c08 setting write format path: ulaw -> ulaw
[2022-02-07 19:17:46] VERBOSE[4560][C-00000e4d] res_musiconhold.c: Stopped music on hold on SIP/oraclepbx-00000c08
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] channel.c: Channel SIP/oraclepbx-00000c08 setting write format path: gsm -> ulaw
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] res_rtp_asterisk.c: (0x7fe7140f9b20) RTP audio difference is 768, ms is 116
[2022-02-07 19:17:46] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[2022-02-07 19:17:46] VERBOSE[4560][C-00000e4d] file.c: <SIP/oraclepbx-00000c08> Playing 'queue-youarenext.gsm' (language 'he')
[2022-02-07 19:17:50] DEBUG[4560][C-00000e4d] res_rtp_asterisk.c: (0x7fe7140f9b20) RTCP got report of 100 bytes from XXX.X.XXX.XX:19717
[2022-02-07 19:17:51] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:51] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:51] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:51] DEBUG[4560][C-00000e4d] channel.c: Channel SIP/oraclepbx-00000c08 setting write format path: ulaw -> ulaw
[2022-02-07 19:17:51] VERBOSE[4560][C-00000e4d] app_queue.c: Told SIP/oraclepbx-00000c08 in 9 their queue position (which was 1)
[2022-02-07 19:17:51] DEBUG[4560][C-00000e4d] channel.c: Channel SIP/oraclepbx-00000c08 setting write format path: gsm -> ulaw
[2022-02-07 19:17:51] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[2022-02-07 19:17:51] VERBOSE[4560][C-00000e4d] file.c: <SIP/oraclepbx-00000c08> Playing 'queue-thankyou.gsm' (language 'he')
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] channel.c: Channel SIP/oraclepbx-00000c08 setting write format path: ulaw -> ulaw
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] res_odbc.c: Reusing ODBC handle 0x296b430 from class 'asterisk1'
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM musiconhold WHERE name = ?
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] res_config_odbc.c: Parameter 1 ('name') = '457'
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] res_odbc.c: Releasing ODBC handle 0x296b430 into pool
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] channel.c: Channel SIP/oraclepbx-00000c08 setting write format path: slin -> ulaw
[2022-02-07 19:17:52] VERBOSE[4560][C-00000e4d] res_musiconhold.c: Started music on hold, class '457', on channel 'SIP/oraclepbx-00000c08'
[2022-02-07 19:17:52] DEBUG[4560][C-00000e4d] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second

{code}

also the music on hold apllication is using  custom mode will try 

> res_musiconhold: Music on hold restarts after positon announcement
> ------------------------------------------------------------------
>
>                 Key: ASTERISK-29879
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-29879
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Resources/res_musiconhold
>    Affects Versions: 18.9.0
>         Environment: centos 7
> real time queue 
>            Reporter: ben kolodny
>            Assignee: Unassigned
>         Attachments: music on hold.txt, new 13 (1).txt, queue configure.txt
>
>
> {quote}
> In /ext/moh/82497 are one or more audio files with a length of around 3 minutes. If a queue is configured with a periodic announcement every 30 seconds, the following will occur:
>     Caller hears music on hold file #1, playing from the beginning
>     After 30 seconds, the caller will hear the announcement
>     Caller hears music on hold file #1, playing from the beginning
>     After 30 seconds, the caller will hear the announcement
>     ...
> E.g., if the periodic announcement is made every 30 seconds the caller will only ever hear the first 30 seconds of music on hold over and over again.
> {quote}
> above is a quote from https://issues.asterisk.org/jira/browse/ASTERISK-27774 
> i seem to have the same problem with version 18.9.0 but it after playing the thank you message when Announce position: is set to yes
> (the code that was fixed checks just announcement maybe position is treated differently?)
> any tips would be appreciated
> {noformat}
> VERBOSE[2643] app_queue.c: Nobody picked up in 20000 ms
> VERBOSE[2643] res_musiconhold.c: Stopped music on hold on PJSIP/fs2-00036104
> VERBOSE[2643] file.c: <PJSIP/fs2-00036104> Playing 'pbx/188d949a5b9bbde4553ef85f252d8ddf.slin' (language 'he')
> VERBOSE[2643] app_queue.c: Told PJSIP/fs2-00036104 in 1507 their queue position (which was 1)
> VERBOSE[2643] file.c: <PJSIP/fs2-00036104> Playing 'queue-thankyou.gsm' (language 'he')
> VERBOSE[2643] res_musiconhold.c: Started music on hold, class '1435', on channel 'PJSIP/fs2-00036104'
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.2#6252)



More information about the asterisk-bugs mailing list