Bug 5164 - SlimServer lockup with AACPlus radio streams and stop button
: SlimServer lockup with AACPlus radio streams and stop button
Status: CLOSED FIXED
Product: Logitech Media Server
Classification: Unclassified
Component: Audio
: 6.5.3
: PC Windows XP
: P2 normal (vote)
: ---
Assigned To: Ross Levine
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2007-07-13 10:09 UTC by Andy Connors
Modified: 2008-12-15 11:58 UTC (History)
3 users (show)

See Also:
Category: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Andy Connors 2007-07-13 10:09:48 UTC
Browser: Firefox 2.0.0.4

Steps to repeat (default web interface):
1) Set up SlimServer for AACplus radio streaming per Wiki page at http://wiki.slimdevices.com/index.cgi?AACplus
2) Using "Tune In URL", enter the following URL:  http://205.234.246.14/jazz-247-aacp
3) Let it play for a half minute or so.
4) Click "Stop" under "Music Player" in the right pane of the default web interface
5) Lockup occurs and SlimServer must be stopped to clear it.

Be sure to save any pending work you have before doing this, as the above steps result in near 100% CPU utilization, making it difficult to even invoke Task Manager.

This sequence works fine in 6.3.1.
Comment 1 Bryan Alton 2007-07-14 05:59:19 UTC
AACplus is not part of slimserver but since I created the config files - I'll own the bug and try to resolve it.

I've repeated your problem description on a clean Windows XP sp2 system and I've not had any probelm.  The stream stop and start without any problem and no need to restart Slimserver nor the server.

I did notice that when Slimserver is run as a user process (i.e. not set up in SlimTray to start at system startup or at login.) when the stream has been stopped,the support application socketwrapper CPU usage goes to 50%.  I have an Intel 3.0GHz CPU - what is the CPU on your system and how is SLimserver setup ? 
Do you have any other plugins installed ?

I'll have a look at socketwrapper and see what is happening.  I have been dealing with one outstanding unrelated sockertwrapper bug  so I am familiar with it.
Comment 2 Andy Connors 2007-07-14 12:10:16 UTC
My SlimServer setup is as follows:

"Automatically run at system start" - unchecked
"Automatically run at login" - unchecked
To run SlimServer, I do a "Start SlimServer", than an "Open SlimServer" from the system tray icon.

I tried your experiment, checking "Automatically run at system start".  Then I rebooted the system and did the "steps to repeat".  Everything worked fine and I couldn't repeat the problem.  But when I have "Automatically run at system start" unchecked and boot that way, the CPU usage goes to 100% every time after doing the "steps to repeat".  If I do this with Task Manager open while looking at the "Performance" tab, Task Manager stops updating almost entirely, taking 30 seconds or so for the CPU usage to update to the 100% value.  If I wait long enough, the high CPU usage eventually goes away.

My CPU is an AMD Athlon64 3000+.  It's single core.  I'm wondering if your CPU is dual core, giving 50% CPU usage on account of only maxing out one of the two cores?
Comment 3 Bryan Alton 2007-07-14 15:47:50 UTC
My process is an old Prescott with single Core with HyperThreading.  I used ProcessExplorer to monitor the processes as it p[rovide more info than TaskManager.

The issues relates to socketwrapper. A stream can stop intentioanlly or vy accident (network disconnect) - in etiehr case socketwrapper polls the inptu/output sockets checking if any data has passed through.  If nothing passes a timer of 60 secs expires and then socketwrapper shurs down mplayer.

That is the worst case - normally when a stream is stopped, mplayer will stop.  The timeout will occur if the data from mplayer has not been read by Slimserver.

The theory about "cores" might be partially right because socketwrapper uses VisualC threads but most of the time they are waiting for input/output. There must be something else because the same socketwrapper has been used since 6.5.1 and in fact any user of AlienBBC should have seen this problem. Also the different behaviour when run in different mode is odd. 

What version of mplayer are you using ?
I  think I'll have to build a debug version of socketwrapper for you to run to get a definitive idead of what socketwrapper is up to.
Comment 4 Andy Connors 2007-07-14 16:20:52 UTC
Here is my mplayer info:

MPlayer 1.0rc1-3.4.2 (C) 2000-2006 MPlayer Team
CPU: AMD Athlon(tm) 64 Processor 3000+ (Family: 15, Model: 44, Stepping: 2)
CPUflags:  MMX: 1 MMX2: 1 3DNow: 1 3DNow2: 1 SSE: 0 SSE2: 0

This appears to be the latest one.
Comment 5 Bryan Alton 2007-07-14 16:42:30 UTC
Mplayer changed handling of disconnect of output stream differently as some point last year - I need to check if it was in  1.0pre8 or 1.0rc1. It might be a contributing factor as most user will use the 1.0pre8 from AlienBBC.

Using ProcessExplorer - I can see that just one thread of Socketwrapper is taking 50% of my CPU for about 1 min.

The following is my theory. To ensure processing, the thread have been assigned priority boost of "Time Critical". When Slim is run as a process separate from the user this boost is only in relation to the Slim.exe but when Slim.exe is part of User process tree - the "Time Critical" boost means it is put ahead of ALL processes in the user space (e.g. any windows, Browser, task manager window).  What I need to find out is what is happening when the player is stopped - that's for tomorrow. 
Comment 6 KDF 2007-07-14 17:09:24 UTC
Bryan, thanks for looking into this.  Since you are taking ownership, let's assign this to you for now.  you can bounce it back to Chris or Ross for verification or extra testing if you need it.  Do you feel that this can be targetted for 6.5.4? Note that 6.5.4 isn't a guaranteed release version as yet.
Comment 7 Andy Connors 2007-07-14 18:38:07 UTC
Yes, thank you Bryan.

I've been doing some more digging on this with Process Explorer also.  When the 100 percent CPU usage finally goes away, that's when socketwrapper.exe and its child processes terminate.  I was able to induce a failure with the exact same pattern that does not involve mplayer.exe.  Just for clarity, I'll repeat that pattern again below:

1) Play internet radio stream
2) Click "Stop" in the web interface
3) Get 100 percent CPU usage for a minute or so
4) 100 percent CPU usage goes away when socketwrapper.exe and its children finally terminate

