NS_ERROR_FAILUREs occur when starting virtual machine

Discussions related to using VirtualBox on Linux hosts.
diamond82908
Posts: 13
Joined: 5. Nov 2022, 11:48

Re: NS_ERROR_FAILUREs occur when starting virtual machine

Post by diamond82908 »

fth0 wrote:Ok. The next step would be to reproduce the issue and to look at ~/.config/VirtualBox/VBoxSVC.log and the system log file(s) of your host OS.
Thanks. This issue only occurs on archlinux hosts (or maybe it only occurs on my archlinux host). I downloaded and installed Virtualbox from virtualbox.org but the issue was still there.
diamond82908
Posts: 13
Joined: 5. Nov 2022, 11:48

Re: NS_ERROR_FAILUREs occur when starting virtual machine

Post by diamond82908 »

It seems Virtualbox runs into a dead loop when I start it. I traced system calls made by VB via strace and found VB kept making these system calls.

Code: Select all

futex(0x7ffc21d54c08, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = 0
futex(0x4eb298, FUTEX_WAKE_PRIVATE, 1)  = 0
poll([{fd=12, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=12, revents=POLLOUT}])
writev(12, [{iov_base="<\0\2\0\231\373\341\0047\0\5\0\232\373\341\4\220\1\340\4\0\0\1\0\0\0\0\0;\3\5\0"..., iov_len=104}], 1) = 104
poll([{fd=12, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=12, revents=POLLOUT}])
writev(12, [{iov_base="<\0\2\0\232\373\341\0047\0\5\0\233\373\341\4\226\1\340\4\0\0\1\0\0\0\0\0;\3\5\0"..., iov_len=104}], 1) = 104
poll([{fd=14, events=POLLIN}, {fd=15, events=POLLIN}, {fd=25, events=POLLIN}], 3, 15) = 0 (Timeout)
poll([{fd=14, events=POLLIN}, {fd=15, events=POLLIN}, {fd=25, events=POLLIN}], 3, 16) = 0 (Timeout)
write(14, "\1\0\0\0\0\0\0\0", 8)        = 8
poll([{fd=14, events=POLLIN}, {fd=15, events=POLLIN}, {fd=25, events=POLLIN}], 3, 0) = 1 ([{fd=14, revents=POLLIN}])
read(14, "\1\0\0\0\0\0\0\0", 16)        = 8
poll([{fd=12, events=POLLIN|POLLOUT}], 1, -1) = 1 ([{fd=12, revents=POLLOUT}])
writev(12, [{iov_base="+\0\1\0", iov_len=4}], 1) = 4
list of used fds.

Code: Select all

lrwx------ 1 root root 64 11月10日 21:41 0 -> /dev/null
lrwx------ 1 root root 64 11月10日 21:41 1 -> /dev/null
lrwx------ 1 root root 64 11月10日 21:41 10 -> 'socket:[26044]'
lrwx------ 1 root root 64 11月10日 21:41 11 -> 'socket:[26045]'
lrwx------ 1 root root 64 11月10日 21:41 12 -> 'socket:[36088]'
lrwx------ 1 root root 64 11月10日 21:41 13 -> 'anon_inode:[eventfd]'
lrwx------ 1 root root 64 11月10日 21:41 14 -> 'anon_inode:[eventfd]'
lrwx------ 1 root root 64 11月10日 21:41 15 -> 'socket:[36089]'
lrwx------ 1 root root 64 11月10日 21:41 16 -> /dev/dri/card0
lrwx------ 1 root root 64 11月10日 21:41 17 -> /dev/dri/card0
lrwx------ 1 root root 64 11月10日 21:41 18 -> /dev/dri/card0
lrwx------ 1 root root 64 11月10日 21:41 19 -> /dev/dri/card0
lrwx------ 1 root root 64 11月10日 21:41 2 -> /dev/null
lrwx------ 1 root root 64 11月10日 21:41 20 -> 'anon_inode:[eventfd]'
lr-x------ 1 root root 64 11月10日 21:41 21 -> anon_inode:inotify
lrwx------ 1 root root 64 11月10日 21:41 22 -> 'socket:[15328]'
lr-x------ 1 root root 64 11月10日 21:41 23 -> /usr/share/icons/breeze/icon-theme.cache
lr-x------ 1 root root 64 11月10日 21:41 24 -> /usr/share/icons/hicolor/icon-theme.cache
lr-x------ 1 root root 64 11月10日 21:41 25 -> 'pipe:[29186]'
l-wx------ 1 root root 64 11月10日 21:41 26 -> 'pipe:[29186]'
lrwx------ 1 root root 64 11月10日 21:41 27 -> 'socket:[29187]'
lr-x------ 1 root root 64 11月10日 21:41 28 -> 'pipe:[29188]'
l-wx------ 1 root root 64 11月10日 21:41 29 -> 'pipe:[29188]'
lr-x------ 1 root root 64 11月10日 21:41 3 -> /opt/VirtualBox
lrwx------ 1 root root 64 11月10日 21:41 30 -> 'anon_inode:[eventfd]'
lrwx------ 1 root root 64 11月10日 21:41 31 -> 'anon_inode:[eventfd]'
lrwx------ 1 root root 64 11月10日 21:41 32 -> 'anon_inode:[eventfd]'
lrwx------ 1 root root 64 11月10日 21:41 33 -> 'anon_inode:[eventfd]'
l-wx------ 1 root root 64 11月10日 21:41 35 -> '/home/(myusername)/VirtualBox VMs/Archlinux/Logs/VBox.log'
lr-x------ 1 root root 64 11月10日 21:41 36 -> /opt/VirtualBox/VMMR0.r0
lr-x------ 1 root root 64 11月10日 21:41 4 -> /opt/VirtualBox
lrwx------ 1 root root 64 11月10日 21:41 44 -> 'anon_inode:[eventfd]'
lr-x------ 1 root root 64 11月10日 21:41 5 -> /opt/VirtualBox
lr-x------ 1 root root 64 11月10日 21:41 6 -> /opt/VirtualBox/components
lrwx------ 1 root root 64 11月10日 21:41 7 -> /dev/vboxdrv
lr-x------ 1 root root 64 11月10日 21:41 8 -> /dev/urandom
lr-x------ 1 root root 64 11月10日 21:41 9 -> anon_inode:inotify
I'm just a sparetime-user of strace but I think these Information may help.
Attachments
system_calls.txt
system calls made by VB
(90.25 KiB) Downloaded 4 times
fth0
Volunteer
Posts: 5668
Joined: 14. Feb 2019, 03:06
Primary OS: Mac OS X other
VBox Version: PUEL
Guest OSses: Linux, Windows 10, ...
Location: Germany

Re: NS_ERROR_FAILUREs occur when starting virtual machine

Post by fth0 »

If you really want to analyze using strace yourself, I'd suggest to use a command like strace -tt -ff -o strace.txt VBoxManage startvm "VM". The timestamps would indicate the frequency of the file accesses, and the thread IDs would reveal the creating thread.
diamond82908
Posts: 13
Joined: 5. Nov 2022, 11:48

Re: NS_ERROR_FAILUREs occur when starting virtual machine

Post by diamond82908 »

I checked ~/.config/Virtualbox/VBoxSVC.log. The only error in the log file was something like "can't emulate usb devices. please add your user into "vboxusers" group (which I had already done)".
Shall I report this to developers? This issue might be a bug. :shock:
fth0
Volunteer
Posts: 5668
Joined: 14. Feb 2019, 03:06
Primary OS: Mac OS X other
VBox Version: PUEL
Guest OSses: Linux, Windows 10, ...
Location: Germany

Re: NS_ERROR_FAILUREs occur when starting virtual machine

Post by fth0 »

Did you log out (or reboot the host) after adding your user to the vboxusers group?
diamond82908
Posts: 13
Joined: 5. Nov 2022, 11:48

Re: NS_ERROR_FAILUREs occur when starting virtual machine

Post by diamond82908 »

fth0 wrote:Did you log out (or reboot the host) after adding your user to the vboxusers group?
Indeed I didn't. The error "can't emulate usb devices" disappeared after rebooting. However the issue is still there.
I found several interesting lines in "VBoxSVC.log":

Code: Select all

00:00:00.722715 nspr-7   ERROR [COM]: aRC=VBOX_E_INVALID_VM_STATE (0x80bb0002) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The machine is not mutable (state is Aborted)}, preserve=false aResultDetail=0
00:00:02.662164 nspr-2   Launched VM: 1946168704 pid: 3755 (0xeab) frontend: GUI/Qt name: Archlinux
00:00:02.687281 nspr-7   ERROR [COM]: aRC=VBOX_E_INVALID_VM_STATE (0x80bb0002) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The machine is not mutable (state is Aborted)}, preserve=false aResultDetail=0
00:00:02.779770 nspr-8   ERROR [COM]: aRC=VBOX_E_INVALID_VM_STATE (0x80bb0002) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The machine is not mutable (state is Aborted)}, preserve=false aResultDetail=0
00:00:03.057796 nspr-8   ERROR [COM]: aRC=VBOX_E_OBJECT_NOT_FOUND (0x80bb0001) aIID={70401eef-c8e9-466b-9660-45cb3e9979e4} aComponent={ExtPackManagerWrap} aText={No extension pack by the name 'Oracle VM VirtualBox Extension Pack' was found}, preserve=false aResultDetail=0
00:00:03.092422 nspr-5   ERROR [COM]: aRC=VBOX_E_IPRT_ERROR (0x80bb0005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={SessionMachine} aText={Saved screenshot data is not available (VERR_NOT_SUPPORTED)}, preserve=false aResultDetail=-37
00:00:03.259458 nspr-8   ERROR [COM]: aRC=VBOX_E_INVALID_VM_STATE (0x80bb0002) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The machine is not mutable (state is Starting)}, preserve=false aResultDetail=0
00:00:03.412850 nspr-8   ERROR [COM]: aRC=VBOX_E_INVALID_VM_STATE (0x80bb0002) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={SessionMachine} aText={The machine is not mutable or saved (state is Starting)}, preserve=false aResultDetail=0
Are they associated with the issue?
fth0
Volunteer
Posts: 5668
Joined: 14. Feb 2019, 03:06
Primary OS: Mac OS X other
VBox Version: PUEL
Guest OSses: Linux, Windows 10, ...
Location: Germany

