VirtualBox hangs on guest Vista shutdown

[Leho Kraav]

Host:

$ uname -a
Linux server 3.0.2-pf #1 SMP PREEMPT Fri Aug 19 12:41:16 EEST 2011 i686 Intel(R) Core(TM) i5 CPU 750 @ 2.67GHz GenuineIntel GNU/Linux

My whole desktop session has hung, VirtualBox process is hogging CPU.

strace gives an endless cycle of clock_gettime() calls.

$ sudo strace -p 16079                                                                                                                                                                         [616/616]
Process 16079 attached - interrupt to quit
restart_syscall(<... resuming interrupted call ...>) = 0
clock_gettime(CLOCK_MONOTONIC, {674331, 706231537}) = 0
read(13, 0x97e3c98, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {674331, 706352427}) = 0
read(13, 0x97e3c98, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=14, events=POLLIN}, {fd=19, events=POLLIN}, {fd=13, events=POLLIN}, {fd=20, events=POLLIN}], 4, 0) = 0 (Timeout)
read(13, 0x97e3c98, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {674331, 706477848}) = 0
clock_gettime(CLOCK_MONOTONIC, {674331, 706508792}) = 0
read(13, 0x97e3c98, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=14, events=POLLIN}, {fd=19, events=POLLIN}, {fd=13, events=POLLIN}, {fd=20, events=POLLIN}], 4, 0) = 0 (Timeout)
read(13, 0x97e3c98, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {674331, 706607390}) = 0
clock_gettime(CLOCK_MONOTONIC, {674331, 706637237}) = 0
read(13, 0x97e3c98, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=14, events=POLLIN}, {fd=19, events=POLLIN}, {fd=13, events=POLLIN}, {fd=20, events=POLLIN}], 4, 0) = 0 (Timeout)
read(13, 0x97e3c98, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {674331, 706728435}) = 0
clock_gettime(CLOCK_MONOTONIC, {674331, 706748617}) = 0
read(13, 0x97e3c98, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=14, events=POLLIN}, {fd=19, events=POLLIN}, {fd=13, events=POLLIN}, {fd=20, events=POLLIN}], 4, 0) = 0 (Timeout)
read(13, 0x97e3c98, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime(CLOCK_MONOTONIC, {674331, 706838166}) = 0
clock_gettime(CLOCK_MONOTONIC, {674331, 706867397}) = 0
read(13, 0x97e3c98, 4096)               = -1 EAGAIN (Resource temporarily unavailable)
...

After sending HUP to hogging process, it responds and aborts, but scary disk controller stuff appears in dmesg, first I've ever seen VirtualBox affect kernel level ATA stuff:

...
[666440.067331] device eth1 entered promiscuous mode
START
[672340.920725] ata3: exception Emask 0x10 SAct 0x0 SErr 0x4090000 action 0xe frozen
[672340.920728] ata3: irq_stat 0x00400040, connection status changed
[672340.920731] ata3: hard resetting link
[672340.920740] ata4: exception Emask 0x10 SAct 0x0 SErr 0x4090000 action 0xe frozen
[672340.920742] ata4: irq_stat 0x00400040, connection status changed
[672340.920744] ata4: hard resetting link
[672341.640049] ata4: SATA link down (SStatus 0 SControl 300)
[672346.236953] ata4: hard resetting link
[672346.236962] ata3: COMRESET failed (errno=-32)
[672346.236965] ata3: reset failed (errno=-32), retrying in 5 secs
[672350.913499] ata3: limiting SATA link speed to 1.5 Gbps
[672350.913504] ata3: hard resetting link
[672351.579659] ata4: link is slow to respond, please be patient (ready=0)
[672355.430300] ata4: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[672355.470755] ata4.00: configured for UDMA/133
[672355.483578] ata4: EH complete
[672356.662720] ata3: link is slow to respond, please be patient (ready=0)
[672357.905207] ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[672357.935690] ata3.00: configured for UDMA/133
[672357.948452] ata3: EH complete
[673974.616954] device eth1 left promiscuous mode
[673974.628959] vboxnetflt: dropped 0 out of 216 packets
END
...

VBox.log attached.

[Leho Kraav]

this is very likely turning out to be my drive going bad. migrating files off it now and will be trying to rescue the disc image and retry on a working drive.