High cpu load at playback #700
Comments
|
What process is using the CPU? Are you using Spotty? There's currently an issue with Spotty where using it in Connect mode would cause high CPU load. |
|
It's the squeezeboxserver process. I don't use Spotty. My active plugins are only:
//edit: I disabled all plugins for testing with the same result. |
|
What kind of content are you playing? Is transcoding involved? What endpoint are you using? |
|
It's a radio stream without transcoding. But that seams to be the right direction. Because everything is fine with an mp3 stream. But if I try AAC, then the higher load begins:
If I switch to the mp3-stream, immediatly I get <1% load. If I press Pause/Off nothing changes for a long time (means high CPU load). |
|
Ok, I can confirm high load. But it's more like 45% on a Pi4. I'll look into this. Or maybe @philippe44 has a great idea (cough, cough)? 😀 |
|
Can you confirm you're using "Proxied Streaming" (Settings/Player/Audio), and that the load would go away if you used "Direct Streaming" instead? |
|
I can confirm that "Direct Streaming" results in <1% CPU load. |
|
@philippe44 - I mentioned you because I thought this could be due to some of the new streaming handling. But I'm seeing the same behaviour with 7.9, and no problem with other AAC streams. So nothing you changed. This must be some oddity with this particular stream. |
|
For AAC inside a MP4, LMS does the frame management and that takes some CPU, but I'm surprised it would be 45% of a pi4. Can you put source logging to info and try on a real SB? |
|
I'm seeing the same behaviour with a Touch. Still around 50% CPU load on a 2020 Intel MacBook Pro! The frame management you mentioned didn't exist in 7.9 yet, did it? |
|
No, unwrapping AAC and putting them in ADTS is new, (can't remember if I added that in 8.0 or after) |
|
That stream does the same on MP3, so it's not related to AAC |
|
I think we can agree that this is a very special problem specific to this track? @derron7 - do you see similar behaviour with other streams? |
|
I've made a fair bit of analysis and it's really strange. It is only this server, when LMS proxies the stream. It is not linked to aac or mp3 format. It is not that the server is sending a ton of small responses (TCP packets) to the GET causing ton of sysreads. As far as LMS is concerned, it receives a normal flow of 2~8kB packets (in sysread) but it seems that something in the underlying layers of CPAN is consuming the CPU. I thought at some point of an issue with icy-metadata interval, but it's fine. I have no idea what that server does that is so specific. |
|
Oh, the crypto miner is hidden in the CPAN module! ;) I have the same behaviour in another stream: http://avw.mdr.de/streams/284340-0_aac_high.m3u I wouldn't really care about if the CPU/Case Fan would not be that loud. |
|
https://st03.sslstream.dlf.de/dlf/03/low/aac/stream.aac?aggregator=web https://st03.sslstream.dlf.de/dlf/03/mid/aac/stream.aac?aggregator=web https://st03.sslstream.dlf.de/dlf/03/high/aac/stream.aac?aggregator=web https://st03.sslstream.dlf.de/dlf/03/128/mp3/stream.mp3 I wonder that I also have a high load on the last mp3-Stream. |
|
Do I have any chance of solving this - maybe via LMS downgrade or CPAN update? |
|
This is the second time my LMS had 100% cpu load after a while listening to http://live.radioart.com/fFilm_scores.mp3?dlid= |
|
Sames issue on a LMS 8.2.0 on Ubuntu 20.04 (Intel x64) - a high load for some streams, independent of device (Baby or Squeezeplay on RPI). CPAN update did not help. Tried on 7.9.3 and 8.3.0 with no change of CPU load (CPU load stays at 30-40%) for specific streams and tested it with streams from derron7.. e.g. - High CPU Load No/very low CPU Load High CPU load stops only if another radio station (or something from the local library) is selected. Could it have something to do with 48khz instead of 44,1khz ? |
|
I'll try to have a look again but this one seems really complicated to investigate. @mimicko74 just to be sure, you are confirming that the problem is not related to LMS version, correct? |
|
So... I'm not a TCP expert, but consider the attached screenshot. One is with a working server (RadioParadise) and you'll see that the TCP WindowSize has scaled properly to 40kB where the one with rndfnk.com is stuck at the ridiculous 11 and cannot scale. It might be a problem of the underlying socket layers, but it's not LMS as such. These server seems to be dysfunctional in term of their TCP handling by having a scaling value of -1. I'll investigate more
|
|
Hej philippe44, thanks for looking into this. Yes, I can confirm that the cpu load is not related to the LMS version. I tried it on 7.9.2 to 8.3.0 with the same result. I tried to change faad to a little script with ffmpeg (from : http://www.siski.de/~carsten/radio-streaming-squeezebox.html#aac , in german) and exchanged the faad in /Bin to another faad binary - no changes. It could have something to do with the switch of the german radio stations to AAC LC in July - unfortunately it was "ARD" who are responsible for the majority of the german radiostations (NDR, MDR,SWR, BR, etc...), |
|
Hi saw the same issue with mp3 files. It seems to me that their server is configure in a way that prevents TCP Window Size to grow from a ridiculous value of 11, so basically we are killing the network stack |
Did Wireshark also capture the three-way handshake? See also https://osqa-ask.wireshark.org/questions/10071/window-size-scaling-factor-1-unknown/ |
|
My bad, I had to re-read my "TCP for dummies". So capturing the SYN, Wireshark was able to get the actual WindowSize and we have an actual 45kB window... wrong lead then 😕 I really don't know what's happening there. All I can say at that point is that the tcpdump capture appears much slower that another same bitrate but low CPU stream. |
|
I have Playing https://liveradio.swr.de/tn2d2ac/swr1bw/: Only difference I can see are some differences between the involuntary context switches. Not much to go on. |
|
Would profiling using nytprof provide some insights? |
|
I wiresharked the streams from my server to a SqueezePlay Client on my windows machine. No 1650 is the switch to SWR1 (the stream with the high cpu load). After the switch of the station the server floods out a lot traffic. Unluckily I am not able to interpret the data any further :( Additionally here the tail from the server.log with network.http on debug while playing SWR1 radio : |
|
I am encountering the same issues with high CPU load.
@philippe44: |
|
Streams would automatically be proxied if the player didn't support https. |
|
Yes, this only happens when the stream is being proxied by LMS, which can happen because user wants to, player does not support HTTPS, transcoding is required, or seeking requires special HTTP handling and a few other cases I'm probably forgetting. In other words, the culprit is in the network layers used by LMS but I have no idea of what is happening - this one if a big mystery for me... |
|
Would anybody know of another https stream we could test? All I've tried so far are http only. Decoding encrypted data certainly has some impact. But I believe it shouldn't be that much. |
|
Found https://stream.srg-ssr.ch/m/drs3/aacp_96 - which would leave the CPU at 1-2%, whereas rndfnk.com usually are at around 30% on a M1 Mac mini. |
|
Hello everybody, my name is Alexander Leschinsky, co-founder and managing director of G&L Geißendörfer & Leschinsky GmbH. We are indeed operating the audio distribution platform rndfnk.com. Thanks for reaching out to us. Generally, we are not aware of any issues with CPU load when playing back streams we deliver. We are very curious to see what is causing this with LMS. I have dedicated a Perl engineer to look into these issues starting tomorrow, December 14th. We might come back with questions about LMS to this thread, as we had not been using this software before. I'd like to list a few test streams here:
These are not covering all combinations, but still might be helpful to localize the issue. |
|
It would be helpful to know if the issue can be observed for streams that are using rndfnk.com, but different encoder vendors, like streams 3, 7, and 11. |
|
A quick tests shows that it seems to affect all streams from rndfnk.com with HTTPS. No matter which encoder and for both MP3 and AAC. Also the HTTPS streams from addradio.de and audiostream.io have no issue. |
|
@Phil1pp this is really helpful. rndfnk.com and radiomast.io share the same underlying streaming software, RSAS. We will focus our examination tomorrow on RSAS streams with HTTPS, then. |
|
Ok, here's my results. First of all: https is NOT the culprit. What @Phil1pp most likely is seeing is that the CPU load in LMS is lower because http can be streamed to the player directly. https on the other hand is proxied through LMS (the players can't do https). If you enabled proxied streaming in Settings/Player/Audio, you'd see the same load in LMS for http vs. https. Here's what I've found playing rndfnk.m3u.txt (remove .txt from the end to use it as a playlist): Where
I ran all testing on a 2020 Intel based MacBook Pro. Those numbers are for the Perl process (LMS) on a single core. I enabled proxied streaming for all playback. As you can see there's no real difference between http and https, but certainly between the different stations. |
|
That correlates, with much higher cases, what I observed a while ago: this is purely due to LMS proxying the stream. I guess we'd need some profiling but I don't know if it can be done with the size of LMS. Again, they might need to be redone, but I took some extensive wireshark traces being convinced that the issue would at the tcp level and all all showed a correct receive window size and normal length packets. On LMS side we don't seem to receive small packets either. One thing is that I don't seem to have observed a cpu difference on windows. |
|
Any findings so far? This situation seems to be leading to LMS hanging at some point. I've seen three or four reports so far about LMS no longer responding where it turns out that these were all German users suffering from this issue. Reports seen for Windows as well as Linux systems (see eg. #714). |
|
No, I've not been able to find some time and I know it will be a difficult one, looking at what I've already tried. I think I will have to profile the whole slimserver.pl and I don't expect that to be easy. BTW, on a different topic, there is still socket exhaustion in LMS with players that come and go all the time. I thought I fixed it but no. |
|
Just wanted to mention here, that Im also effected by this issue. Using rndfnk stream |
|
Merry Christmas! I have resolved it for my setup by using the http mp3 streams instead of the https versions (I just removed the "s" from the https-URL)
With this, the CPU load gets back to near zero. So it might (in the end) have something to do with https? (specifically with the streams from rndfnk.com?) I also removed the content of the CPAN folder to the bare minimum and use the up-to-date versions. But this seems to have nothing to do with the CPU load - as the CPU load remains low on all tried versions with a complete CPAN folder (7.9.2 - 8.3.0). |
|
No I don't think it's HTTPS. I've done some verification earlier which seems to indicate it's purely server dependent. What happens in your example is that likely the stream is sent directly to the player (no proxy) and the issue happens as soon as LMS proxies such streams, regardless of the format or protocol (HTTP/HTTPS). |
|
I've setup the profiler and I'm getting results. Need a bit more time to read them properly but there is an obvious HUGE difference in term of number of times we call readChunk/sysread (like for 60s of playback, one is called 2000 times the other 130,000 times |
|
So ... first data says that when it's time to read the ICY metadata, we spend a HUGE amount of time calling readChunk with probably no success. In 60s, readMetadata is called about 70 times but in one case it consumes 16,000,000 cycles and in the other case 12,000 cycles - I'll do some traces now that I know where the issue sits |
|
The hypothesis is that these radio align their chunks with icy metadata blocks. When offset has been reached to read icy, LMS enters a busy loop to read the one byte that gives the icy length. As it is a radio stream, then that 1st byte will arrive "much" later with the next chunk but LMS cycles on it. I'll verify that [edit]: This is confirmed, now I can't think of an elegant solution that does require some re-architecturing. The ugly PR for now is to add in Slim::Player::Protocols::HTPP.pm::readMetadata, line 215 (after the else) It takes care of the issue but it is so ugly... |
|
I think I have a solution with read "behind" instead of read "ahead" - See #718 |
|
This should be fixed in 8.3 via @philippe44's change in #718. Please give it a try. Thanks a lot, @philippe44! |
|
This fix (v8.3 beta) works for me! CPU load is 0,5-0,8 in average and 3% at maximum with 3 synced Players. Thank you very much @philippe44 and @mherger! |
|
I think we can consider this done. Thanks again, @philippe44! |
Hello, for some time (probably since the update to 8.2.0) I have had problems with a high CPU load at all times during playback. You could think that the server is mining cryptos ;)
I use LMS in a Debian 9 container with an Intel NUC I5. Usually it should not be challenged. Several Squeezeboxes and piCorePlayers are connected. It doesn't matter which player I choose.
Were there any changes to the playback in the last update(s)?
Are there logging features to help you/me find the problem?
The text was updated successfully, but these errors were encountered: