[AHCI] XFS (sda3): metadata I/O error: block 0x941ce20 ("xlog_iodone") error 5 numblks 64

From: Fengguang Wu
Date: Mon Nov 03 2014 - 23:25:46 EST


Hi Tejun,

FYI, we noticed the below changes on

git://git.kernel.org/pub/scm/linux/kernel/git/tj/libata for-3.18-fixes
commit 61e268068c92ed000f078dc1ab71d1228439fecd ("Revert "AHCI: Optimize single IRQ interrupt processing"")

+-----------------------------------------------------------+------------+------------+
| | aa1cf25887 | 61e268068c |
+-----------------------------------------------------------+------------+------------+
| boot_successes | 35 | 4 |
| early-boot-hang | 1 | |
| boot_failures | 0 | 8 |
| metadata_I/O_error:block#("xlog_iodone")error#numblks | 0 | 8 |
| XFS(sda3):Log_I/O_Error_Detected.Shutting_down_filesystem | 0 | 8 |
| Please_umount_the_filesystem_and_rectify_the_problem(s) | 0 | 8 |
+-----------------------------------------------------------+------------+------------+


[ 24.322655] sd 2:0:0:0: [sda] CDB:
[ 24.322657] Write(10): 2a 00 27 b5 22 10 00 00 10 00
[ 24.322659] ata2: EH complete
[ 24.322672] XFS (sda3): metadata I/O error: block 0x941ce20 ("xlog_iodone") error 5 numblks 64
[ 24.322674] XFS (sda3): xfs_do_force_shutdown(0x2) called from line 1181 of file fs/xfs/xfs_log.c. Return address = 0xffffffff81356796
[ 24.322710] XFS (sda3): Log I/O Error Detected. Shutting down filesystem
[ 24.322710] XFS (sda3): Please umount the filesystem and rectify the problem(s)
[ 24.322716] Buffer I/O error on device sda3, logical block 19432150
[ 24.322716] lost page write due to I/O error on sda3
[ 24.322720] Buffer I/O error on device sda3, logical block 19432151

To reproduce:

apt-get install ruby ruby-oj
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
cd lkp-tests
bin/setup-local job.yaml # the job file attached in this email
bin/run-local job.yaml

testbox/testcase/testparams: lkp-ne04/fsmark/performance-1x-32t-1HDD-xfs-5K-400M-fsyncBeforeClose-16d-256fpd

aa1cf25887099bba 61e268068c92ed000f078dc1ab
---------------- --------------------------
:15 20% 1:5 last_state.is_incomplete_run
:15 20% 1:5 last_state.booting
:15 80% 4:5 dmesg.Please_umount_the_filesystem_and_rectify_the_problem(s)
:15 80% 4:5 dmesg.XFS(sda3):Log_I/O_Error_Detected.Shutting_down_filesystem
:15 80% 4:5 dmesg.metadata_I/O_error:block#("xlog_iodone")error#numblks

testbox/testcase/testparams: lkp-ne04/fsmark/performance-1x-32t-1HDD-xfs-8K-400M-fsyncBeforeClose-16d-256fpd

aa1cf25887099bba 61e268068c92ed000f078dc1ab
---------------- --------------------------
fail:runs %reproduction fail:runs
| | |
:10 80% 4:5 dmesg.Please_umount_the_filesystem_and_rectify_the_problem(s)
:10 80% 4:5 dmesg.XFS(sda3):Log_I/O_Error_Detected.Shutting_down_filesystem
:10 80% 4:5 dmesg.metadata_I/O_error:block#("xlog_iodone")error#numblks
:10 80% 4:5 stderr.fopen_failed_to_open:fs_log.txt
:10 80% 4:5 stderr.fs_mark:fsync_failed_Input/output_error

Thanks,
Fengguang

Attachment: .dmesg
Description: Binary data

---
testcase: fsmark
default_monitors:
wait: pre-test
uptime:
iostat:
vmstat:
numa-numastat:
numa-vmstat:
numa-meminfo:
proc-vmstat:
proc-stat:
meminfo:
slabinfo:
interrupts:
lock_stat:
latency_stats:
softirqs:
bdi_dev_mapping:
diskstats:
cpuidle:
cpufreq:
turbostat:
sched_debug:
interval: 10
pmeter:
default_watchdogs:
watch-oom:
watchdog:
cpufreq_governor:
- performance
model: Nehalem-EP
memory: 12G
hdd_partitions: "/dev/disk/by-id/ata-ST3500514NS_9WJ03EBA-part3"
swap_partitions: "/dev/disk/by-id/ata-ST3120026AS_5MS07HA2-part2"
rootfs_partition: "/dev/disk/by-id/ata-ST3500514NS_9WJ03EBA-part1"
commit: 61e268068c92ed000f078dc1ab71d1228439fecd
iterations: 1x
nr_threads: 32t
disk: 1HDD
fs:
- xfs
fs2:
-
fsmark:
filesize:
- 5K
test_size: 400M
sync_method: fsyncBeforeClose
nr_directories: 16d
nr_files_per_directory: 256fpd
enqueue_time: 2014-10-31 18:16:31.406733520 +08:00
testbox: lkp-ne04
tbox_group: lkp-ne04
kconfig: x86_64-rhel
head_commit: 7d33fe9ab9eace2403adefea3c6dc2c92a0a5185
base_commit: cac7f2429872d3733dc3f9915857b1691da2eb2f
branch: linux-devel/devel-hourly-2014102723
user: lkp
queue: validate
rootfs: debian-x86_64.cgz
result_root: "/result/lkp-ne04/fsmark/performance-1x-32t-1HDD-xfs-5K-400M-fsyncBeforeClose-16d-256fpd/debian-x86_64.cgz/x86_64-rhel/61e268068c92ed000f078dc1ab71d1228439fecd/3"
job_file: "/lkp/scheduled/lkp-ne04/validate_fsmark-performance-1x-32t-1HDD-xfs-5K-400M-fsyncBeforeClose-16d-256fpd-debian-x86_64.cgz-x86_64-rhel-61e268068c92ed000f078dc1ab71d1228439fecd-2.yaml"
repeat_to: 5
kernel: "/kernel/x86_64-rhel/61e268068c92ed000f078dc1ab71d1228439fecd/vmlinuz-3.18.0-rc2-g61e2680"
dequeue_time: 2014-10-31 18:25:36.586355107 +08:00
job_state: failed
loadavg: 2.80 0.63 0.21 1/209 3265
start_time: '1414751176'
end_time: '1414751180'
version: "/lkp/lkp/.src-20141030-221304"