[Home]

Summary:ASTERISK-15170: [patch] asterisk reload causes mpg123 streams to be recreated
Reporter:Andrew Parisio (parisioa)Labels:
Date Opened:2009-11-18 18:14:36.000-0600Date Closed:2009-12-08 12:35:19.000-0600
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Resources/res_musiconhold
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 20091201__issue16279__2.diff.txt
( 1) 20091201__issue16279__3.diff.txt
( 2) 20091201__issue16279.diff.txt
( 3) 20091202__issue16279__2.diff.txt
( 4) 20091202__issue16279.diff.txt
( 5) refs.tar.gz
( 6) refs2.tar.gz
( 7) refs3.tar.gz
( 8) ss.jpg
Description:Every time there is an asterisk reload all of the mpg123 streams get re-started, and the old ones do not get removed.  This causes many many streams to build up over time, and after enough reloads with enough streams actually causes asterisk to completely fail.

****** ADDITIONAL INFORMATION ******

I just downloaded and compiled the latest 1.6.1.9 to test this out.
Comments:By: Andrew Parisio (parisioa) 2009-11-18 18:29:25.000-0600

i just tested against the SVN tree, and the problem exists there as well.

musiconhold.conf
[hits]
mode=custom
application=/usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-mtc-aa02.stream.aol.com:80/stream/1074
By: Leif Madsen (lmadsen) 2009-11-19 09:43:36.000-0600

This may be a duplicate of ASTERISK-15102 but I'm just marking it as related for now as it isn't clear if the other issue has people reloading Asterisk or not.
By: Andrew Parisio (parisioa) 2009-11-24 15:44:22.000-0600

the patch in 16207 does not fix this issue
By: Tilghman Lesher (tilghman) 2009-11-30 11:25:19.000-0600

Slightly different patch uploaded to this issue.
By: Andrew Parisio (parisioa) 2009-11-30 13:56:37.000-0600

patch does not fix the issue.  4 reloads = 4 streams.
By: Tilghman Lesher (tilghman) 2009-11-30 15:54:44.000-0600

Do you get any additional warnings on reload?
By: Andrew Parisio (parisioa) 2009-11-30 16:29:06.000-0600

csgtacsip1*CLI> module reload res_musiconhold
   -- Reloading module 'res_musiconhold.so' (Music On Hold Resource)
 == Parsing '/etc/asterisk/musiconhold.conf':   == Found
 == Parsing '/etc/asterisk/musiconhold-autogenerated.conf':   == Found
csgtacsip1*CLI>


this is all i get with verbose 10
By: Andrew Parisio (parisioa) 2009-11-30 16:31:50.000-0600

also i think i found a new bug, should i report it?  unloading res_musiconhold shuts asterisk down completely.

csgtacsip1*CLI> module unload res_musiconhold
 == Destroying musiconhold processes
 == Unregistered application 'MusicOnHold'
 == Unregistered application 'WaitMusicOnHold'
 == Unregistered application 'SetMusicOnHold'
 == Unregistered application 'StartMusicOnHold'
 == Unregistered application 'StopMusicOnHold'
csgtacsip1*CLI>
Disconnected from Asterisk server
By: Tilghman Lesher (tilghman) 2009-11-30 17:08:24.000-0600

If you type 'moh show classes' after reloading several times, do you have duplicate classes loaded?
By: Andrew Parisio (parisioa) 2009-11-30 17:19:03.000-0600

no

