Laurès wrote:
Hello,

Dear kernel developers, my dmesg asked me to report this, so here I go ;)
Here is what I found in my dmesg: "anticipatory: forced dispatching is broken (nr_sorted=1), please report this".

- First, let's talk about the machine: it's quite pushed so maybe the cause is me doing something wrong rather than a bug in the kernel.

I got this alert on a dual core amd64 xen host. It has 8 SATA drives making a raid 5 array. This array makes a virtual block device for one of the virtual machines: an Openfiler appliance. Openfiler then manages logical volumes on this device including an XFS partition shared via NFS. 2 MythTV hosts continuously write MPEG2 tv shows on it (1 to 4Gb each). Still following ? Here is a summary: MPEG2 files -> NFS -> XFS -> LVM -> Xen VBD -> RAID 5 -> 8x SATA disks.

- Next, the symptoms.

This setup is only 2 weeks old. Behavior was quite good, except for some unexplained failures from the sata_nv attached disks. Not always from the same disk. Never from any disks attached through the sata_sil HBA. Eventually a second disk would go down before the end of the raid reconstruction (still a sata_nv attached one). Since the disks showed nothing wrong with smartmontools I re-added them each time. So far the raid array was strong enough to be fully recovered, mdadm --force and xfs_check are my friends ;-) It seems to happen more often now that the XFS partition is quite heavily fragmented, and I can't even run the defragmenter without a quick failure. I didn't payed big attention to the logs and quickly decided to buy a SATA Sil PCI card to get rid of the Nvidia SATA HBA.

- Now the problem.

Yesterday, however, the MPEG2 streams hanged for a few tens of seconds just as usual. But there were no disk failure. The array was still in good shape, although dmesg showed the same "ata[56]: Resetting port", "SCSI errors" etc. fuss. However this was new in dmesg: "anticipatory: forced dispatching is broken (nr_sorted=1), please report this". Got 4 identical in a row. Maybe managing 8 block devices queues under load with the anticipatory scheduler is too much ? I immediately switched to deadline on the 8 disks, and I'll see if it it happens again by stressing the whole system more and more. I have no clue if anticipatory is a good choice or definitely not in my case, anyone can point some documentation or good advices ?

- How to reproduce.

Here is what I would do:
Harness a small CPU with lots of sata/scsi drives.
Do raid 5 with big block size (1-4Mb) on it.
Make a 50G XFS file system with sunit/swidth options
Trigger bonnie++ with 1G<files<4G and fill the FS to 80-95%, trying to achieve 98%+ fragmentation.
Defrag !

- Finally the usual bug report stuff is attached.

From your report:

ata5: EH in ADMA mode, notifier 0x0 notifier_error 0x0 gen_ctl 0x1501000 status 0x400
ata5: CPB 0: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 1: ctl_flags 0x1f, resp_flags 0x2
ata5: CPB 2: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 3: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 4: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 5: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 6: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 7: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 8: ctl_flags 0x1f, resp_flags 0x2
ata5: CPB 9: ctl_flags 0x1f, resp_flags 0x2
ata5: CPB 10: ctl_flags 0x1f, resp_flags 0x2
ata5: CPB 11: ctl_flags 0x1f, resp_flags 0x2
ata5: CPB 12: ctl_flags 0x1f, resp_flags 0x2
ata5: CPB 13: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 14: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 15: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 16: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 17: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 18: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 19: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 20: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 21: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 22: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 23: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 24: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 25: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 26: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 27: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 28: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 29: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 30: ctl_flags 0x1f, resp_flags 0x1
ata5: Resetting port
ata5.00: exception Emask 0x0 SAct 0x1f02 SErr 0x0 action 0x2 frozen
ata5.00: cmd 60/40:08:8f:eb:67/00:00:03:00:00/40 tag 1 cdb 0x0 data 32768 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: cmd 60/08:40:17:eb:67/00:00:03:00:00/40 tag 8 cdb 0x0 data 4096 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: cmd 60/18:48:47:eb:67/00:00:03:00:00/40 tag 9 cdb 0x0 data 12288 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: cmd 60/08:50:77:eb:67/00:00:03:00:00/40 tag 10 cdb 0x0 data 4096 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: cmd 60/08:58:87:eb:67/00:00:03:00:00/40 tag 11 cdb 0x0 data 4096 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: cmd 60/48:60:d7:eb:67/00:00:03:00:00/40 tag 12 cdb 0x0 data 36864 in
         res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5: soft resetting port

The CPB resp_flags 0x2 entries are ones where the drive has been sent the request and the controller is waiting for a response. The timeout is 30 seconds, so that means the drive failed to service those queued commands for that length of time.

It may be that your drive has a poor NCQ implementation that can starve some of the pending commands for a long time under heavy load?

--
Robert Hancock      Saskatoon, SK, Canada
To email, remove "nospam" from [EMAIL PROTECTED]
Home Page: http://www.roberthancock.com/

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Reply via email to