I had been having problems with some OGG internet radio streams that were causing the SB itself to hang, requiring power-down of the SB to reset it.  I found from reading some bug reports that by disabling the built-in OGG decoder, the stream could be made playable.  I did so, and this did indeed make the stream playable, but then when I clicked "Stop" in the UI, I got the pattern mentioned above, same as in the AACplus case with mplayer.exe.  But this time, the child processes of socketwrapper.exe were flac.exe and sox.exe.  In the mplayer scenario, the socketwrapper.exe child processes were flac.exe and mplayer.exe.  So this issue doesn't appear to be unique to mplayer.exe.  I suspected flac.exe as the common element.  But I disabled the flac encoding such that the only child process of socketwrapper.exe was sox.exe and the problem remained.

I then configured SlimServer to start at system startup to see if the socketwrapper problem with OGG streams went away as it does in the mplayer/AACplus case.  This time, the problem still occurred.
Comment 8 Bryan Alton 2007-07-15 09:53:40 UTC
The problem is in socketwrapper and is quite a simple one. 

The problem is when the input audio stream to socketwrapper comes via Slimserver. When the stream is stopped - the input to socketwrapper is closed but by design Windows doesn't provide an End-Of-File error to the thread processing input - it just returns 0 bytes read. So the input processing thread spins  - reading & writing 0 bytes as fast as it can at Time Critical priority so it will pre-empt other processes in the process tree.

The "input via Slimserver" is not usual - it looks like AACplus and Sox streams are the only ones but WMA streams decoded by SS may also be an issue.  So the problem is rare and to be noticed - it needs Windows, Single core processor with no hyperthreading playing AACplus or Sox streams.

I have a version which now works but I need to test different uses of socketwrapper to make sure there are no data truncation side effects. I'll post a link to the new version later today.
Comment 9 Bryan Alton 2007-07-15 16:31:47 UTC
The new version (1.10 beta) of socketrapper can be found here.
http://homepage.eircom.net/~altondsl/slim/socketwrapper110b.zip

Unzip and replace your existing socketwrapper. I've done some testing
of it and didn't see any problems but I haven't tested different startup Slimserver modes (system start, login start etc) yet.

Neither WMA streams with built-in disabled nor AlienBBC use socketwrapper in the way which caused problem in AACplus and Sox streams.
Comment 10 Andy Connors 2007-07-15 16:45:23 UTC
Thanks very much Bryan.

There's a four hour radio show on that station that I listen to every Sunday in its entirety.  It comes on shortly, so I'll be able to give the modified socketwrapper lots of testing.
Comment 11 Andy Connors 2007-07-15 21:37:28 UTC
I've just tested the modified socketwrapper.exe.  It's working really great.  The shutoff is very fast - in fact it has a kind of snappy feel to it, better than 6.3.1 was I think.  I tested it over a four hour period on the stream originally mentioned in this report.  Each time the DJ came on in between songs (which was often), I began rapidly clicking back and forth between "stop" and "play".  I did not experience a single glitch in the entire four hour session.  I have done only limited testing with sox streams so far.  This was testing the workaround for the bug with OGG stream decoding which requires disabling the built-in OGG decoder.  That's working fine too.  So this new socketwrapper.exe is a fix for two problems I was having.  I was having the problem of OGG streams crashing the SB hardware, but the fix for that was disabling the OGG decoder, which then was giving me the socketwrapper lockup before this fix.  Those problems are all gone now.

