Vbox hangs with SATA controller enabled

LeXa2 · Post by **LeXa2** » 11. Apr 2009, 22:47

When SATA support was first untroduced (AFAIK in 1.6.x times) it was broken for me - any attempt to install intel SATA drivers to WinXP guest resulted in BSOD, either immidiate or delayed by no more than a minite. Since Vbox 2.0.0 things got better and I had switched to using SATA as a primary boot drive for my WinXP guest. After an upgrade to VBox 2.1.x there were sporadic VBox hangs introduced with strange symptoms.

For a some period of time WinXP guest runs correctly, and then - suddenly - it gets stalled, with OS blocked on HDD access. Hard drive acces icon on the bottom of the guest VM window shows red circle, indicating that there are attempts to write something on guest HDD, and nothing else happens. I can even switch between open windows in guest OS, but any operation that requires HDD access hangs. If I try to reset VM using "Host+R", or throung menu item "Reset" - it tooks a lot of time to complete a reset, and then OS starts to boot, but hangs on HDD access with green circle displayed over HDD icon in the bottom of guest VM windows.

An attempt to close down guest VM leads to VBox hang, displaying "Stopping virtual machine..." of 70% (screenshot attached). This hang is not accompanied with excess CPU usage - almost no CPU cycles got used by either kernel side or userspace side of VirtualBOX process. strace attach to VBox process shows this:

Code: Select all

[root@lexa2 webcore]# ps axfu | grep -i box
lexa2     9045  0.0  0.7  79124 33040 ?        Sl   Apr10   0:40  \_ /usr/lib/virtualbox/VirtualBox
root     17082  0.0  0.0   4976   756 pts/1    S+   00:31   0:00  |               \_ grep -i box
lexa2    19039  0.0  0.0   8008  2160 ?        S    Apr09   0:57 /usr/lib/virtualbox/VBoxXPCOMIPCD
lexa2    19048  0.0  0.1  17448  6608 ?        Sl   Apr09   3:24 /usr/lib/virtualbox/VBoxSVC --automate
lexa2    17930 22.1 14.3 855472 593656 ?       Sl   Apr09 847:40  \_ /usr/lib/virtualbox/VirtualBox --comment WinXP --startvm be45aaf4-387c-4fe4-508c-3a03eac9b080
lexa2     9253  2.6  8.0 406624 334180 ?       Sl   Apr10  60:01  \_ /usr/lib/virtualbox/VirtualBox --comment CentOS4-SandBox --startvm b5dfa80a-2541-42a0-9726-88ec2bd6bdd4
[root@lexa2 webcore]#
[root@lexa2 webcore]# strace -p 17930
Process 17930 attached - interrupt to quit
restart_syscall(<... resuming interrupted call ...>) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 6483228}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035237, 6611727}) = 0
gettimeofday({1239481922, 735794}, NULL) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 6698045}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 6744137}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 6782966}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x96f86cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}, {fd=86, events=POLLIN|POLLPRI}], 10, 38) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 45564504}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035237, 46753678}) = 0
gettimeofday({1239481922, 776131}, NULL) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 47255941}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 47479697}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x96f86cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}, {fd=86, events=POLLIN|POLLPRI}], 10, 9) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 58609102}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035237, 59070860}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 59294895}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 59508594}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 59718104}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x96f86cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}, {fd=86, events=POLLIN|POLLPRI}], 10, 26) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 87535889}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035237, 87980887}) = 0
gettimeofday({1239481922, 817341}, NULL) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 88413313}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 88620588}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x96f86cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}, {fd=86, events=POLLIN|POLLPRI}], 10, 17) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 107602395}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035237, 108090691}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 108327855}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 108550773}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x96f86cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}, {fd=86, events=POLLIN|POLLPRI}], 10, 18) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 128497440}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035237, 128940203}) = 0
gettimeofday({1239481922, 858365}, NULL) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 129442187}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 129652813}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x96f86cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}, {fd=86, events=POLLIN|POLLPRI}], 10, 26) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 157163318}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035237, 157650776}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 157720613}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 157780113}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 157834027}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x96f86cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}, {fd=86, events=POLLIN|POLLPRI}], 10, 10) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 169169310}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035237, 169287752}) = 0
gettimeofday({1239481922, 898482}, NULL) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 169400049}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 169453125}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x96f86cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}, {fd=86, events=POLLIN|POLLPRI}], 10, 37) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 207190190}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035237, 207331260}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 207399141}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 207453054}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x96f86cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}, {fd=86, events=POLLIN|POLLPRI}], 10, 2) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 210163823}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035237, 210280869}) = 0
gettimeofday({1239481922, 939934}, NULL) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 210866098}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 210922247}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x96f86cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}, {fd=86, events=POLLIN|POLLPRI}], 10, 39) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 251159734}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035237, 251260857}) = 0
gettimeofday({1239481922, 980441}, NULL) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 251345219}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035237, 251383490}) = 0
read(39, 0x96bad2c, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x96f86cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
...
... and so on ...
...

After about 15-20 minutes VBox finally manages to close down the hanged VM.

Situation can be resolved with a kill -9 <VboxProcessID>, but guest VM will hang again in some time. My solution was to switch main HDD of guest VM to be PIIX3/4 IDE again, and wait some tome for a new version of VBox to arrive. 2.1,x branch showed no improvements - still the same soradic hangs from time to time (not so long time, thow - hang was almost guaranted to happen in about an hour after VM start with SATA controller on). Now, after 2.2.0 has been released, things got slightly better - hang happened after about a day of uptime if guest VM. But it still happens, and I've got no idea how to troubleshoot it (i.e. there's nothing special concerning this hang in guest VM log - all seems to run well enought and then - BOOM - hang happens). Now crash dumps got produces in VM log, so I have virtually no info to post to bugtracker to help track this bug down.