Re: NS_ERROR_FAILUREs occur when starting virtual machine

Post by fth0 »

diamond82908 wrote:Are they associated with the issue?
I don't know, and evaluating partial information often doesn't make sense. Please do the following:

Reboot your host, open a terminal and start the VM with strace -tt -ff -o strace.log VBoxManage startvm "Archlinux". Provide a zip file with the VBoxSVC.log file, the VBox.log file and the strace.log* files. Depending on the size of the log files, you'll have to provide multiple zip files because of the forum's 128 kB limit.
diamond82908
Posts: 13
Joined: 5. Nov 2022, 11:48

Re: NS_ERROR_FAILUREs occur when starting virtual machine

Post by diamond82908 »

I have found a solution in arch wiki: Adding a kernel parameter "ibt=off". It disables Intel's "Indirect Branch Trace", which causes this issue.
Freeze during virtual machine startup with 11th generation Intel CPU

If the message traps: Missing ENDBR and kernel BUG at arch/x86/kernel/traps.c appears in the journal you can try adding ibt=off as a kernel parameter. Seems to be linked to FS#74891.
https://wiki.archlinux.org/title/VirtualBox
Now I consider this issue as a bug. I think developers have made some mistakes which brings incompatibility with the IBT.
fth0
Volunteer
Posts: 5668
Joined: 14. Feb 2019, 03:06
Primary OS: Mac OS X other
VBox Version: PUEL
Guest OSses: Linux, Windows 10, ...
Location: Germany

Re: NS_ERROR_FAILUREs occur when starting virtual machine

Post by fth0 »

diamond82908 wrote:Now I consider this issue as a bug.
Agreed! I'd suggest to reproduce the issue with the current VirtualBox 7.0.4. If the issue persists, create a ticket in the Bugtracker, including VBoxSVC.log and VBox.log files and a description of how to reproduce the issue.
Post Reply