[Home]

Summary:ASTERISK-01002: request wav moh type - mpg123 cause crash
Reporter:jharragi (jharragi)Labels:
Date Opened:2004-02-06 08:32:04.000-0600Date Closed:2008-01-15 14:44:05.000-0600
Priority:CriticalRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) bt.040220
Description:Development on the decoder has stalled yet encoding features continue to advance. Thus the mpg123 trouble will never go away and may continue to get worse. 16 bit 8khz wav for moh will solve this.

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

Problem particularly bad on RH9 (still with latest kernel... with RHs up2date).
Comments:By: Brian West (bkw918) 2004-02-06 09:40:09.000-0600

can you provide a bt or some more info.  I use mpg123 and never have any crashes related to it.  bt or something simlar would be helpful
By: jharragi (jharragi) 2004-02-06 14:33:38.000-0600

Sure, check out this thread. Also, it appears to me the problem is more pronounced on RH9.
http://lists.digium.com/pipermail/asterisk-users/2004-February/035895.html
By: Brian West (bkw918) 2004-02-06 21:51:11.000-0600

Don't create your mp3s @ 8000hz mpg123 will resample them.
By: Brian West (bkw918) 2004-02-06 23:18:23.000-0600

We can't reproduce this if you can provide me with a backtrace or other such info (ie run under safe_asterisk) then