csgtacsip1*CLI> moh show classes
Class: 80s*CLI>
csgtacsiMode: custom
csgtacsiDirectory: nodir
csgtacsiApplication: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
csgtacsiFormat: slin
Class: default>
csgtacsiMode: files
csgtacsiDirectory: /var/lib/asterisk/moh
csgtacsip1*CLI> exit
csgtacsip1:/etc/asterisk# ps aux | grep mpg123
root     32147  0.0  0.0   2736  1184 ?        S<   14:26   0:00 /usr/bin mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
root     32158  0.0  0.0   2736  1188 ?        S<   14:28   0:00 /usr/bin mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
root     32164  0.0  0.0   2736  1188 ?        S<   14:28   0:00 /usr/bin mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
root     32169 19.0  0.0   2736  1184 ?        S<   14:28   8:48 /usr/bin mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
root     32191  0.0  0.0   2736  1188 ?        S<   14:28   0:00 /usr/bin mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
root     32272  4.2  0.0   2736  1188 ?        S<   15:14   0:00 /usr/bin mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
root     32274  0.2  0.0   2736  1184 ?        S<   15:14   0:00 /usr/bin mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
root     32276  3.1  0.0   2736  1188 ?        S<   15:14   0:00 /usr/bin mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
root     32278  0.5  0.0   2736  1184 ?        S<   15:14   0:00 /usr/bin mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
root     32280  0.7  0.0   2736  1184 ?        S<   15:14   0:00 /usr/bin mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
root     32282  0.0  0.0   3120   736 pts/0    S<+  15:14   0:00 grep mpg123
By: Tilghman Lesher (tilghman) 2009-11-30 17:44:17.000-0600

Sorry, it occurred to me after I posted that that it was a silly question, because we don't track deleted classes until they are actually destroyed, but only until they are unlinked from our class list.

Here is a patch that tracks deleted threads until their eventual destruction.  With this patch, 'moh show classes' should show all outstanding references to deleted MOH classes, which would explain why the destruction code is not getting executed.  We may need to run some reference debugging, if this patch confirms that we have a reference leak somewhere.
By: Tilghman Lesher (tilghman) 2009-11-30 17:56:26.000-0600

I'm just going to go ahead and upload the reference debugging code.  After you confirm that the deleted classes are still sticking around, grab the /tmp/refs file and upload it here.
By: Andrew Parisio (parisioa) 2009-11-30 18:24:15.000-0600

csgtacsip1*CLI> moh show classes
Class: 80s*CLI>
csgtacsiMode: custom
csgtacsiDirectory: nodir
csgtacsiApplication: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
csgtacsiFormat: slin
Class: default>
csgtacsiMode: files
csgtacsiDirectory: /var/lib/asterisk/moh
(Deleted) Class: 80s (1)
csgtacsiMode: custom
csgtacsiDirectory: nodir
       Application: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
       Format: slin
(Deleted) Class: 80s (1)
csgtacsiMode: custom
csgtacsiDirectory: nodir
       Application: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
csgtacsiFormat: slin
(Deleted) Class: 80s (1)
csgtacsiMode: custom
csgtacsiDirectory: nodir
       Application: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
csgtacsiFormat: slin
(Deleted) Class: 80s (1)
csgtacsiMode: custom
csgtacsiDirectory: nodir
csgtacsiApplication: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
       Format: slin
(Deleted) Class: 80s (1)
csgtacsiMode: custom
csgtacsiDirectory: nodir
csgtacsiApplication: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
       Format: slin
By: Andrew Parisio (parisioa) 2009-11-30 18:26:18.000-0600

i had to compress it because it was too big, sorry.
By: Tilghman Lesher (tilghman) 2009-12-01 21:02:25.000-0600

Okay, go ahead and delete your /tmp/refs file, then apply this patch.  If this patch still doesn't solve it, please upload the (newly created) /tmp/refs file.
By: Andrew Parisio (parisioa) 2009-12-01 21:13:03.000-0600

