SATA AHCI Errors: READ FPDMA QUEUED

[andornaut]

My guest OS hangs periodically with a harddrive command error followed by an attempt to reset the HD (reproduced with Ubuntu and ArcLinux). This issue does not occur in the host OS (Windows 7), only in the Guest OS.

Environment:

• Ubuntu running in a Virtual Box 4.0.2 running on Windows 7 64bit.
• Asus G53JW Laptop
• Intel X25 SSD HD

Log excerpts:

Jan 17 14:48:32 vm kernel: [ 1513.120252] ata3: hard resetting link
Jan 17 14:48:33 vm kernel: [ 1513.470345] ata3: SATA link up 3.0 Gbps (SStatus
123 SControl 300)
Jan 17 14:48:33 vm kernel: [ 1513.471232] ata3.00: configured for UDMA/133
Jan 17 14:48:33 vm kernel: [ 1513.471241] ata3.00: device reported invalid CHS
sector 0
Jan 17 14:48:33 vm kernel: [ 1513.471255] ata3: EH complete

[ 1513.120200] ata3.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x6 frozen
[ 1513.120210] ata3.00: failed command: READ FPDMA QUEUED
[ 1513.120222] ata3.00: cmd 60/08:00:30:66:4c/00:00:00:00:00/40 tag 0 ncq 4096
in
[ 1513.120224]          res 40/00:00:00:00:00/00:00:00:00:00/40 Emask 0x4
(timeout)
[ 1513.120230] ata3.00: status: { DRDY }
[ 1513.120252] ata3: hard resetting link
[ 1513.470345] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ 1513.471232] ata3.00: configured for UDMA/133
[ 1513.471241] ata3.00: device reported invalid CHS sector 0
[ 1513.471255] ata3: EH complete

[cmeyer]

This issue is also occurring for me on Fedora 14 and Ubuntu 10.10. I have tried with using SATA, SCSI and SAS and the error still occurs.

Environment: DELL E6410 Windows 7 64bit

Guest OS's Tested: Ubuntu 10.10 i386 Fedora 14 x86_64

This issue does not seem to occur on a Windows XP 32 bit virtual machine.

[andornaut]

I've been able to workaround (not to say "solve") this issue by using the following kernel boot option: nolapic_timer

This workaround is described in this bug: #7619

[Frank Mehnert]

Please reopen if still relevant with VBox 4.1.4. From your description this looks like an issue related to the virtual time and there were some fixes in between.

[JackieKu]

This issue still happens in 4.1.12 and 4.1.14. Added noapictimer kernel options seems to reduce (but not gone completely) the happen rate.

Several disks got reset when it occurs. I'm using SATA AHCI controller.

Environment:
Host: Windows 7 x64
Guest: Gentoo Linux x64 (linux 3.2.12)
HDD: 6 Seagate 1TB (ST31000524AS and ST31000528AS) whole disk raw access + 1 WD 80GB raw access with some partitions

[StarNamer]

I recently started testing ZFS using a VirtualBox VM and have started to see this and similar errors. My environment is VirtualBox 4.3.18_Debian r96516 running under Debian (Sid) kernel 3.16.0-4-amd64. The VM is also running kernel 3.16.0-4-amd64 with ZFS/SPL 0.6.3 (from ZFSforLinux). The host system is not reporting any errors.

Apr  6 10:12:59 model-zfs kernel: [290529.896417] ata7.00: exception Emask 0x0 SAct 0x200 SErr 0x0 action 0x6 frozen
Apr  6 10:12:59 model-zfs kernel: [290529.896434] ata7.00: failed command: WRITE FPDMA QUEUED
Apr  6 10:12:59 model-zfs kernel: [290529.896449] ata7.00: cmd 61/01:48:f4:59:00/00:00:00:00:00/40 tag 9 ncq 512 out
Apr  6 10:12:59 model-zfs kernel: [290529.896449]          res 40/00:01:00:00:00/00:00:00:00:00/40 Emask 0x4 (timeout)
Apr  6 10:12:59 model-zfs kernel: [290529.896456] ata7.00: status: { DRDY }
Apr  6 10:12:59 model-zfs kernel: [290529.896476] ata7: hard resetting link
Apr  6 10:13:00 model-zfs kernel: [290530.216457] ata7: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Apr  6 10:13:00 model-zfs kernel: [290530.217616] ata7.00: configured for UDMA/133
Apr  6 10:13:00 model-zfs kernel: [290530.217633] ata7.00: device reported invalid CHS sector 0
Apr  6 10:13:00 model-zfs kernel: [290530.217661] ata7: EH complete

