Crash due to invalid assumption (unsigned wrap around) in vgsvcCpuHotPlugGetACPIDevicePath (VBoxService) => fixed in SVN/next maintenance

[musteresel]

TL;DR: There's an unsigned integer "underflow"/wrap around of the variable iLvlCurr in the function vgsvcCpuHotPlugGetACPIDevicePath in src/VBox/Additions/common/VBoxService/VBoxServiceCpuHotPlug.cpp

---

When I try to unplug a CPU (initiated from the host to a linux guest with guest additions installed and VBoxService running) then I get a segmentation fault in the guest additions code, most certainly in the vgsvcCpuHotPlugGetACPIDevicePath function (src/VBox/Additions/common/VBoxService/VBoxServiceCpuHotPlug.cpp). On the host side I get an error that the CPU couldn't be safely unplugged:

$ VBoxManage controlvm nixos-vm unplugcpu 2
VBoxManage: error: Hot-Remove was aborted because the CPU may still be used by the guest
VBoxManage: error: Details: code VBOX_E_VM_ERROR (0x80bb0003), component ConsoleWrap, interface IConsole, callee nsISupports
VBoxManage: error: Context: "HotUnplugCPU(n)" at line 427 of file VBoxManageControlVM.cpp

The code (in VBoxService) actually contains an assertion which shows the (invalid) assumption which causes this crash:

https://www.alldomusa.eu.org/browser/vbox/trunk/src/VBox/Additions/common/VBoxService/VBoxServiceCpuHotPlug.cpp#L388

Here's the output from VBoxService -f -vvvv run from within gdb:

Reading symbols from /run/current-system/sw/bin/VBoxService...

warning: Loadable section ".dynsym" outside of ELF segments