All testing was done with SlimServer run as a user process rather than launched at system startup.
Comment 12 Bryan Alton 2007-07-16 12:49:04 UTC
Kevin,
This should be alright for 6.5.4 - it also include my fix for bug#5128.  
 
Since it is a bug in socketwrapper and can occur with OGG streams which a Slimserver support format, I think QA should reproduce the problem and satisfy that I have fixed the bug and not broken any other use of socketwrapper.  I think QA should also run a few tests to be happy there is no truncation but since 6.5.3 there are fewer use cases where it could occur. 

Main symptom of the bug is user lockout for about 1 min on Single core processors or a burst of high CPU usage on multi core CPU (the user may notice the problem by an increase in the CPU or system fans)

For QA - how to reproduce and see/notice the bug:

1. Prerequisite - only tested on Windows XP but should also happen with Vista. Slimserver 6.5.2 or 6.5.3 with Socketwrapper 1.8.  Problem is easiest to see with a Single core CPU. You will need Task Manager/ProcessExplorer if using a single core with HyperThreading or a multi core processor.
2. Start Slimserver in user space - Both SlimTray options "Autmatically run at system startup " and "Autmatically run at login" are unchecked.   
3. If in doubt about socketwrapper version. Open a cmd prompt and run socketwrapper - it will print its version in a banner.  
4. Change Filetypes OGG and disable the "built-in" format.
5. Play with an SB2/3, using "Tune-in", the WCPE OGG stream  http://audio-ogg.ibiblio.org:8000/wcpe.ogg .  If the stream doesn't play then double check that "built-in" has been disabled.  
6. Start Task Manager. Open Processes Tab and check that socketwrapper and sox are running. Open performance tab and then select View/CPU History/One Graph Per CPU. ProcessExplorer does the same job if you open the "system Information" window.
7. Let it play for a short while .  Stop the stream either from Web Interface or remote.
8. Look at the CPU display - on a single CPU load will go to 100% and I believe may become usable for 1 min because of lockup.  On a multi-core system or Hyperhreaded - one CPU will go to 100%.  This will last from between 20secs to 1min and then socketwrapper and mplayer will stop.  The CPU usage graph is very square.

The updated version of socketwrapper is 1.10 beta with two changes from 1.8
1) Changes to stop socketwrapper crash per bug #5128 
2) Changes to fix this bug. 
In both cases, the change is to shutdown behaviour of socketwrapper so if there is a problem in other uses, it is likely to be truncation at the end of a song/stream.  I tested 1.10b with 6.5.2 which used socketwrapper more extensively and didn't have any truncation problems when playing a series of gapless tracks.
Comment 13 KDF 2007-07-16 14:19:20 UTC
ta.  I'll bounce this over to chris to sort out who to handle the tests and/or adding to the automated testing.
Comment 14 Chris Owens 2007-07-16 17:34:34 UTC
Ross has been doing the socketwrapper testing recently.  
Comment 15 Ross Levine 2007-07-18 13:59:58 UTC
Tested and looking good. I'm able to reproduce the crash easily, and socketwrapper 1.10 fixes that crash. I've also tested socketwrapper 1.10 against various transcoding settings with the gap test files and I'm not noticing a gap in any scenario. 

I did notice however that the AACplus streams still do not work with bitrate limiting, however that may not be a bug. 
Comment 16 Bryan Alton 2007-07-19 07:15:26 UTC
The bit rate limit issue has been raised in bug 4266 and that problem is not related to socketwrappper.

Before commiting this version to SVN, I'd be happier if bug 5128 can be closed as well.
Comment 17 Ross Levine 2007-07-23 15:34:34 UTC
With 5128 closed I think this new socketwrapper should be committed. Chris, do you have any issue with this? 
Comment 18 Chris Owens 2007-07-23 17:51:19 UTC
That sounds like the right decision to me.
Comment 19 Chris Owens 2007-09-18 12:36:10 UTC
Is this fixed with the 6.5.4 or later versions?
Comment 20 Bryan Alton 2007-09-19 14:47:58 UTC
Yes - it was rev 12528 in 6.5 which means it is in 6.5.4.  I've just been reminded to put it into trunk.
Comment 21 Blackketter Dean 2007-10-26 09:38:32 UTC
Bryan, has this been resolved?
Comment 22 Bryan Alton 2007-10-26 15:28:46 UTC
Yes - socketwrapper.exe was updated in trunk in change 13139.
Comment 23 Ross Levine 2007-11-14 17:26:38 UTC
Marking this as fixed and verified. 
Comment 24 James Richardson 2008-12-15 11:58:15 UTC
This bug has been fixed in the latest release of SqueezeCenter!

Please download the new version from http://www.slimdevices.com/su_downloads.html if you haven't already.  

If you are still experiencing this problem, feel free to reopen the bug with your new comments and we'll have another look.