i removed res/*mus* then rechecked out hte code to make sure i was starting from scratch. make clean, make,

  [LD] res_limit.o -> res_limit.so
  [CC] res_monitor.c -> res_monitor.o
  [LD] res_monitor.o -> res_monitor.so
  [CC] res_musiconhold.c -> res_musiconhold.o
res_musiconhold.c: In function â_get_mohbynameâ:
res_musiconhold.c:769: warning: passing argument 4 of â_ao2_find_debugâ discards                                                                                                                                qualifiers from pointer target type
res_musiconhold.c:769: warning: passing argument 5 of â_ao2_find_debugâ makes po                                                                                                                               inter from integer without a cast
res_musiconhold.c:769: warning: passing argument 6 of â_ao2_find_debugâ makes in                                                                                                                               teger from pointer without a cast
res_musiconhold.c:769: error: too few arguments to function â_ao2_find_debugâ
make[1]: *** [res_musiconhold.o] Error 1
make: *** [res] Error 2
CC="cc" CXX="g++" LD="" AR="" RANLIB="" CFLAGS="" make -C menuselect CONFIGURE_S                                                                                                                               ILENT="--silent" makeopts
make[1]: Entering directory `/root/asterisk-1.6.1.svn/menuselect'
make[1]: `makeopts' is up to date.
make[1]: Leaving directory `/root/asterisk-1.6.1.svn/menuselect'
  [CC] res_musiconhold.c -> res_musiconhold.o
res_musiconhold.c: In function â_get_mohbynameâ:
res_musiconhold.c:769: warning: passing argument 4 of â_ao2_find_debugâ discards                                                                                                                                qualifiers from pointer target type
res_musiconhold.c:769: warning: passing argument 5 of â_ao2_find_debugâ makes po                                                                                                                               inter from integer without a cast
res_musiconhold.c:769: warning: passing argument 6 of â_ao2_find_debugâ makes in                                                                                                                               teger from pointer without a cast
res_musiconhold.c:769: error: too few arguments to function â_ao2_find_debugâ
make[1]: *** [res_musiconhold.o] Error 1
make: *** [res] Error 2
csgtacsip1:~/asterisk-1.6.1.svn#
By: Andrew Parisio (parisioa) 2009-12-01 21:28:59.000-0600

just to make REALLLLY sure, i killed my entire tree, rechecked out the entire thing, reran, and got the same thing.
By: Tilghman Lesher (tilghman) 2009-12-01 22:07:52.000-0600

Oops.  Let's try that again.  New patch uploaded.
By: Andrew Parisio (parisioa) 2009-12-01 22:30:03.000-0600

csgtacsip1*CLI> moh show classes
Class: 80s*CLI>
       Mode: custom
       Directory: nodir
       Application: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
       Format: slin
Class: default
       Mode: files
       Directory: /var/lib/asterisk/moh
(Deleted) Class: 80s (1)
       Mode: custom
       Directory: nodir
       Application: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
       Format: slin
(Deleted) Class: 80s (1)
       Mode: custom
       Directory: nodir
       Application: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
       Format: slin
(Deleted) Class: 80s (1)
       Mode: custom
       Directory: nodir
       Application: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
       Format: slin
(Deleted) Class: 80s (1)
       Mode: custom
       Directory: nodir
       Application: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
       Format: slin
(Deleted) Class: 80s (1)
       Mode: custom
       Directory: nodir
       Application: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
       Format: slin
(Deleted) Class: 80s (1)
       Mode: custom
       Directory: nodir
       Application: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-dtc-aa03.stream.aol.com:80/stream/1040
       Format: slin
By: Tilghman Lesher (tilghman) 2009-12-01 23:50:25.000-0600

Yet another try.  I think it's not properly decrementing reference counts if the class returned during the find has been marked for deletion.  This can be remedied by not returning results for a class which has been marked for deletion in that particular case.  This was the intended codepath, anyway, so we're probably eliminating a ton of bugs along the way of nailing down this particular issue.
By: Andrew Parisio (parisioa) 2009-12-01 23:55:09.000-0600

haha, awesome.  same thing.
By: Tilghman Lesher (tilghman) 2009-12-02 12:48:31.000-0600

Let's try this again, shall we?
By: Andrew Parisio (parisioa) 2009-12-02 13:04:32.000-0600

it crashed when i typed reload.  and this is what i got compiling:
Generating embedded module rules ...
  [CC] res_musiconhold.c -> res_musiconhold.o
res_musiconhold.c: In function âlocal_ast_moh_startâ:
res_musiconhold.c:1319: warning: passing argument 6 of â_moh_registerâ discards qualifiers from pointer target type
res_musiconhold.c: In function âload_moh_classesâ:
res_musiconhold.c:1613: warning: passing argument 6 of â_moh_registerâ discards qualifiers from pointer target type
  [LD] res_musiconhold.o -> res_musiconhold.so
By: Andrew Parisio (parisioa) 2009-12-02 13:07:46.000-0600

Here is the refs file
csgtacsip1:/usr/src/asterisk-1.6.1.svn# cat /tmp/refs
0x86084b8 -1   res_musiconhold.c:1615:ast_moh_destroy (Destroy callback) [@1]
0x86084b8 **call destructor** res_musiconhold.c:1615:ast_moh_destroy (Destroy callback)
0xf791e488 =1   res_musiconhold.c:1766:load_module (Moh class container)
0xf791e270 =1   res_musiconhold.c:1770:load_module (Moh deleted class container)
0xf791e698 =1   res_musiconhold.c:1563:load_moh_classes (Allocating new moh class)
0xf791e698 +1   res_musiconhold.c:1157:_moh_register (Adding class to container) [@1]
0xf791e698 -1   res_musiconhold.c:1160:_moh_register (Unreffing new moh class because we just added it to the container) [@2]
0xf7916250 =1   res_musiconhold.c:1563:load_moh_classes (Allocating new moh class)
0xf7916250 +1   res_musiconhold.c:1157:_moh_register (Adding class to container) [@1]
0xf7916250 -1   res_musiconhold.c:1160:_moh_register (Unreffing new moh class because we just added it to the container) [@2]
0xf791dc68 =1   res_musiconhold.c:1563:load_moh_classes (Allocating new moh class)
0xf791e698 +1   res_musiconhold.c:1613:load_moh_classes (get_mohbyname) [@1]
0xf791e698 -1   res_musiconhold.c:1126:_moh_register (unreffing mohclass we just found by name) [@2]
0xf791dc68 -1   res_musiconhold.c:1128:_moh_register (unreffing potential new moh class (it is a duplicate)) [@1]
0xf791dc68 **call destructor** res_musiconhold.c:1128:_moh_register (unreffing potential new moh class (it is a duplicate))
0xf791dc68 =1   res_musiconhold.c:1563:load_moh_classes (Allocating new moh class)
0xf7916250 +1   res_musiconhold.c:1613:load_moh_classes (get_mohbyname) [@1]
0xf7916250 -1   res_musiconhold.c:1133:_moh_register (unreffing mohclass we just found by name) [@2]
0xf791dc68 +1   res_musiconhold.c:1157:_moh_register (Adding class to container) [@1]
0xf791dc68 -1   res_musiconhold.c:1160:_moh_register (Unreffing new moh class because we just added it to the container) [@2]
0xf7916250 +1   res_musiconhold.c:1518:moh_classes_delete_marked () [@1]
0xf7916250 -1   res_musiconhold.c:1621:load_moh_classes (Purge marked classes) [@2]
0xf791e698 +1   res_musiconhold.c:1518:moh_classes_delete_marked () [@1]
0xf791e698 -1   res_musiconhold.c:1621:load_moh_classes (Purge marked classes) [@2]
0xf7916250 +1   res_musiconhold.c:554:deleted_monitor () [@1]
0xf7916250 -1   res_musiconhold.c:556:deleted_monitor () [@2]
0xf7916250 -1   res_musiconhold.c:558:deleted_monitor () [@1]
0xf7916250 **call destructor** res_musiconhold.c:558:deleted_monitor ()
0xf791dc68 -1   res_musiconhold.c:1629:ast_moh_destroy (Destroy callback) [@1]
0xf791dc68 **call destructor** res_musiconhold.c:1629:ast_moh_destroy (Destroy callback)
0x8deede8 =1   res_musiconhold.c:1766:load_module (Moh class container)
0x8deebd0 =1   res_musiconhold.c:1770:load_module (Moh deleted class container)
0x8df0f40 =1   res_musiconhold.c:1563:load_moh_classes (Allocating new moh class)
0x8df0f40 +1   res_musiconhold.c:1157:_moh_register (Adding class to container) [@1]
0x8df0f40 -1   res_musiconhold.c:1160:_moh_register (Unreffing new moh class because we just added it to the container) [@2]
0x8df1250 =1   res_musiconhold.c:1563:load_moh_classes (Allocating new moh class)
0x8df1250 +1   res_musiconhold.c:1157:_moh_register (Adding class to container) [@1]
0x8df1250 -1   res_musiconhold.c:1160:_moh_register (Unreffing new moh class because we just added it to the container) [@2]
By: Tilghman Lesher (tilghman) 2009-12-02 15:24:28.000-0600

That output suggests to me that it's fixed.  Is that what you're also seeing?
By: Andrew Parisio (parisioa) 2009-12-02 15:29:17.000-0600

Except when I type reload asterisk crashes and dumps out.
By: Tilghman Lesher (tilghman) 2009-12-02 15:40:52.000-0600

Can you upload the backtrace?
By: Andrew Parisio (parisioa) 2009-12-02 15:52:56.000-0600

it doens't generate one. enabled dont optimize, make clean; make; make install. asterisk -vvvvvg -c

on reload of asterisk i get this:

  -- Added extension '1609' priority -1 to subscribecontext (0xf61348b8)
   -- Added extension '1610' priority -1 to subscribecontext (0xf61348b8)
   -- Added extension '1611' priority -1 to subscribecontext (0xf61348b8)
   -- Added extension '1612' priority -1 to subscribecontext (0xf61348b8)
   -- Added extension '1614' priority -1 to subscribecontext (0xf61348b8)
   -- Added extension '1615' priority -1 to subscribecontext (0xf61348b8)
   -- Added extension '1616' priority -1 to subscribecontext (0xf61348b8)
   -- Added extension '1617' priority -1 to subscribecontext (0xf61348b8)
   -- Added extension '1618' priority -1 tKilled
csgtacsip1:/usr/src/asterisk-1.6.1.svn/doc#  ls /tmp/core*
csgtacsip1:/usr/src/asterisk-1.6.1.svn/doc#
By: Tilghman Lesher (tilghman) 2009-12-02 16:07:34.000-0600

Does it crash if you just do a 'moh reload'?
By: Andrew Parisio (parisioa) 2009-12-02 16:13:32.000-0600

yes. moh reload kills it.
actually check out my earlier comment: https://issues.asterisk.org/view.php?id=16279#114432

previously unloading moh would cause asterisk to do this EXACT same thing.  seems a bit coincidental that now a reload causes it to do that too.
By: Tilghman Lesher (tilghman) 2009-12-02 17:30:13.000-0600

Okay, new patch uploaded.
By: Andrew Parisio (parisioa) 2009-12-02 17:45:33.000-0600

Bingo!
module unload res_musiconhold no longer causes asterisk to stop either.

So how many bugs did we just fix?
By: Digium Subversion (svnbot) 2009-12-02 18:16:32.000-0600

Repository: asterisk
Revision: 232660

U   trunk/include/asterisk/astobj2.h
U   trunk/res/res_musiconhold.c

------------------------------------------------------------------------
r232660 | tilghman | 2009-12-02 18:16:31 -0600 (Wed, 02 Dec 2009) | 19 lines

Fix multiple issues with musiconhold, which led to classes not getting destroyed properly.
* Classes are now tracked past removal from the core container, and module
  removal is actively prevented until all references are freed.
* A hanging reference stored in the channel has been removed.  This could have
  caused a mismatch and the music state not properly cleared, if two or more
  reloads occurred between MOH being stopped and MOH being restarted.
* In certain circumstances, duplicate classes were possible.
* A race existed at reload time between a process being killed and the thread
  responsible for reading from the related pipe respawning that process.
* Several reference counts have also been corrected.  At least one could have
  caused deleted classes to stick around forever, consuming resources.  This
  originally manifested as MOH external processes that were not killed at
  reload time.
(closes issue ASTERISK-15170, closes issue ASTERISK-15102)
Reported by: parisioa, dcabot
Patches:
      20091202__issue16279__2.diff.txt uploaded by tilghman (license 14)
Tested by: parisioa, tilghman

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=232660
By: Digium Subversion (svnbot) 2009-12-02 18:25:39.000-0600

Repository: asterisk
Revision: 232666

_U  branches/1.6.1/
U   branches/1.6.1/res/res_musiconhold.c

------------------------------------------------------------------------
r232666 | tilghman | 2009-12-02 18:25:38 -0600 (Wed, 02 Dec 2009) | 30 lines

Recorded merge of revisions 232660-232661 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
 r232660 | tilghman | 2009-12-02 18:08:55 -0600 (Wed, 02 Dec 2009) | 19 lines
 
 Fix multiple issues with musiconhold, which led to classes not getting destroyed properly.
  * Classes are now tracked past removal from the core container, and module
    removal is actively prevented until all references are freed.
  * A hanging reference stored in the channel has been removed.  This could have
    caused a mismatch and the music state not properly cleared, if two or more
    reloads occurred between MOH being stopped and MOH being restarted.
  * In certain circumstances, duplicate classes were possible.
  * A race existed at reload time between a process being killed and the thread
    responsible for reading from the related pipe respawning that process.
  * Several reference counts have also been corrected.  At least one could have
    caused deleted classes to stick around forever, consuming resources.  This
    originally manifested as MOH external processes that were not killed at
    reload time.
 (closes issue ASTERISK-15170, closes issue ASTERISK-15102)
  Reported by: parisioa, dcabot
  Patches:
        20091202__issue16279__2.diff.txt uploaded by tilghman (license 14)
  Tested by: parisioa, tilghman
........
 r232661 | tilghman | 2009-12-02 18:09:36 -0600 (Wed, 02 Dec 2009) | 2 lines
 
 Remove debugging line
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=232666
By: Digium Subversion (svnbot) 2009-12-02 18:27:31.000-0600

Repository: asterisk
Revision: 232675

_U  branches/1.6.2/
U   branches/1.6.2/res/res_musiconhold.c

------------------------------------------------------------------------
r232675 | tilghman | 2009-12-02 18:27:30 -0600 (Wed, 02 Dec 2009) | 30 lines

Recorded merge of revisions 232660-232661 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
 r232660 | tilghman | 2009-12-02 18:08:55 -0600 (Wed, 02 Dec 2009) | 19 lines
 
 Fix multiple issues with musiconhold, which led to classes not getting destroyed properly.
  * Classes are now tracked past removal from the core container, and module
    removal is actively prevented until all references are freed.
  * A hanging reference stored in the channel has been removed.  This could have
    caused a mismatch and the music state not properly cleared, if two or more
    reloads occurred between MOH being stopped and MOH being restarted.
  * In certain circumstances, duplicate classes were possible.
  * A race existed at reload time between a process being killed and the thread
    responsible for reading from the related pipe respawning that process.
  * Several reference counts have also been corrected.  At least one could have
    caused deleted classes to stick around forever, consuming resources.  This
    originally manifested as MOH external processes that were not killed at
    reload time.
 (closes issue ASTERISK-15170, closes issue ASTERISK-15102)
  Reported by: parisioa, dcabot
  Patches:
        20091202__issue16279__2.diff.txt uploaded by tilghman (license 14)
  Tested by: parisioa, tilghman
........
 r232661 | tilghman | 2009-12-02 18:09:36 -0600 (Wed, 02 Dec 2009) | 2 lines
 
 Remove debugging line
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=232675
By: Digium Subversion (svnbot) 2009-12-02 18:40:14.000-0600

Repository: asterisk
Revision: 232699

_U  branches/1.6.0/
U   branches/1.6.0/res/res_musiconhold.c

------------------------------------------------------------------------
r232699 | tilghman | 2009-12-02 18:40:14 -0600 (Wed, 02 Dec 2009) | 30 lines

Merged revisions 232660-232661 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
 r232660 | tilghman | 2009-12-02 18:08:55 -0600 (Wed, 02 Dec 2009) | 19 lines
 
 Fix multiple issues with musiconhold, which led to classes not getting destroyed properly.
  * Classes are now tracked past removal from the core container, and module
    removal is actively prevented until all references are freed.
  * A hanging reference stored in the channel has been removed.  This could have
    caused a mismatch and the music state not properly cleared, if two or more
    reloads occurred between MOH being stopped and MOH being restarted.
  * In certain circumstances, duplicate classes were possible.
  * A race existed at reload time between a process being killed and the thread
    responsible for reading from the related pipe respawning that process.
  * Several reference counts have also been corrected.  At least one could have
    caused deleted classes to stick around forever, consuming resources.  This
    originally manifested as MOH external processes that were not killed at
    reload time.
 (closes issue ASTERISK-15170, closes issue ASTERISK-15102)
  Reported by: parisioa, dcabot
  Patches:
        20091202__issue16279__2.diff.txt uploaded by tilghman (license 14)
  Tested by: parisioa, tilghman
........
 r232661 | tilghman | 2009-12-02 18:09:36 -0600 (Wed, 02 Dec 2009) | 2 lines
 
 Remove debugging line
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=232699
By: Andrew Parisio (parisioa) 2009-12-02 18:56:14.000-0600

Whoops, it's still broken.
When i start asterisk it loads my MOH stream.  When i connect and listen it works.   When i disconnect from the MOH stream, it then closes the mpg123 process.  When i connect again, i get nothing but dead air, it doesn't respawn the process.

I think it should not kill the mpg123 process when i disconnect.


By: Andrew Parisio (parisioa) 2009-12-02 19:02:43.000-0600

i cant reproduce the crashes but i've crashed asterisk 3 times so far just playing with it.  i should have 4 MOH classes.  i've listened to 3 of them at this point so those 3 are now dead.  the only one left is the 4th.

csgtacsip1:/usr/src# ps uax | grep mpg
root     12040 15.2  0.0   2736  1184 ?        S<   16:55   0:32 /usr/bin mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-mtc-aa02.stream.aol.com:80/stream/1074


check out this nasty moh show classes output.  i did it twice to show it printed out the exact same crazy stuff twice in a row.

csgtacsip1*CLI> moh show classes
Class: ngth: 0>
       Mode: o: <sip:1044@rtel.csgopenline.com:5060>
       Directory:  Local/1593@inside-leg-cd0e;1
Variable: __SIPADDHEADER
Value: Alert-Info: ;info=alert-autoanswer
Uniqueid: 1259801742.24


       Format: unknown
Class: : talk, hold, conference, LocalModeStatus
       Mode: <none>
       Directory: ,realm="asterisk",nonce="1439fd78",uri="sip:rtel.csgopenline.com:5060",response="574d4664d021e14060639ce2b2bdb42c",algorithm=MD5
       Format: unknown
Class: default
       Mode: files
       Directory: /var/lib/asterisk/moh
Class: e.com:5060
       Mode: one" <sip:1517@192.168.16.226:5060;transport=udp>;expires=30;+sip.instance="<urn:uuid:00000000-0000-1000-8000-00085D20F49F>"
       Directory: 3a22d41f
       Format: unknown
Class: Hitz
       Mode: custom
       Directory: nodir
       Application: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-mtc-aa02.stream.aol.com:80/stream/1074
       Format: slin
[Dec  2 16:57:08] ERROR[12070]: astobj2.c:116 INTERNAL_OBJ: bad magic number 0x654c2d74 for 0x88ecfe0
[Dec  2 16:57:08] ERROR[12070]: astobj2.c:116 INTERNAL_OBJ: bad magic number 0x654c2d74 for 0x88ecfe0
[Dec  2 16:57:08] ERROR[12070]: astobj2.c:116 INTERNAL_OBJ: bad magic number 0x73746e65 for 0x88ed2f0
[Dec  2 16:57:08] ERROR[12070]: astobj2.c:116 INTERNAL_OBJ: bad magic number 0x73746e65 for 0x88ed2f0
[Dec  2 16:57:08] ERROR[12070]: astobj2.c:116 INTERNAL_OBJ: bad magic number 0x6e696c6e for 0x88eccd0
[Dec  2 16:57:08] ERROR[12070]: astobj2.c:116 INTERNAL_OBJ: bad magic number 0x6e696c6e for 0x88eccd0
csgtacsip1*CLI>
csgtacsip1*CLI>
csgtacsip1*CLI>
csgtacsip1*CLI>
csgtacsip1*CLI>
csgtacsip1*CLI> moh show classes
Class: ngth: 0>
       Mode: o: <sip:1044@rtel.csgopenline.com:5060>
       Directory:  Local/1593@inside-leg-cd0e;1
Variable: __SIPADDHEADER
Value: Alert-Info: ;info=alert-autoanswer
Uniqueid: 1259801742.24


       Format: unknown
Class: : talk, hold, conference, LocalModeStatus
       Mode: <none>
       Directory: ,realm="asterisk",nonce="1439fd78",uri="sip:rtel.csgopenline.com:5060",response="574d4664d021e14060639ce2b2bdb42c",algorithm=MD5
       Format: unknown
Class: default
       Mode: files
       Directory: /var/lib/asterisk/moh
Class: e.com:5060
       Mode: one" <sip:1517@192.168.16.226:5060;transport=udp>;expires=30;+sip.instance="<urn:uuid:00000000-0000-1000-8000-00085D20F49F>"
       Directory: 3a22d41f
       Format: unknown
Class: Hitz
       Mode: custom
       Directory: nodir
       Application: /usr/bin/mpg123 -q -s --mono -r 8000 -f 8192 -b 0 http://scfire-mtc-aa02.stream.aol.com:80/stream/1074
       Format: slin
[Dec  2 16:57:45] ERROR[12070]: astobj2.c:116 INTERNAL_OBJ: bad magic number 0x654c2d74 for 0x88ecfe0
[Dec  2 16:57:45] ERROR[12070]: astobj2.c:116 INTERNAL_OBJ: bad magic number 0x654c2d74 for 0x88ecfe0
[Dec  2 16:57:45] ERROR[12070]: astobj2.c:116 INTERNAL_OBJ: bad magic number 0x73746e65 for 0x88ed2f0
[Dec  2 16:57:45] ERROR[12070]: astobj2.c:116 INTERNAL_OBJ: bad magic number 0x73746e65 for 0x88ed2f0
[Dec  2 16:57:45] ERROR[12070]: astobj2.c:116 INTERNAL_OBJ: bad magic number 0x6e696c6e for 0x88eccd0
[Dec  2 16:57:45] ERROR[12070]: astobj2.c:116 INTERNAL_OBJ: bad magic number 0x6e696c6e for 0x88eccd0
csgtacsip1*CLI>


By: Tilghman Lesher (tilghman) 2009-12-02 19:44:53.000-0600

What this actually looks like is unrelated memory corruption, probably by the SIP channel.  Let's open a new issue, and run your Asterisk under Valgrind, as specified in doc/valgrind.txt.  This should help us track down where this memory corruption is occurring.
By: Russell Bryant (russell) 2009-12-04 14:48:42.000-0600

Tilghman, please look at this a bit more.  Based on when the errors occur, and the invasive changes that were just committed, it really looks like a bug in the MOH code to me.
By: Tilghman Lesher (tilghman) 2009-12-04 15:23:26.000-0600

I hear you, but it still needs Valgrind output.
By: Andrew Parisio (parisioa) 2009-12-04 15:29:34.000-0600

it's attached to 16388.
https://issues.asterisk.org/file_download.php?file_id=24679&type=bug


By: Andrew Parisio (parisioa) 2009-12-04 19:04:59.000-0600

it happened again on SVN-branch-1.6.1-r232865. Screenshot attached to this and the other bug report because they are both open now.  Valgrind on the other.

nothing was happening either. it's 5pm on a friday and it exploded with nobody using it.
By: Digium Subversion (svnbot) 2009-12-08 12:35:17.000-0600

Repository: asterisk
Revision: 233718

U   trunk/res/res_musiconhold.c

------------------------------------------------------------------------
r233718 | tilghman | 2009-12-08 12:22:44 -0600 (Tue, 08 Dec 2009) | 8 lines

Find another ref leak and change how we manage module references.
(closes issue ASTERISK-15271, closes issue ASTERISK-15170, closes issue ASTERISK-15273)
Reported by: parisioa
Patches:
      20091208__issue16388.diff.txt uploaded by tilghman (license 14)
Tested by: parisioa, tilghman
Review: https://reviewboard.asterisk.org/r/442/

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=233718