warning: Loadable section ".dynstr" outside of ELF segments
(No debugging symbols found in /run/current-system/sw/bin/VBoxService)
(gdb) run -f -vvvv
Starting program: /nix/store/w3j8lnbn641g9hc1ghq3l6bz9cb10ba8-system-path/bin/VBoxService -f -vvvv
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/nix/store/xg6ilb9g9zhi2zg1dpi4zcp288rhnvns-glibc-2.30/lib/libthread_db.so.1".
[New Thread 0x7fffeac5c700 (LWP 19725)]
[New Thread 0x7fffea45b700 (LWP 19726)]
[Thread 0x7fffea45b700 (LWP 19726) exited]
[Thread 0x7fffeac5c700 (LWP 19725) exited]
23:36:57.721123 main     VBoxService 6.1.6 r137129 (verbosity: 4) linux.amd64 (Apr  9 2020 19:52:18) release log
23:36:57.721127 main     Log opened 2020-09-19T23:36:57.721111000Z
23:36:57.753045 main     OS Product: Linux
23:36:57.753150 main     OS Release: 5.4.66
23:36:57.753187 main     OS Version: #1-NixOS SMP Thu Sep 17 11:47:56 UTC 2020
23:36:57.753246 main     Executable: /nix/store/m7jdv9mzg0czfz3l6b6zcy76z80wl0p4-VirtualBox-GuestAdditions-6.1.6-5.4.66/bin/VBoxService
23:36:57.753247 main     Process ID: 19721
23:36:57.753248 main     Package type: LINUX_64BITS_GENERIC
23:36:57.754037 main     Guest Property: /VirtualBox/GuestAdd/VBoxService/--timesync-interval not found
23:36:57.755296 main     Guest Property: /VirtualBox/GuestAdd/VBoxService/--timesync-min-adjust not found
23:36:57.757081 main     Guest Property: /VirtualBox/GuestAdd/VBoxService/--timesync-latency-factor not found
23:36:57.759389 main     Guest Property: /VirtualBox/GuestAdd/VBoxService/--timesync-max-latency not found
23:36:57.760613 main     Guest Property: /VirtualBox/GuestAdd/VBoxService/--timesync-set-threshold not found
23:36:57.762017 main     Guest Property: /VirtualBox/GuestAdd/VBoxService/--timesync-set-start not found
23:36:57.762802 main     Guest Property: /VirtualBox/GuestAdd/VBoxService/--timesync-no-set-start not found
23:36:57.764212 main     Guest Property: /VirtualBox/GuestAdd/VBoxService/--timesync-set-on-restore not found
23:36:57.765754 main     Guest Property: /VirtualBox/GuestAdd/VBoxService/--timesync-no-set-on-restore not found
23:36:57.767093 main     Guest Property: /VirtualBox/GuestAdd/VBoxService/--timesync-verbosity not found
23:36:57.767759 main     6.1.6 r137129 started. Verbose level = 4
23:36:57.769269 main     Setting VBoxService status to 30
23:36:57.785986 main     Initializing services ...
23:36:57.812554 main     vbglR3GuestCtrlDetectPeekGetCancelSupport: Supported (#1)
23:36:57.812996 main     Guest control service client ID=25 w/ optimizations
23:36:57.814539 main     Host features: 0x3
23:36:57.816135 main     Property Service Client ID: 0x1a
23:36:57.818363 main     Guest Property: /VirtualBox/GuestAdd/VBoxService/--vminfo-user-idle-threshold not found
23:36:57.819907 main     vgsvcBalloonInit
23:36:57.821279 main     MemBalloon: New balloon size 0 MB (R0 memory)
23:36:57.822376 main     vgsvcVMStatsInit
23:36:57.823971 main     vgsvcVMStatsInit: New statistics interval 0 seconds
23:36:57.825671 main     vbsvcAutomounterInit
23:36:57.827241 main     vbsvcAutomounterInit: Service Client ID: 0x1b
23:36:57.842866 main     Starting services ...
23:36:57.843246 main     Starting service     'control' ...
[New Thread 0x7fffe9c5a700 (LWP 19727)]
[New Thread 0x7fffe9bd9700 (LWP 19728)]
23:36:57.847465 control  GstCtrl: Waiting for host msg ...
23:36:57.849543 main     Starting service     'timesync' ...
[New Thread 0x7fffe9b58700 (LWP 19729)]
23:36:57.853321 main     Starting service     'vminfo' ...
23:36:57.853813 timesync vgsvcTimeSyncWorker: Host: 2020-09-19T23:36:57.859000000Z (MinAdjust: 100 ms), Guest: 2020-09-19T23:36:57.853394000Z => 5 606 000 ns drift
[New Thread 0x7fffe9ad7700 (LWP 19730)]
23:36:57.856894 main     Starting service     'cpuhotplug' ...
[New Thread 0x7fffe9a56700 (LWP 19731)]
23:36:57.859560 vminfo   Writing guest property '/VirtualBox/GuestInfo/OS/Product' = 'Linux'
23:36:57.862285 main     Starting service     'memballoon' ...
23:36:57.863818 vminfo   Writing guest property '/VirtualBox/GuestInfo/OS/Release' = '5.4.66'
[New Thread 0x7fffe99d5700 (LWP 19732)]
23:36:57.865417 vminfo   Writing guest property '/VirtualBox/GuestInfo/OS/Version' = '#1-NixOS SMP Thu Sep 17 11:47:56 UTC 2020'
23:36:57.865591 vminfo   Writing guest property '/VirtualBox/GuestInfo/OS/ServicePack' = ''
23:36:57.865858 vminfo   Writing guest property '/VirtualBox/GuestAdd/Version' = '6.1.6'
23:36:57.865934 main     Starting service     'vmstats' ...
23:36:57.866023 vminfo   Writing guest property '/VirtualBox/GuestAdd/VersionExt' = '6.1.6'
[New Thread 0x7fffe9954700 (LWP 19733)]
23:36:57.866911 vminfo   Writing guest property '/VirtualBox/GuestAdd/Revision' = '137129'
23:36:57.867451 vminfo   Found entry 'reboot' (type: 2, PID: 0, session: 0)
23:36:57.867573 vminfo   Found entry 'danieljour' (type: 7, PID: 728, session: 0)
23:36:57.867616 vminfo   Adding user 'danieljour' (type: 7) to list
23:36:57.867667 vminfo   Found entry 'danieljour' (type: 7, PID: 947, session: 0)
23:36:57.868003 main     Starting service     'automount' ...
[New Thread 0x7fffe98d3700 (LWP 19734)]
23:36:57.873438 main     All services started.
23:36:57.873757 main     Setting VBoxService status to 50
23:36:57.877053 automount vbsvcAutomounterRefreshTable: 0 entries in mount table after pass #1.
23:36:57.877954 automount vbsvcAutomounterWorker: Waiting with uConfigVer=0
23:36:57.880908 automount vbsvcAutomounterWorker: Woke up with uNewVersion=0 and rc=VERR_CANCELLED
23:36:57.948426 vminfo   Checking ConsoleKit sessions ...
23:36:57.950917 vminfo   cUsersInList=1, pszUserList=danieljour, rc=VINF_SUCCESS
23:36:57.951405 vminfo   [PropCache 0000000000692340]: Written '/VirtualBox/GuestInfo/OS/LoggedInUsersList'='danieljour' (flags: a), rc=VINF_SUCCESS
23:36:57.951545 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/OS/LoggedInUsersList' resulted in rc=VINF_SUCCESS
23:36:57.951712 vminfo   [PropCache 0000000000692340]: Written '/VirtualBox/GuestInfo/OS/LoggedInUsers'='1' (flags: a), rc=VINF_SUCCESS
23:36:57.951777 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/OS/LoggedInUsers' resulted in rc=VINF_SUCCESS
23:36:57.953751 vminfo   [PropCache 0000000000692340]: Written '/VirtualBox/GuestInfo/OS/NoLoggedInUsers'='false' (flags: a), rc=VINF_SUCCESS
23:36:57.954069 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/OS/NoLoggedInUsers' resulted in rc=VINF_SUCCESS
23:36:57.954880 vminfo   Writing users returned with rc=VINF_SUCCESS
23:36:57.957360 vminfo   [PropCache 0000000000692340]: Written '/VirtualBox/GuestInfo/Net/0/V4/IP'='10.0.2.15' (flags: 0), rc=VINF_SUCCESS
23:36:57.957848 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/0/V4/IP' resulted in rc=VINF_SUCCESS
23:36:57.959430 vminfo   [PropCache 0000000000692340]: Written '/VirtualBox/GuestInfo/Net/0/V4/Broadcast'='10.0.2.255' (flags: 0), rc=VINF_SUCCESS
23:36:57.960786 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/0/V4/Broadcast' resulted in rc=VINF_SUCCESS
23:36:57.961677 vminfo   [PropCache 0000000000692340]: Written '/VirtualBox/GuestInfo/Net/0/V4/Netmask'='255.255.255.0' (flags: 0), rc=VINF_SUCCESS
23:36:57.961792 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/0/V4/Netmask' resulted in rc=VINF_SUCCESS
23:36:57.963149 vminfo   [PropCache 0000000000692340]: Written '/VirtualBox/GuestInfo/Net/0/MAC'='0800272F54B7' (flags: 0), rc=VINF_SUCCESS
23:36:57.965817 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/0/MAC' resulted in rc=VINF_SUCCESS
23:36:57.969406 vminfo   [PropCache 0000000000692340]: Written '/VirtualBox/GuestInfo/Net/0/Status'='Up' (flags: 0), rc=VINF_SUCCESS
23:36:57.969887 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/0/Status' resulted in rc=VINF_SUCCESS
23:36:57.971318 vminfo   [PropCache 0000000000692340]: Written '/VirtualBox/GuestInfo/Net/0/Name'='enp0s3' (flags: 0), rc=VINF_SUCCESS
23:36:57.973628 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/0/Name' resulted in rc=VINF_SUCCESS
23:36:57.975789 vminfo   [PropCache 0000000000692340]: Written '/VirtualBox/GuestInfo/Net/Count'='1' (flags: 6), rc=VINF_SUCCESS
23:36:57.977170 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/Count' resulted in rc=VINF_SUCCESS
23:36:57.977976 vminfo   Guest Property: /VirtualBox/HostInfo/VRDP/ActiveClient not found
23:36:57.978041 vminfo   VRDP: Handling location awareness done
23:36:59.007040 automount vbsvcAutomounterWorker: Waiting with uConfigVer=0
23:37:03.058141 vminfo   Found entry 'reboot' (type: 2, PID: 0, session: 0)
23:37:03.058253 vminfo   Found entry 'danieljour' (type: 7, PID: 728, session: 0)
23:37:03.058292 vminfo   Adding user 'danieljour' (type: 7) to list
23:37:03.058352 vminfo   Found entry 'danieljour' (type: 7, PID: 947, session: 0)
23:37:03.058396 vminfo   Checking ConsoleKit sessions ...
23:37:03.059076 vminfo   cUsersInList=1, pszUserList=danieljour, rc=VINF_SUCCESS
23:37:03.059696 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/OS/LoggedInUsersList' resulted in rc=VINF_NO_CHANGE
23:37:03.059771 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/OS/LoggedInUsers' resulted in rc=VINF_NO_CHANGE
23:37:03.059812 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/OS/NoLoggedInUsers' resulted in rc=VINF_NO_CHANGE
23:37:03.059853 vminfo   Writing users returned with rc=VINF_NO_CHANGE
23:37:03.059911 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/0/V4/IP' resulted in rc=VINF_NO_CHANGE
23:37:03.059962 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/0/V4/Broadcast' resulted in rc=VINF_NO_CHANGE
23:37:03.060000 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/0/V4/Netmask' resulted in rc=VINF_NO_CHANGE
23:37:03.060043 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/0/MAC' resulted in rc=VINF_NO_CHANGE
23:37:03.060679 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/0/Status' resulted in rc=VINF_NO_CHANGE
23:37:03.060765 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/0/Name' resulted in rc=VINF_NO_CHANGE
23:37:03.060973 vminfo   [PropCache 0000000000692340]: Written '/VirtualBox/GuestInfo/Net/Count'='1' (flags: 6), rc=VINF_SUCCESS
23:37:03.061045 vminfo   [PropCache 0000000000692340]: Updating '/VirtualBox/GuestInfo/Net/Count' resulted in rc=VINF_SUCCESS
23:37:03.061702 vminfo   Guest Property: /VirtualBox/HostInfo/VRDP/ActiveClient not found
23:37:03.061795 vminfo   VRDP: Handling location awareness done
23:37:05.685843 cpuhotplug CpuHotPlug: Event happened idCpuCore=2 idCpuPackage=0 enmEventType=3
23:37:05.686102 cpuhotplug Final path after probing /sys/devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:01/LNXCPU:01 rc=VINF_SUCCESS
23:37:05.686215 cpuhotplug Going deeper (iLvlCurr=1)
23:37:05.686257 cpuhotplug New path /sys/devices/LNXSYSTM:00/LNXSYBUS:*
23:37:05.686311 cpuhotplug Going deeper (iLvlCurr=2)
23:37:05.686345 cpuhotplug New path /sys/devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:*
23:37:05.686396 cpuhotplug Going deeper (iLvlCurr=3)
23:37:05.686428 cpuhotplug New path /sys/devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:01/LNXCPU:*
23:37:05.686536 cpuhotplug CPU doesn't match, next directory
23:37:05.686577 cpuhotplug Directory not found, going back (iLvlCurr=2)
23:37:05.686616 cpuhotplug Going deeper (iLvlCurr=3)
23:37:05.686641 cpuhotplug New path /sys/devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:02/LNXCPU:*
23:37:05.686698 cpuhotplug CPU doesn't match, next directory
23:37:05.686729 cpuhotplug Directory not found, going back (iLvlCurr=2)
23:37:05.686756 cpuhotplug Going deeper (iLvlCurr=3)
23:37:05.686797 cpuhotplug New path /sys/devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/LNXCPU:*
23:37:05.686866 cpuhotplug CPU doesn't match, next directory
23:37:05.686898 cpuhotplug Directory not found, going back (iLvlCurr=2)
23:37:05.686927 cpuhotplug Directory not found, going back (iLvlCurr=1)
23:37:05.686954 cpuhotplug Going deeper (iLvlCurr=2)
23:37:05.686978 cpuhotplug New path /sys/devices/LNXSYSTM:00/LNXSYBUS:01/ACPI0004:*
23:37:05.687019 cpuhotplug Directory not found, going back (iLvlCurr=1)
23:37:05.687058 cpuhotplug Directory not found, going back (iLvlCurr=0)
23:37:05.687114 cpuhotplug Directory not found, going back (iLvlCurr=4294967295)

Thread 8 "cpuhotplug" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffe9a56700 (LWP 19731)]
0x0000000000414756 in ?? ()
(gdb) bt
#0  0x0000000000414756 in ?? ()
#1  0x0000000000404ddf in ?? ()
#2  0x00000000004382fc in ?? ()
#3  0x0000000000417e7b in ?? ()
#4  0x00007ffff7fafedd in start_thread () from /nix/store/xg6ilb9g9zhi2zg1dpi4zcp288rhnvns-glibc-2.30/lib/libpthread.so.0
#5  0x00007ffff7ed6aaf in clone () from /nix/store/xg6ilb9g9zhi2zg1dpi4zcp288rhnvns-glibc-2.30/lib/libc.so.6
(gdb) 

