I'm noticing 100% cpu usage on latest 2.2 appimages on my x86-64 arch linux machine
on both the oldest and earliest 2.2 AppImages available currently on https://ftp.osuosl.org/pub/musescore-nightlies/linux/x86_64/?C=M;O=D (which are e37f251 and bebdec5), I notice mscore-portable's CPU starts off at %104 and doesn't go down. Since I don't have earlier 2.2 AppImages to test, I can't easily trace down which commit caused this (unless someone can point me to an AppImage archive).
No console output out of the ordinary:
Jack appears to be installed on this system, so we'll use it.
initScoreFonts 0x2fb7f90
qt.network.ssl: QSslSocket: cannot resolve SSLv3_client_method
qt.network.ssl: QSslSocket: cannot resolve SSLv3_server_method
I should note that the distro's 2.1 doesn't have this CPU usage error.
Comments
I've just compiled latest 2.2 (3543170) in qt-creator as regular binary, not an AppImage, and still notice the %100 CPU usage. So the issue isn't related to AppImage packaging.
Looking at htop, the correspond thread in qt, thread #9 (the last spaned mscore thread), is apparently the thread eating all the CPU, and it seems to be stuck in AlsaDriver::write() at line:
from https://github.com/musescore/MuseScore/blob/9e275eb7ea8b1d078cc3573aa3e…
I'm guessing it is stuck waiting to gain a handle, but that never happens. I should note that I'm using Jack on this system.
Here is stacktrace:
1 poll 0x7fffedef497b
2 ?? 0x7ffff7280e30
3 snd_pcm_wait 0x7ffff728113c
4 Ms::AlsaDriver::write alsa.cpp 530 0x55555627dbca
5 Ms::AlsaAudio::alsaLoop alsa.cpp 691 0x55555627e7a4
6 Ms::alsaLoop alsa.cpp 652 0x55555627e480
7 start_thread 0x7ffff4f8908c
8 clone 0x7fffedefee7f
In reply to Looking at htop, the… by ericfontainejazz
According to https://www.alsa-project.org/alsa-doc/alsa-lib/group___p_c_m.html#gad4d… docs says it is "Wait for a PCM to become ready." and that the timeout parameter indicates maximum time in milliseconds to wait, a negative value means infinity (which alsa.cpp currently uses -1).
I'm thinking that should be set to 10,000 so that after 10 seconds of waiting, it gives up.
In reply to According to https://www… by ericfontainejazz
If I switch MuseScore to use Jack instead, then musescore no longer consumes all the CPU.
In reply to According to https://www… by ericfontainejazz
Well it turns out adding a finite timeout doesn't fix the problem. Because that function actually wasn't the thing the was stalling, but rather the AlsaDriver::write() loop outside of it which has an infinite for (;;) loop.
So what I could do instead is change that loop from infinite to finite after some very large number of iterations. Or maybe just provide some qDebug info... I don't know what is best.
In reply to Well it turns out adding a… by ericfontainejazz
so adding a sleep(1) at the end of that loop (when avail=0) fixes the CPU hogging problem. Whether or not that is the best way to go about this is debatable. Maybe during intialization could test if avial = 0 and print a qDebug message.
In reply to so adding a sleep(1) at the… by ericfontainejazz
What is interesting is that according to docs (https://www.alsa-project.org/alsa-doc/alsa-lib/group___p_c_m.html#ga8bb…) the function snd_pcm_avail_update should only return positive number of frames or should return a negative error code. There is no mention of that function returning a 0. So I don't know if the return value of 0 is documented or implemented behavior.
If the correct interpretation of 0 is that there are 0 frames that need to be written, then I suppose it makes sense to sleep. How long to sleep is a better question... Maybe just a millisecond?
In reply to What is interesting is that… by ericfontainejazz
sleeping a millisecond seems reasonable. If I sleep .1 ms, then it still uses too much cpu, like %10 of a CPU...but waiting a millisecond only wastes %1 a CPU.
In reply to sleeping a millisecond seems… by ericfontainejazz
Well I went ahead and made a PR with this change (although I didn't include "fix #" because I haven't made an issue): https://github.com/musescore/MuseScore/pull/3524
Maybe there is a better way to handle this.
In reply to Well I went ahead and made a… by ericfontainejazz
If you are not using alsa, maybe alsa::write shouldn't be called at all no ?
In reply to If you are not using alsa,… by [DELETED] 5
I think I'll agree with that. I'll try to check the alsa init logic to see why musescore is not aware in alsa's init that alsa isn't able to output.
although I'm still wondering if this sleep shuld be left in here for the case that avail = 0 (if that would happen in other circumstances).
In reply to I think I'll agree with that… by ericfontainejazz
I should note that I experience the same CPU hog bug when I don't have Jack running on my system. In either case (jack running before starting musescore or not), the Alsa::init() function succeeds. Why that init is succeding but still can't output audio is the question.
In reply to I should note that I… by ericfontainejazz
hmm...I don't think Jack has anything to do with it. I think the problem might be related to the fact I have PulseAudio running to. (FYI, most of my audio goes out to jack or to pulse audio, and in jack I have a pulseaudio-to-jack bridge). But I still wish musescore knew that alsa is not working, somehow. Maybe by trying to play a sound on init, I don't know.
In reply to hmm...I don't think Jack has… by ericfontainejazz
hmm....well I disabled pulseaudio, and now I can play musescore via alsa. But for some reason I'm noticing another CPU hog but this time in the main mscore thread. I don't know if it is related or not...I'll have to install debugging symbols now, cause is in a bunch of qt stuff.
In reply to hmm....well I disabled… by ericfontainejazz
Trying to nail down what specific configuration causes the problem. It seems the problem also affects 2.1 distro package, so has nothing to do with packaging and is not a result of a new commit since 2.1. Let me first show you my alsa devices list:
aplay --list-devices
**** List of PLAYBACK Hardware Devices ****
card 0: PCH [HDA Intel PCH], device 0: ALC269VC Analog [ALC269VC Analog]
Subdevices: 0/1
Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 3: HDMI 0 [HDMI 0]
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 7: HDMI 1 [HDMI 1]
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 8: HDMI 2 [HDMI 2]
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 9: HDMI 3 [HDMI 3]
Subdevices: 1/1
Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 10: HDMI 4 [HDMI 4]
Subdevices: 1/1
Subdevice #0: subdevice #0
Now the strage thing is alsa device 0,0 works fine if start with that setting, but I seem to have the CPU hog problem when I switch to one of the 5 HDMI devices on card 0 (3, 7, 8, 9, or 10). But if I start musescore with one of those devices in settgins, musescore doesn't experience the audio hog. Note I don't hear any output (probably cause my HDMI doesn't have audio output configured properly), but I do see the synthesizer volume meter react.
In reply to Trying to nail down what… by ericfontainejazz
I do see a lot of messages like:
AlsaDriver: recover: stat = 00, xrun of at least 1520527415868.270 ms
In reply to I do see a lot of messages… by ericfontainejazz
So I'm able to use and hear HDMI output 0 if I specify it like:
hdmi:CARD=PCH,DEV=0
In reply to So I'm able to use and hear… by ericfontainejazz
So in preferences gui if I put in any of the names outputted by:
aplay -L | grep :CARD
sysdefault:CARD=PCH
front:CARD=PCH,DEV=0
surround21:CARD=PCH,DEV=0
surround40:CARD=PCH,DEV=0
surround41:CARD=PCH,DEV=0
surround50:CARD=PCH,DEV=0
surround51:CARD=PCH,DEV=0
surround71:CARD=PCH,DEV=0
hdmi:CARD=PCH,DEV=0
hdmi:CARD=PCH,DEV=1
hdmi:CARD=PCH,DEV=2
hdmi:CARD=PCH,DEV=3
hdmi:CARD=PCH,DEV=4
sysdefault:CARD=U49e
Then I don't experience the CPU hog. However, if I type in names like "0,3" or "default", then I experience the CPU hog.
In reply to So in preferences gui if I… by ericfontainejazz
In some cases, I can get two cpu hogs happening at the same time in different threads, on in the alsa thread and one in the main thread.
In reply to In some cases, I can get two… by ericfontainejazz
so starting musescore with alsa hw:0,3 already in preferences works fine (no cpu hog, and I hear the output on hdmi).
In reply to so starting musescore with… by ericfontainejazz
if after starting musescore with alsa hw:0,3 (which works), if I then switch to hw:0,0 I get init ALSA audio driver failed. But I don't get a cpu bug cause alsa driver is not initialized (I simply don't get audio). If I then switch back to hw:0,3 then I get a CPU hog (in the main mscore thread, not the alsa thread) AND I get sound working.
In reply to if after starting musescore… by ericfontainejazz
I'm hearing the theme from "The Twilight Zone" playing. ;)
In reply to if after starting musescore… by ericfontainejazz
so if start with hw:0,3 then can go to hw:0,0 with no audio and no cpu hog, then can go to hw:0,3 and will get CPU hog in main mscore thread while alsa output works fine. If then go to 'default', then will get cpu hog in both main thread and alsa thread (and alsa output ofcourse doesn't work).
I'm trying to investigate all return error codes, but haven't received any. Alsa apparently says the output works but it doesn't.
In reply to so if start with hw:0,3 then… by ericfontainejazz
So looking at https://stackoverflow.com/questions/38789405/alsa-snd-pcm-avail-always-… someone else is experiencing the same phenomenon of snd_pcm_avail returning 0, and someone answers that "The device was never started. This would happen automatically with the first snd_pcm_read*() call, but can also be done explicitly with snd_pcm_start()".
I notice that snd_pcm_start is called with proper test for return code in AlsaDriver::pcmStart(), which is called in AlsaAudio::alsaLoop(), and Ms::alsaLoop is used as the main loop of the pthread that is created in AlsaAudio::start().
So what my theory now is: when musescore starts, pcmStart() gets called and returns success code, so the main alsa thread starts just fine. But then the alsa device gets changed to some device that would fail pcmStart(), but since the alsa thread is already running, it doesn't retry pcmStart().
So I think a solution might be to stop the alsa thread when the device (or maybe any other alsa settings) get changed, and then restart the thread.
In reply to So looking at https:/… by ericfontainejazz
But it doesn't just happen when switching configuration, cause the bug occurs when start mscore with 'default' as alsa device. I'm not noticing any unusual return codes.
In reply to But it doesn't just happen… by ericfontainejazz
I'm convinced that there may be a bug in Alsa. Cause the initialization isn't failing, when it probably should be failing.
I noticed this old ubuntu bug which doesn't seem resovled: https://bugs.launchpad.net/ubuntu/+source/linux/+bug/329620
I'm wondering if maybe I should clone the alsa source code and try to step through and nail this down. I'll try that tomorrow...please advise if any one else has ideas.
In reply to I'm convinced that there may… by ericfontainejazz
Starting mscore with 'bogus' as device name correctly fails to initilaize alsa.
In reply to I still get the alsa thread… by ericfontainejazz
So after much investigation, I found that I had configured my ~/.asoundrc file (attached) whereby I set my default device to pulse, which was the source of the problem. For some reason this config will cause alsa to not report any errors while initializing the device, even though the device never presents any available frames when trying to write to it. Basically deleting my custom ~/.asoundrc file and usnig my system's default (or changing the default alsa device to jack) seemed to avoid this problem. Attached is also my alsa config for future reference, should anyone stumble upon this.
I still think I have stumbled upon some alsa bug...because it seems to me that opening the device for playback should return an error if the device can't actually be written to.
In reply to So after much investigation,… by ericfontainejazz
One thing very strange is that AlsaDriver::pcmStart(), which is called before the write() function, succesfully gets a positive number of avilable frames from snd_pcm_avail_update(). So why it is able to get frames at the beginning during internalization, but not later, is the million dollar question.
In reply to One thing very strange is… by ericfontainejazz
Anyway, I found a somewhat clean way to deal with a device that fails to provide any frames after that init... At the end of pcmStart(), I wait 100ms and then check to see if there are any frames avaialbe. If not, then i assume that the device failed initialization:
https://github.com/ericfont/MuseScore/commit/33a3a69e96c77d67b9df8769be…
What I don't know is why the alsa test programs latency.c and pcm_min.c still work with the bad defautl device. Maybe becuase they aren't doing asynchornous writing?
I've just tried mscore-3.0-dev on my Raspberry Pi 3 B+ (newly-released 1.4 GHz revision), and unfortunately I've found this cpu-eating bug still persists when using audio output. Runs fine if I disable audio output.