VirtualBox

Ticket #5836 (reopened defect)

Opened 4 years ago

Last modified 2 years ago

VBoxManage hangs after calling futex(..., FUTEX_WAIT_PRIVATE, ...)

Reported by: petar Owned by:
Priority: major Component: other
Version: VirtualBox 3.1.0 Keywords:
Cc: Guest type: Windows
Host type: Linux

Description

Hi,

since I upgraded from 3.0.12 to 3.1.0..

VBoxManage startvm {id} --type {headless,sdl}

..sometimes hangs. It just affects the startvm subcommand while showvminfo, controlvm (and probably others) are pretty reliable.

When the system is idle, it rarely happens but when it's under heavy load (e.g. compiling something), then it will almost certainly hang.

A short strace revealed the following:

(...)
write(1, "Remote session has been successf"..., 45Remote session has been successfully opened.
) = 45
write(9, "8", 1)                        = 1
gettimeofday({1261672393, 414255}, NULL) = 0
gettimeofday({1261672393, 414282}, NULL) = 0
gettimeofday({1261672393, 414309}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1261672393, 414336878}) = 0
futex(0x96098e0, FUTEX_WAIT_PRIVATE, 33, {29, 999972122}) = 0
futex(0x9609bac, FUTEX_WAKE_PRIVATE, 1) = 0
write(9, "8", 1)                        = 1
gettimeofday({1261672393, 414553}, NULL) = 0
gettimeofday({1261672393, 414581}, NULL) = 0
gettimeofday({1261672393, 414608}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1261672393, 414635799}) = 0
futex(0x96098e0, FUTEX_WAIT_PRIVATE, 35, {29, 999972201}) = 0
futex(0x9609bac, FUTEX_WAKE_PRIVATE, 1) = 0
write(9, "8", 1)                        = 1
gettimeofday({1261672393, 414822}, NULL) = 0
gettimeofday({1261672393, 414850}, NULL) = 0
gettimeofday({1261672393, 414878}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1261672393, 414905386}) = 0
futex(0x96098e0, FUTEX_WAIT_PRIVATE, 37, {29, 999972614}) = 0
futex(0x9609bac, FUTEX_WAKE_PRIVATE, 1) = 0
write(9, "8", 1)                        = 1
gettimeofday({1261672393, 415100}, NULL) = 0
gettimeofday({1261672393, 415129}, NULL) = 0
gettimeofday({1261672393, 415155}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1261672393, 415182796}) = 0
futex(0x96098e0, FUTEX_WAIT_PRIVATE, 39, {29, 999972204}) = 0
futex(0x9609bac, FUTEX_WAKE_PRIVATE, 1) = 0
gettimeofday({1261672393, 415335}, NULL) = 0
gettimeofday({1261672393, 415364}, NULL) = 0
gettimeofday({1261672393, 415391}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1261672393, 415419418}) = 0
futex(0x9609c38, FUTEX_WAIT_PRIVATE, 37, {1047991, 607971582}) = 0
futex(0x9609d4c, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x9609e10, FUTEX_CMP_REQUEUE_PRIVATE, 1, 2147483647, 0x960a284, 12) = 1
sched_yield()                           = 0
gettimeofday({1261672393, 416255}, NULL) = 0
gettimeofday({1261672393, 416284}, NULL) = 0
gettimeofday({1261672393, 416311}, NULL) = 0
clock_gettime(CLOCK_REALTIME, {1261672393, 416339089}) = 0
futex(0x9609c38, FUTEX_WAIT_PRIVATE, 39, {1047991, 606971911}
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ stops and waits here

When using..

/usr/lib/virtualbox/VBox{Headless,SDL} --startvm {id}

..directly, everything works fine.

I tried to start VBoxSVC before running VBoxManage but that didn't help. Same applies to removing --auto-shutdown or lowering --pipe.

Any ideas what else I could try?

Thanks

Change History

comment:1 Changed 4 years ago by petar

Hm, I can't reproduce this with 3.1.2. Please close.

comment:2 Changed 4 years ago by frank

  • Status changed from new to closed
  • Resolution set to fixed

comment:3 Changed 4 years ago by schuetzm

  • Status changed from closed to reopened
  • Resolution fixed deleted

Reopening. I'm having quite similar symptoms with 3.1.4 / Linux-x86, so I'm certain this is related.

VBoxManage startvm ... --type gui gets stuck almost every time. It also sleeps waits in futex(). After that, all other VBoxManage commands will also hang; you cannot even start the VirtualBox GUI until you killall all VBoxSVC and VirtualBox processes: killall -9 VBoxSVC killall -9 VirtualBox

This is the output of VBoxManage startvm: Waiting for the remote session to open... Remote session has been successfully opened. At this point, it just sits there and waits.

If I start VBoxSVC beforehand, it prints "Informational: VirtualBox object created (rc=NS_OK)." and doesn't do anything else.

These VirtualBox related processes are running according to pstree: init-+-VBoxSVC-+-VirtualBox---3*[{VirtualBox}]

| `-8*[{VBoxSVC}] :

|bash---VBoxManage---VBoxManage-+-VBoxXPCOMIPCD

| | `-3*[{VBoxManage}]

ps ax|grep V: 23979 pts/5 S+ 0:00 /bin/bash /usr/bin/VBoxManage --nologo startvm winxp --type gui 23980 pts/5 Sl+ 0:00 /usr/lib/virtualbox/VBoxManage --nologo startvm winxp --type gui 23983 pts/5 S+ 0:00 /usr/lib/virtualbox/VBoxXPCOMIPCD 23990 ? Sl 0:00 /usr/lib/virtualbox/VBoxSVC --pipe 13 --auto-shutdown 24000 ? Sl 0:00 /usr/lib/virtualbox/VirtualBox --comment winxp --startvm 136d5e95-4219-4a3a-b8f0-b1b7de90798e

Here's what the processes are doing:

strace -p 23979: waitpid(-1, C <unfinished ...>

strace -p 23980: restart_syscall(<... resuming interrupted call ...>

strace -p 23983: restart_syscall(<... resuming interrupted call ...>

strace -p 23990: futex(0x81c4430, FUTEX_WAIT_PRIVATE, 441, NULL

strace -p 24000: restart_syscall(<... resuming interrupted call ...>

Playing with the --pipe parameter had no effect for me either.

Please tell me what other information I can provide.

comment:4 Changed 4 years ago by schuetzm

Sorry for the formatting, here are the relevant parts again:

init-+-VBoxSVC-+-VirtualBox---3*[{VirtualBox}]
     |         `-8*[{VBoxSVC}]
     :
     |                   |-bash---VBoxManage---VBoxManage-+-VBoxXPCOMIPCD
     |                   |                                `-3*[{VBoxManage}]
ps ax|grep V:
23979 pts/5 S+  0:00 /bin/bash /usr/bin/VBoxManage --nologo startvm winxp --type gui
23980 pts/5 Sl+ 0:00 /usr/lib/virtualbox/VBoxManage --nologo startvm winxp --type gui
23983 pts/5 S+  0:00 /usr/lib/virtualbox/VBoxXPCOMIPCD
23990 ?     Sl  0:00 /usr/lib/virtualbox/VBoxSVC --pipe 13 --auto-shutdown
24000 ?     Sl  0:00 /usr/lib/virtualbox/VirtualBox --comment winxp --startvm 136d5e95-4219-4a3a-b8f0-b1b7de90798e 

comment:5 Changed 2 years ago by frank

  • Status changed from reopened to closed
  • Resolution set to fixed

Please reopen if still relevant with VBox 4.1.6.

comment:6 Changed 2 years ago by petar

Long gone, thanks for closing.

comment:7 Changed 2 years ago by Dusty

  • Status changed from closed to reopened
  • Resolution fixed deleted

I'm experiencing a problem similar to this one, I'm unable to shutdown a VM and unable to do anything more with it.

doing a strace for the command: $ strace VBoxManage controlvm w7-vm poweroff the process hangs and these are the latest lines of strace: [...] futex(0x197e770, FUTEX_WAKE_PRIVATE, 1) = 1 futex(0x198767c, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 25, {1323964345, 488719000}, ffffffff) = -1 EAGAIN (Resource temporarily unavailable) futex(0x19876c8, FUTEX_WAKE_PRIVATE, 1) = 0 futex(0x19879ac, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 23, {1327144894, 463827000}, ffffffff) = 0 futex(0x19879f8, FUTEX_WAKE_PRIVATE, 1) = 0 write(7, "8", 1) = 1 futex(0x198767c, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 27, {1323964345, 489028000}, ffffffff) = 0 futex(0x19876c8, FUTEX_WAKE_PRIVATE, 1) = 0 futex(0x19879ac, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 25, {1327144894, 463251000}, ffffffff

I'm using vbox 4.1.6, kernel 2.6.39

comment:8 Changed 2 years ago by Dusty

Sorry for the bad formatting, is a better log:

futex(0x197e770, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x198767c, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 25, {1323964345, 488719000}, ffffffff) = -1 EAGAIN (Resource temporarily unavailable)
futex(0x19876c8, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x19879ac, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 23, {1327144894, 463827000}, ffffffff) = 0
futex(0x19879f8, FUTEX_WAKE_PRIVATE, 1) = 0
write(7, "8", 1)                        = 1
futex(0x198767c, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 27, {1323964345, 489028000}, ffffffff) = 0
futex(0x19876c8, FUTEX_WAKE_PRIVATE, 1) = 0
futex(0x19879ac, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 25, {1327144894, 463251000}, ffffffff
Note: See TracTickets for help on using tickets.

www.oracle.com
ContactPrivacy policyTerms of Use