[musteresel]

Ok, found out more for *why* the ACPI path cannot be found:

• For some reason (not yet sure why) the CPU which is wanted to unplug was already offline (cat /sys/devices/system/cpu/cpu2/online returns 0)

• Therefore, /sys/devices/LNXSYSTM\:00/LNXSYBUS\:00/ACPI0004\:02/LNXCPU\:02/physical_node/ contains no topology directory; and the above mentioned function fails to find the ACPI path (and crashes due to the bug)

If I make sure that the CPU is online prior to unplugging, then everything works as expected. This should be fixed, though, because VBoxService might not be the only thing turning CPUs on and off on a system (and apparently, for some other unrelated issue, it is not turning them on on mine).

[musteresel]

(Side note, found reason for the CPU not being online: https://www.alldomusa.eu.org/ticket/19903)

[aeichner]

Thanks for the report, should be fixed in the next maintenance release. There is a new testbuild available on Testbuilds, >= r140448. You only need to update the guest additions if you want to try it out.

[musteresel]

@aeichner Thank you, yes indeed, the test builds work fine! When is it planned that this feature will hit a "stable" version (6.1.16 probably?)? (I'm packaging this, and since your testbuild isos for a specific revision don't stay online for long this is difficult)

[aeichner]

We usually don't give any release dates but the next Oracle CPU (Critical Patch Update) is on the 20th of October 2020, so you can likely expect a release on this date at latest. ;)

[arudnev]

Fixed in 6.1.16