gdb asterisk /tmp/core.XXXX (XXXX being the pid of the process that droped the core.  Then we can get a better idea of what is going on.

bkw
By: jharragi (jharragi) 2004-02-07 01:47:22.000-0600

backtrace provided.

http://lists.digium.com/pipermail/asterisk-users/2004-February/036218.htm

Core was generated by `asterisk -vvvfg'.
Program terminated with signal 11, Segmentation fault.
#0  0x0805781d in ?? ()
(gdb) bt full
#0  0x0805781d in ?? ()
No symbol table info available.
#1  0x41c1cf8f in ?? ()
No symbol table info available.
#2  0x41c2d8ce in ?? ()
No symbol table info available.
#3  0x41c28655 in ?? ()
No symbol table info available.
#4  0x41c22410 in ?? ()
No symbol table info available.
ASTERISK-1  0x08051790 in ?? ()
No symbol table info available.
ASTERISK-2  0x41c1ee62 in ?? ()
No symbol table info available.
ASTERISK-3  0x4002d484 in ?? ()
No symbol table info available.

this is  -vvv output leading up to crash (then restart at  == Parsing...).


  -- Stopped music on hold on Parked/IAX2[ec@ec]/4<ZOMBIE>
== Spawn extension (hc_fxs, 501, 1) exited non-zero on 'Zap/13-1'
  -- Hungup 'Zap/13-1'
  -- Started music on hold, class 'default', on IAX2[ec@ec]/4
== Parked IAX2[ec@ec]/4 on 501
Ouch ... error while writing audio data: : Broken pipe
== Parsing '/etc/asterisk/asterisk.conf': Found
sterisk CVS-01/20/04-17:15:14, Copyright (C) 1999-2001 Linux Support
Services, Inc.

I can't get any additional info until monday. I can certainly try re-encoding to any recommended mp3 spec and encoder as well (this exemplifies the mpg problem). As for reproducing the problem, 'Ouch ... Broken pipe' has been reoccuring for a long time.
By: jharragi (jharragi) 2004-02-07 11:28:59.000-0600

One more thing... this switch is probably handling over a thousand calls (a few hundred of which get parked) between crashes so reproducability will be low. Futhuremore, the frequency was much lower prior to an upgrade from RH8 to 9 plus the most recent RH patches, (* config remained the same - but new cvs) so it may occur less or not at all on other platforms.
An additional comment, if I use the most common mp3 encoding, 128 kbps 44.1 stereo, on the basis that mpg123 is better tested and more solid in this mode, the mp3s are no smaller than a native wav file. Therefore mpg123 is a complete waste of cpu cycles - with absolutely no benefits...

edited on: 02-07-04 11:46
By: Brian West (bkw918) 2004-02-07 20:06:29.000-0600

mpg123 doesn't waste CPU if you notice the stream stops when MOH isn't needed and only starts when its needed.  mp3's at 128k, 44.1 are ALOT smaller than the wav counterpart at 44.1 stereo.   I think your bug is related to crashing while parking on iax2 take a look at bug 986.  I have had many people look at this bug we dont see this happening.... Run under safe asterisk (I have another bug in mind that it might be related to but I cant tell unless you run under safe_asterisk to see if it goes away)
By: jharragi (jharragi) 2004-02-09 09:42:04.000-0600

You would store wavs at 8khz mono - this is 128kbps (16bits/sample X 8k samples/second). Same size, no extra CPU cycles for decoding, mixing L&R and resampling! 128kbps mp3s are completely a waste.

Going back to the immediate problem...

From what I understand about bug 986 it looks like the channel retrieving the parked call is getting hung. I am getting a crash of the * program. I just spoke to the receptionist at that building. The crash is occurring when a call is parked rather than when she is retreiving it.

This system is running in our own 'safe mode' that captures the verbose output - I will try it in the regular safe mode. If you look at the -vvvc output...
The broken pipe line is from mpg123. This is the last line output by * before the restart.
'Ouch ... error while writing audio data: : Broken pipe'
(If you search through the mail list, you will see this has been an ongoing issue appearing since the introduction of moh.)
ASTERISK CRASHES at this point. The next lines after this is asterisk restarting...

== Parsing '/etc/asterisk/asterisk.conf': Not found (No such file or directory)
Asterisk CVS-02/04/04-19:23:58, Copyright (C) 1999-2001 Linux Support Services
, Inc.
Written by Mark Spencer <markster@linux-support.net>
By: Brian West (bkw918) 2004-02-09 09:52:54.000-0600

Why do you have no asterisk.conf?
By: Brian West (bkw918) 2004-02-09 09:53:50.000-0600

"asterisk -vvvg -c" is the cli options safe_asterisk uses.
By: jharragi (jharragi) 2004-02-09 10:43:40.000-0600

Good point with asterisk.conf. This machine was set up over a year and a half ago. Hadn't noticed it missing & have not run 'make samples' - till now. I'm moving in the 128 kbps mp3s next. I'll let you know how it works out.
By: Brian West (bkw918) 2004-02-09 10:48:43.000-0600

I bet that could be part of it.. but it shouldn't crash it should be graceful.

hrm
By: jharragi (jharragi) 2004-02-09 12:23:13.000-0600

I have second machine that has this problem which is not missing config files (Also, we have a couple more that don't use moh that run solid).
By: jharragi (jharragi) 2004-02-10 13:27:36.000-0600

OK I changed the mp3s on both boxes to encoded as 44.1 stereo 128kbps constant bitrate (which are a tiny bit larger than 8k mono wavs - I assume due to header & framing). I did many many parkings on the box with the most trouble and it seems ok.

Coincidentally I just got a crash on the second box (with new mp3s). This one was flashed on hold. I have left a little more of the cli output. Again the crash is preceeded by the 'Broken pipe' output line from mpg123...

   -- Channel 13 flashed to other channel Zap/13-1
   -- IAX2[ec]/2 is ringing
   -- IAX2[ec]/2 stopped sounds
   -- IAX2[ec]/2 answered Zap/9-1
   -- Starting simple switch on 'Zap/13-2'
   -- Started three way call on channel 13
   -- Started music on hold, class 'default', on IAX2[ec@ec]/1
   -- Executing Macro("Zap/13-2", "stdexten|18|20|0") in new stack
   -- Executing GotoIf("Zap/13-2", "0?s|3:s|2") in new stack
   -- Goto (macro-stdexten,s,2)
   -- Executing SetVar("Zap/13-2", "ARG3=6141") in new stack
   -- Executing Dial("Zap/13-2", "Zap/18|20") in new stack
   -- Called 18
   -- Zap/18-1 is ringing
   -- Zap/18-1 is ringing
   -- Zap/18-1 answered Zap/13-2
   -- Attempting native bridge of Zap/13-2 and Zap/18-1
   -- Starting simple switch on 'Zap/10-1'
   -- Stopped music on hold on IAX2[ec@ec]/1
   -- Hungup 'Zap/18-1<MASQ>'
Ouch ... error while writing audio data: : Broken pipe
 == Parsing '/etc/asterisk/asterisk.conf': Found
Asterisk CVS-01/20/04-17:15:14, Copyright (C) 1999-2001 Linux Support Services
, Inc.
Written by Mark Spencer <markster@linux-support.net>
=========================================================================
 == Parsing '/etc/asterisk/logger.conf': Found
Asterisk Event Logger Started /var/log/asterisk/event_log
 == Manager registered action Ping
By: Brian West (bkw918) 2004-02-10 14:07:18.000-0600

this isn't mpg123 related... Can you get me a bt of this?
By: jharragi (jharragi) 2004-02-10 14:55:43.000-0600

This GDB was configured as "i386-redhat-linux-gnu".
Core was generated by `asterisk -vvvfg'.
Program terminated with signal 11, Segmentation fault.
#0  0x41d6c150 in ?? ()
(gdb) bt
#0  0x41d6c150 in ?? ()
#1  0x41d671df in ?? ()
#2  0x0805c34b in ?? ()
#3  0x418bad7a in ?? ()
#4  0x41dbe08f in ?? ()
ASTERISK-1  0x08063f5a in ?? ()
ASTERISK-2  0x0806b521 in ?? ()
ASTERISK-3  0x0806a465 in ?? ()
ASTERISK-4  0x41e34444 in ?? ()
ASTERISK-5  0x08063f5a in ?? ()
ASTERISK-6 0x0806b521 in ?? ()
ASTERISK-7 0x08065f1c in ?? ()
ASTERISK-8 0x41d63b48 in ?? ()
ASTERISK-9 0x4002d484 in ?? ()
By: Brian West (bkw918) 2004-02-10 15:17:06.000-0600

you have to do this "gdb asterisk corefilename"
By: Brian West (bkw918) 2004-02-10 15:21:11.000-0600

also gdb /path/to/asterisk /tmp/core.pid

What codec are you using?
By: jharragi (jharragi) 2004-02-10 15:27:02.000-0600

Thanks, this is much more informative... I'm learning.
(gdb) bt
#0  zt_unlink (slave=0x810c998, master=0x8106b78) at chan_zap.c:2206
#1  0x41d671df in zt_bridge (c0=0x8156bf0, c1=0x815a658, flags=0, fo=0x4b145de0, rc=0x4b145de4)
   at chan_zap.c:2479
#2  0x0805c34b in ast_channel_bridge (c0=0x810c998, c1=0x4b145de4, flags=0, fo=0x4b145de0, rc=0x4b145de4)
   at channel.c:2224
#3  0x418bad7a in ast_bridge_call (chan=0x8156bf0, peer=0x815a658, allowredirect_in=0, allowredirect_out=0,
   allowdisconnect=0) at res_parking.c:224
