canonical / multipass

Multipass orchestrates virtual Ubuntu instances
https://multipass.run
GNU General Public License v3.0
7.86k stars 650 forks source link

Potential memory leak in multipass.gui #2233

Open ColinIanKing opened 3 years ago

ColinIanKing commented 3 years ago

In an effort to reduce CPU usage and hence reduce power consumption on laptops I noticed multipass-gui is not very idle and causing wake up events that prevent CPUs from going into deep sleep states:

I ran health-check on the process(es) and we get the following activity on an "idle" laptop:

uname -a
Linux lenovo 5.13.0-12-generic #12 SMP Thu Jul 22 08:02:41 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu Impish Indri (development branch)
Release:    21.10
Codename:   impish

 sudo health-check -p multipass.gui

CPU usage (in terms of 1 CPU):
     PID Process USR% SYS% TOTAL% Duration
    3448 multipass.gui 0.20 0.18 0.38 60.00 (very light load)

Page Faults:
     PID Process Minor/sec Major/sec Total/sec
    3448 multipass.gui 0.17 0.00 0.17

Context Switches:
     PID Process Voluntary Involuntary Total
                               Ctxt Sw/Sec Ctxt Sw/Sec Ctxt Sw/Sec
    3448 multipass.gui 51.72 0.02 51.73 (moderate)
    3747 multipass.gui 14.57 0.00 14.57 (moderate)
    3746 multipass.gui 14.12 0.00 14.12 (moderate)
    3750 multipass.gui 4.12 0.00 4.12 (low)
    3735 multipass.gui 3.95 0.00 3.95 (low)
    3646 multipass.gui 1.87 0.00 1.87 (low)
    3736 multipass.gui 0.00 0.00 0.00 (idle)
    3689 multipass.gui 0.00 0.00 0.00 (idle)
    3688 multipass.gui 0.00 0.00 0.00 (idle)
 Total 90.33 0.02 90.35

File I/O operations:
 No file I/O operations detected.

System calls traced:
     PID Process Syscall Count Rate/Sec Total μSecs % Call Time
    3448 multipass.gui poll 250 4.1666 58811927 16.7992
    3448 multipass.gui futex 194 3.2333 19837 0.0057
    3448 multipass.gui read 190 3.1666 8968 0.0026
    3448 multipass.gui write 183 3.0499 16374 0.0047
    3448 multipass.gui stat 180 3.0000 7485 0.0021
    3448 multipass.gui openat 120 2.0000 7879 0.0023
    3448 multipass.gui close 120 2.0000 4386 0.0013
    3448 multipass.gui access 60 1.0000 4097 0.0012
    3448 multipass.gui restart_syscall 1 0.0167 108620 0.0310
    3646 multipass.gui recvmsg 16 0.2667 1732 0.0005
    3646 multipass.gui write 16 0.2667 1712 0.0005
    3646 multipass.gui poll 16 0.2667 49636001 14.1782
    3646 multipass.gui restart_syscall 1 0.0167 8082750 2.3088
    3688 multipass.gui futex 1 0.0167 0 0.0000
    3689 multipass.gui futex 1 0.0167 0 0.0000
    3735 multipass.gui futex 78 1.3000 55985585 15.9919
    3735 multipass.gui epoll_wait 6 0.1000 796 0.0002
    3735 multipass.gui restart_syscall 1 0.0167 330956 0.0945
    3736 multipass.gui restart_syscall 1 0.0167 0 0.0000
    3746 multipass.gui recvmsg 114 1.9000 5969 0.0017
    3746 multipass.gui futex 102 1.7000 57937295 16.5494
    3746 multipass.gui write 90 1.5000 4118 0.0012
    3746 multipass.gui epoll_wait 56 0.9333 7297 0.0021
    3746 multipass.gui sendmsg 32 0.5333 3991 0.0011
    3746 multipass.gui mprotect 2 0.0333 86 0.0000
    3746 multipass.gui restart_syscall 1 0.0167 108987 0.0311
    3747 multipass.gui recvmsg 119 1.9833 5170 0.0015
    3747 multipass.gui futex 109 1.8166 57942254 16.5508
    3747 multipass.gui write 90 1.5000 3325 0.0009
    3747 multipass.gui epoll_wait 56 0.9333 6840 0.0020
    3747 multipass.gui sendmsg 33 0.5500 3200 0.0009
    3747 multipass.gui mprotect 1 0.0167 45 0.0000
    3747 multipass.gui restart_syscall 1 0.0167 1110219 0.3171
    3750 multipass.gui futex 82 1.3666 59918248 17.1153
    3750 multipass.gui epoll_wait 6 0.1000 706 0.0002
 Total 2329 38.8160 350086855