Apr  6 10:24:56 model-zfs kernel: [291246.888769] ata4.00: exception Emask 0x0 SAct 0x400 SErr 0x0 action 0x6 frozen
Apr  6 10:24:56 model-zfs kernel: [291246.888801] ata4.00: failed command: WRITE FPDMA QUEUED
Apr  6 10:24:56 model-zfs kernel: [291246.888830] ata4.00: cmd 61/19:50:2b:a7:01/00:00:00:00:00/40 tag 10 ncq 12800 out
Apr  6 10:24:56 model-zfs kernel: [291246.888830]          res 40/00:01:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
Apr  6 10:24:56 model-zfs kernel: [291246.888852] ata4.00: status: { DRDY }
Apr  6 10:24:56 model-zfs kernel: [291246.888883] ata4: hard resetting link
Apr  6 10:24:57 model-zfs kernel: [291247.248428] ata4: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Apr  6 10:24:57 model-zfs kernel: [291247.249216] ata4.00: configured for UDMA/133
Apr  6 10:24:57 model-zfs kernel: [291247.249229] ata4.00: device reported invalid CHS sector 0
Apr  6 10:24:57 model-zfs kernel: [291247.249254] ata4: EH complete

Apr  6 10:32:02 model-zfs kernel: [291672.872331] ata4.00: exception Emask 0x0 SAct 0x10000 SErr 0x0 action 0x6 frozen
Apr  6 10:32:02 model-zfs kernel: [291672.872348] ata4.00: failed command: WRITE FPDMA QUEUED
Apr  6 10:32:02 model-zfs kernel: [291672.872364] ata4.00: cmd 61/02:80:92:03:00/00:00:00:00:00/40 tag 16 ncq 1024 out
Apr  6 10:32:02 model-zfs kernel: [291672.872364]          res 40/00:01:00:00:00/00:00:00:00:00/40 Emask 0x4 (timeout)
Apr  6 10:32:02 model-zfs kernel: [291672.872371] ata4.00: status: { DRDY }
Apr  6 10:32:02 model-zfs kernel: [291672.872390] ata4: hard resetting link
Apr  6 10:32:03 model-zfs kernel: [291673.193487] ata4: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Apr  6 10:32:03 model-zfs kernel: [291673.194270] ata4.00: configured for UDMA/133
Apr  6 10:32:03 model-zfs kernel: [291673.194302] ata4.00: device reported invalid CHS sector 0
Apr  6 10:32:03 model-zfs kernel: [291673.194335] ata4: EH complete

Apr  6 10:36:45 model-zfs kernel: [291955.882996] ata2.00: exception Emask 0x0 SAct 0xc000000 SErr 0x0 action 0x6 frozen
Apr  6 10:36:45 model-zfs kernel: [291955.883014] ata2.00: failed command: READ FPDMA QUEUED
Apr  6 10:36:45 model-zfs kernel: [291955.883028] ata2.00: cmd 60/30:d0:b1:d7:75/00:00:01:00:00/40 tag 26 ncq 24576 in
Apr  6 10:36:45 model-zfs kernel: [291955.883028]          res 40/00:01:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
Apr  6 10:36:45 model-zfs kernel: [291955.883036] ata2.00: status: { DRDY }
Apr  6 10:36:45 model-zfs kernel: [291955.883042] ata2.00: failed command: READ FPDMA QUEUED
Apr  6 10:36:45 model-zfs kernel: [291955.883053] ata2.00: cmd 60/10:d8:f1:d7:75/00:00:01:00:00/40 tag 27 ncq 8192 in
Apr  6 10:36:45 model-zfs kernel: [291955.883053]          res 40/00:01:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
Apr  6 10:36:45 model-zfs kernel: [291955.883060] ata2.00: status: { DRDY }
Apr  6 10:36:45 model-zfs kernel: [291955.883077] ata2: hard resetting link
Apr  6 10:36:46 model-zfs kernel: [291956.200464] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Apr  6 10:36:46 model-zfs kernel: [291956.201409] ata2.00: configured for UDMA/133
Apr  6 10:36:46 model-zfs kernel: [291956.201422] ata2.00: device reported invalid CHS sector 0
Apr  6 10:36:46 model-zfs kernel: [291956.201428] ata2.00: device reported invalid CHS sector 0
Apr  6 10:36:46 model-zfs kernel: [291956.201454] ata2: EH complete

Is this a known bug or simple the result of ZFS stressing the virtual system too much?

[aeichner]

Please upload the VBox.log of the problematic VM.