Mumble 33% cpu use when disconnected

[jaggzh]

Description

So, when connected and listening to live audio from one other system, in Debian Stable's packaged mumble client, (1.3.4-1), the CPU use fluctuates, going up to maybe 16% here and there. (8 core system or so).

Once DISCONNECTED, however, I get 33%, give or take.
I ran an strace, and only see a poll() every split second or so.
But with -f I see quite a lot more. Within several seconds of logs I got
strace -fp 959856
(Then sorted, uniq'ed, and sorted -n'ed):

  17208 [pid 949860] getpid()                   = 949856
## This is 17000 calls to getpid() within seconds!

   1298 [pid 949860] write(11, "\1\0\0\0\0\0\0\0", 8) = 8
    990 [pid 949860] write(10, "W", 1)          = 1
    964 [pid 949860] read(13, "\1\0\0\0\0\0\0\0", 8) = 8
    960 [pid 949860] poll([{fd=9, events=POLLIN}, {fd=12, events=POLLIN}, {fd=13, events=POLLIN}], 3, -1) = 1 ([{fd=13, revents=POLLIN}])
    940 [pid 949860] read(9, "W", 10)           = 1
    935 [pid 949860] read(9, 0x7f807fffeb5e, 10) = -1 EAGAIN (Resource temporarily unavailable)
     25 [pid 949860] read(9, "WW", 10)          = 2

Here's another run, after restarting mumble (it automatically connects to my server, then I disconnect and check top for it (31%), then run..):

$ date; strace -fp $(pidof mumble) 2>&1 | head -20000 | sort | uniq -c | sort -rn | head -10; date
Fri 21 Jan 2022 08:54:29 AM PST
  14661 [pid 960190] getpid()                   = 960186
   1000 [pid 960190] write(11, "\1\0\0\0\0\0\0\0", 8) = 8
    850 [pid 960190] write(10, "W", 1)          = 1
    843 [pid 960190] read(13, "\1\0\0\0\0\0\0\0", 8) = 8
    838 [pid 960190] read(9, "W", 10)           = 1
    838 [pid 960190] poll([{fd=9, events=POLLIN}, {fd=12, events=POLLIN}, {fd=13, events=POLLIN}], 3, -1) = 1 ([{fd=13, revents=POLLIN}])
    805 [pid 960190] read(9, 0x7f007fffeb5e, 10) = -1 EAGAIN (Resource temporarily unavailable)
     15 [pid 960190] getpid( <unfinished ...>
     15 [pid 960190] <... getpid resumed>)      = 960186
     10 [pid 960186] <... poll resumed>)        = 0 (Timeout)
Fri 21 Jan 2022 08:54:34 AM PST

5 seconds there.

Steps to reproduce

1. Run mumble (perhaps with auto-connect to server enabled).
2. Disconnect
3. Make sure you're still on Debian Stable with Mumble 1.3.4-1 :)
4. Check top / htop
5. If you see such a high %, perhaps the above strace is called for.

Mumble version

1.3.4-1

Mumble component

Client

OS

Linux

Reproducible?

Yes

Additional information

No response

Relevant log output

No response

Screenshots

No response

[Krzmbrzl]

I have the feeling that this is essentially a duplicate of the high-CPU issues mentioned in #5408

Could you try switching to a different audio backend and/or disabling echo cancellation and noise suppression?

[jaggzh]

If I run mumble without 'auto-connect at start', and do not connect/disconnect, I get 7-9% cpu (why's mumble doing so much when not connected anyway? Checking 3 or 4 server statuses periodically isn't that tasking is it?)

Here's an strace, with mumble just run, not connected, and the server-connect window up:

Fri 21 Jan 2022 09:02:31 AM PST
  13137 [pid 960640] getpid()                   = 960634
    971 [pid 960640] write(11, "\1\0\0\0\0\0\0\0", 8) = 8
    799 [pid 960640] read(9, "W", 10)           = 1
    796 [pid 960640] read(9, 0x7f528fffeb5e, 10) = -1 EAGAIN (Resource temporarily unavailable)
    796 [pid 960640] read(13, "\1\0\0\0\0\0\0\0", 8) = 8
    791 [pid 960640] write(10, "W", 1)          = 1
    723 [pid 960640] poll([{fd=9, events=POLLIN}, {fd=12, events=POLLIN}, {fd=13, events=POLLIN}], 3, -1) = 1 ([{fd=13, revents=POLLIN}])
    132 [pid 960640] getpid( <unfinished ...>
    132 [pid 960640] <... getpid resumed>)      = 960634
    119 [pid 960634] <... futex resumed>)       = 0
Fri 21 Jan 2022 09:02:35 AM PST

Roughly the same amount of time to get 20k strace lines out, but lower CPU use.

1. If I close the server window, without connecting, it stays about the same (7-8% cpu).
2. Connecting raises it to 10-13% cpu
3. Disconnect, and cpu use rises, 13-16% right now. (Hey, it's not going to 30+%!)
4. Connect => 13-18%
5. Disconnect => 34%

[Krzmbrzl]

Could you try to compile Mumble yourself (build instructions) from current master or from the 1.4.x branch, to see if the issue can be reproduced with the latest version?

EDIT: I just tried it with a version built from the current master branch and I am unable to reproduce this issue.

[jaggzh]

I have the feeling that this is essentially a duplicate of the high-CPU issues mentioned in #5408

Could you try switching to a different audio backend and/or disabling echo cancellation and noise suppression?

I'll try. I am using PA by the way. I think we should add in to #5408 that, maybe, disconnecting from the server could also disconnect the audio? I think the only issue here is the possibility that text-to-speech might need audio. (I'm not using tts, since nobody's typing in chat, but it turns out it is enabled). Perhaps it could time out if no TTS is needed... and disconnect PA?

Okay, I switched both input and output to ALSA. (If I just switch input, sound cuts out when I Apply, and I can't get it to start until I go change Output to ALSA as well). Mumble is currently taking 13-16% when disconnected. Still strange, since reconnecting drops that to 8-13%.

[Krzmbrzl]

I think we should add in to #5408 that, maybe, disconnecting from the server could also disconnect the audio?

Yep. I added it

Still strange, since reconnecting drops that to 8-13%.

Strange indeed - now I am really curious if the issue persists with a more recent Mumble build 👀

[jaggzh]

Okay, just running a fresh build of mumble (no auto connect, and not connected), and performance is already better. 5%.

Okay, I just connected and it crashed. :)
`Fatal (internal) error in /home/jaguar/projects/src/mumble/3rdparty/opus/celt/celt_decoder.c, line 118: assertion failed: st->mode == opus_custom_mode_create(48000, 960, NULL)

(not sure what opus is -- saw it needed to be added as a build dep, and did).
(I am connecting to a server running 1.3.4-1)

[Krzmbrzl]

Alright, so it seems that the performance issue is probably fixed.

The issue you are seeing is described in #5302. Unfortunately we don't know the cause of this yet

(not sure what opus is -- saw it needed to be added as a build dep, and did).

It's the voice codec used to encode the audio streams.

I'd say that we can close this issue as probably fixed in a more recent version of Mumble and as already mentioned: for the crash we have a separate issue already.