Top polling system calls:
     PID Process Syscall Rate/Sec Infinite Zero Minimum Maximum Average
                                                             Timeouts Timeouts Timeout Timeout Timeout
    3448 multipass.gui poll 4.1666 0 63 0.0 sec 1.0 sec 714.6 msec
    3646 multipass.gui poll 0.2667 16 0 0.0 sec 0.0 sec 0.0 sec
    3735 multipass.gui epoll_wait 0.1000 0 6 0.0 sec 0.0 sec 0.0 sec
    3746 multipass.gui epoll_wait 0.9333 56 0 0.0 sec 0.0 sec 0.0 sec
    3747 multipass.gui epoll_wait 0.9333 56 0 0.0 sec 0.0 sec 0.0 sec
    3750 multipass.gui epoll_wait 0.1000 0 6 0.0 sec 0.0 sec 0.0 sec
 Total 6.4999 128 75

Distribution of poll timeout times:
                                                            10.0 100.0 1.0 10.0 100.0 1.0 10.0 100.0
                                                    up to to to to to to to to or more
                                              Zero 9.9 99.9 999.9 9.9 99.9 999.9 9.9 99.9 Infinite
     PID Process Syscall sec usec usec usec msec msec msec sec sec sec Wait
    3448 multipass.gui poll 63 - - - - 1 185 1 - - 0
    3646 multipass.gui poll 0 - - - - - - - - - 16
    3735 multipass.gui epoll_wait 6 - - - - - - - - - 0
    3746 multipass.gui epoll_wait 0 - - - - - - - - - 56
    3747 multipass.gui epoll_wait 0 - - - - - - - - - 56
    3750 multipass.gui epoll_wait 6 - - - - - - - - - 0

Polling system call analysis:
 No bad polling discovered.

Filesystem Syncs:
 None.

Inotify watches added:
 None.

Memory:
Per Process Memory (K):
     PID Process Type Size RSS PSS
    3448 multipass.gui Stack 132 24 24
    3448 multipass.gui Heap 602656 16620 16620
    3448 multipass.gui Mapped 92888 34232 24546

Change in memory (K/second):
     PID Process Type Size RSS PSS
    3448 multipass.gui Heap 0.00 0.67 0.67 (growing)

Heap Change via brk():
 None.

Memory Change via mmap() and munmap():
 None.

Open Network Connections:
     PID Process Proto Send Receive Address
    3747 multipass.gui UNIX 2.75 K 7.87 K @/tmp/.X11-unix/X0
    3746 multipass.gui UNIX 2.67 K 7.81 K @/tmp/.X11-unix/X0
    3646 multipass.gui UNIX 0.00 B 672.00 B /run/dbus/system_bus_socket
    3448 multipass.gui UNIX 0.00 B 0.00 B /run/user/1000/bus
    3448 multipass.gui UNIX 0.00 B 0.00 B /run/systemd/journal/stdout
    3448 multipass.gui UNIX 0.00 B 0.00 B @/tmp/.X11-unix/X0
    3448 multipass.gui UNIX 0.00 B 0.00 B /run/dbus/system_bus_socket
 Total 5.43 K 16.34 K

Things to note:

  1. The heap is growing, is that a long term leak?
  2. There are quite a few poll events going on per second. That's a good way to keep a CPU from going into deep C states.
Saviq commented 3 years ago

Thanks @ColinIanKing, we know it's not ideal, we never got the time to improve it yet.

Duplicate of #1528

ColinIanKing commented 3 years ago

It's not quite a duplicate, please see the things to note section:

"The heap is growing, is that a long term leak?"

Saviq commented 3 years ago

Thanks, indeed, I've re-tasked the issue to be about that potential leak.

ColinIanKing commented 3 years ago

Thanks, much appreciated!