In case there were any other VM running when WinXP guest hangs - it got stuck too, sometimes on network access, sometimes - on HDD access. (Second screenshot gives an idea on what it looks like). Strace to the process of other hanged vbox VM looks similar to WinXP guest ones:

Code: Select all

[root@lexa2 webcore]# strace -p 9253
Process 9253 attached - interrupt to quit
restart_syscall(<... resuming interrupted call ...>) = 0
clock_gettime(CLOCK_MONOTONIC, {1035635, 896097278}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035635, 896267121}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x9adb6cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}], 9, 0) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035635, 896568536}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035635, 896624685}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x9adb6cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}], 9, 0) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035635, 896906825}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035635, 896976382}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035635, 897042867}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x9adb6cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}], 9, 49) = 0
clock_gettime(CLOCK_MONOTONIC, {1035635, 947171377}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035635, 947315520}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035635, 947387033}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035635, 947442623}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x9adb6cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}], 9, 49) = 0
clock_gettime(CLOCK_MONOTONIC, {1035635, 997198484}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035635, 997333688}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035635, 997404083}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035635, 997461349}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x9adb6cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}], 9, 49) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 47165531}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035636, 47271404}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 47334536}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 47375321}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x9adb6cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}], 9, 49) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 97186213}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035636, 97313037}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 97383712}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 97438184}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x9adb6cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}], 9, 49) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 147185386}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035636, 147314723}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 147385678}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 147442385}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x9adb6cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}], 9, 49) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 197176737}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035636, 197302164}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 197372559}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 197427032}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x9adb6cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}], 9, 49) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 247179262}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035636, 247306365}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 247376760}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 247442407}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x9adb6cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=35, events=POLLIN}, {fd=40, events=POLLIN}, {fd=41, events=POLLIN}, {fd=39, events=POLLIN}, {fd=45, events=POLLIN}, {fd=49, events=POLLIN|POLLPRI}, {fd=51, events=POLLIN|POLLPRI}, {fd=52, events=POLLIN|POLLPRI}, {fd=53, events=POLLIN|POLLPRI}], 9, 49) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 297159997}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {1035636, 297283748}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 297353864}) = 0
clock_gettime(CLOCK_MONOTONIC, {1035636, 297413086}) = 0
read(39, 0x9aa18ac, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
read(40, 0x9adb6cc, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll(^C <unfinished ...>
Process 9253 detached

Shitching back to using PIIX3/4 IDE helps, but I don't think that this is really a solution - it is obvious, that there's a bug somewhere in VBox, that was introduced somewhere in 2.1.x and still is in place in 2.2.0. Hope, my report will help to track this bug down.

Host system: Fedora 8 i686 (kernel 2.6.26.8-57.fc8PAE), AMD Athlon(tm) 64 X2 Dual Core Processor 3800+, preformance governor, 4Gb RAM DDR PC3200.

LeXa2 · Post by **LeXa2** » 11. Apr 2009, 22:52

Upd. As there are no attaches allowed, here are link to the my site where I've got them uploaded:

Attachment 1: http://textrock.ru/tempimg/VboxHang.png
Attachment 2: http://textrock.ru/tempimg/VboxHang1.png
Attachment 3: http://textrock.ru/tempimg/VboxHang.log

Upd2. Forgot to mention, that the virtual HDD image type used is VMDK.

nyback · Post by **nyback** » 13. Apr 2009, 12:00

Same situation here.

Host: Gentoo linux 64bit
guest: Gentoo Linux 32bit

Virtual machine as vmdk files.

Same on both Virtualbox 2.1.4 and 2.2

I have not done any strace but symptoms are the same. Hangs sporadically after boot. Sometimes running for just a couple of minutes, sometimes up to 30 minutes before hang.

Thanks for the clue that led me to disable the SATA controller.

/Andreas

I was too quick to write. still got hangs after turning off sata. After also turning off acpi it seems stable so far.

virtualbox.org

Vbox hangs with SATA controller enabled

Vbox hangs with SATA controller enabled

Re: Vbox hangs with SATA controller enabled

Re: Vbox hangs with SATA controller enabled