Vbox hangs with SATA controller enabled
Posted: 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:
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:
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.
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 ...
...
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
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.