#4  0x41dbe08f in dial_exec (chan=0x8156bf0, data=0x8156bf0) at app_dial.c:697
ASTERISK-1  0x08063f5a in pbx_exec (c=0x8156bf0, app=0x80ee778, data=0x4b146778, newstack=1) at pbx.c:396
ASTERISK-2  0x0806b521 in pbx_extension_helper (c=0x8156bf0, context=0x8156d48 "macro-stdexten",
   exten=0x815a658 "Zap/13-1<ZOMBIE>", priority=3,
   callerid=0x80dac18 "\"MW PPS 6124 amormile\" <845-460-6120>", action=1104942452) at pbx.c:1170
ASTERISK-3  0x0806a465 in ast_spawn_extension (c=0x0, context=0x0, exten=0x0, priority=0, callerid=0x0) at pbx.c:1654
ASTERISK-4  0x41e34444 in macro_exec (chan=0x8156bf0, data=0x8156bf0) at app_macro.c:140
ASTERISK-5  0x08063f5a in pbx_exec (c=0x8156bf0, app=0x8135460, data=0x4b1471c8, newstack=1) at pbx.c:396
ASTERISK-6 0x0806b521 in pbx_extension_helper (c=0x8156bf0, context=0x8156d48 "macro-stdexten",
   exten=0x4b1471c8 "stdexten|18|20|0", priority=1,
   callerid=0x80dac18 "\"MW PPS 6124 amormile\" <845-460-6120>", action=1104942452) at pbx.c:1170
ASTERISK-7 0x08065f1c in ast_pbx_run (c=0x41dc1574) at pbx.c:1654
ASTERISK-8 0x41d63b48 in ss_thread (data=0x8156bf0) at chan_zap.c:4351
ASTERISK-9 0x4002d484 in start_thread () from /lib/tls/libpthread.so.0
By: jharragi (jharragi) 2004-02-10 16:10:48.000-0600

I am using the ulaw codec.
By: Brian West (bkw918) 2004-02-10 17:21:11.000-0600

See this isn't related to moh... but seems to be something related to chan_zap.  What exactly are you doing when this happens?  Are you parking a call ? if so via what? IAX ZAP SIP ?
By: Brian West (bkw918) 2004-02-10 17:25:41.000-0600

Find me or kram on IRC.  #asterisk on irc.freenode.net kram wants to take a first hand look at this crash.
By: Mark Spencer (markster) 2004-02-19 19:32:14.000-0600

I believe this is now resolved, actually unrelated to mpg123...
By: jharragi (jharragi) 2004-02-20 15:46:39.000-0600

I got another crash on the machine we were working on yesterday. The messages that preceeded the crash were slightly different then usual - but definitely in the same department. I included the few output lines before the crash a bt  and full bt for threads 2 & 3 in bt.040220.

Thanks, John
By: Mark Spencer (markster) 2004-02-20 16:37:28.000-0600

Okay, another pass.  This time I'm working on solidifying the effects of the masquerade deep within chan_zap.  I think this is a byproduct of the RedHat 9 threading model showing some weaknesses that have been in there for a while.  Anyway try it out and let me know.
By: jharragi (jharragi) 2004-02-25 11:52:27.000-0600

I cvs updated as soon as you put up the patch. Glitch free on both machines so far...
By: Digium Subversion (svnbot) 2008-01-15 14:44:05.000-0600

Repository: asterisk
Revision: 2208

U   trunk/channels/chan_zap.c

------------------------------------------------------------------------
r2208 | markster | 2008-01-15 14:44:05 -0600 (Tue, 15 Jan 2008) | 2 lines

Properly lock slave and master in zt_unlink (bug ASTERISK-1002)

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

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