[BUG] XFS: Assertion failed: atomic_read(&pag->pag_ref) == 0, file: fs/xfs/xfs_mount.c, line: 272
Arkadiusz Bubała
arkadiusz.bubala at open-e.com
Mon May 27 07:40:53 CDT 2013
Hello,
>>>> Test environment consist two machines target and initiator.
>>>> First machine works as target with QLogic Corp. ISP2432-based 4Gb
>>>> Fibre Channel device. Storage is placed on two KINGSTON SNV425S SSD
>>>> working as RAID0 array. RAID is managed by LSI MegaRAID SAS 1068
>>>> controller.
>>>> Second machine works as initiator with the same QLogic card.
>>>>
>>>> After few days of running test script I got following call trace and
>>>> XFS stopped working.
>>>>
>>>>
>>> Can you narrow this down from "takes several days" to the simplest
>>> possible reproducer? It happened due to IO errors during mount, so
>>> maybe you can did that part out of your script and give us a test
>>> case that reproduces on the first mount?
>>>
>>>
>>>
>> I 'll try. This errors occurs only on heavy load.
>> Is there any possibility to simulate I/O errors on XFS filesystem?
>>
> You can use something like a dm-flakey or md-faulty block devices perhaps.
>
Thank you very much. Md-faulty helps to reproduce this problem. I can
repeat this problem after a few mounts.
Simple test script source for reproducing this problem:
#!/bin/bash
mdadm --create -l faulty /dev/md0 -n1 /dev/sda
parted /dev/md0 --script mklabel msdos
parted /dev/md0 --script mkpart primary 1 100
mkfs -t xfs -f -l lazy-count=0 /dev/md0p1
mdadm -G /dev/md0 -l faulty --layout=rt40
mkdir /mnt/test
while true; do
mount -t xfs -o defaults,usrquota,grpquota,nouuid,noatime,nodiratime
/dev/md0p1 /mnt/test
sleep 1
umount /dev/md0p1
done
And a call trace:
[ 994.403980] XFS (md0p1): Mounting Filesystem
[ 994.439392] XFS (md0p1): Ending clean mount
[ 994.439805] XFS (md0p1): Quotacheck needed: Please wait.
[ 994.453523] XFS (md0p1): Quotacheck: Done.
[ 995.494715] XFS (md0p1): Mounting Filesystem
[ 995.495310] XFS (md0p1): metadata I/O error: block 0x1905f
("xlog_bread_noalign") error 5 buf count 512
[ 995.557848] XFS (md0p1): empty log check failed
[ 995.557851] XFS (md0p1): log mount/recovery failed: error 5
[ 995.558284] XFS (md0p1): log mount failed
[ 996.585465] XFS (md0p1): Mounting Filesystem
[ 996.604007] XFS (md0p1): Ending clean mount
[ 997.633585] XFS (md0p1): last sector read failed
[ 998.642557] XFS (md0p1): Mounting Filesystem
[ 998.660927] XFS (md0p1): metadata I/O error: block 0x60
("xfs_trans_read_buf") error 5 buf count 4096
[ 998.723018] XFS (md0p1): Ending clean mount
[ 999.751782] XFS (md0p1): Mounting Filesystem
[ 999.779665] XFS (md0p1): metadata I/O error: block 0x60
("xfs_trans_read_buf") error 5 buf count 4096
[ 999.842094] XFS (md0p1): Ending clean mount
[ 1000.867508] XFS (md0p1): Mounting Filesystem
[ 1000.895354] XFS (md0p1): metadata I/O error: block 0x40
("xfs_trans_read_buf") error 5 buf count 8192
[ 1000.958168] XFS (md0p1): xfs_imap_to_bp: xfs_trans_read_buf()
returned error 5.
[ 1000.958172] XFS (md0p1): failed to read root inode
[ 1000.958240] XFS: Assertion failed: atomic_read(&pag->pag_ref) == 0,
file: fs/xfs/xfs_mount.c, line: 272
[ 1001.022557] ------------[ cut here ]------------
[ 1001.054458] kernel BUG at fs/xfs/xfs_message.c:101!
[ 1001.054461] invalid opcode: 0000 [#1] SMP
[ 1001.054464] CPU 1
[ 1001.054465] Modules linked in: iscsi_scst(O) scst_vdisk(O) scst(O)
libcrc32c ext2 drbd(O) iscsi_tcp libiscsi_tcp libiscsi
scsi_transport_iscsi bonding sg e1000e(O) usbserial uhci_hcd ohci_hcd
ehci_hcd aufs [last unloaded: ohci_hcd]
[ 1001.054477]
[ 1001.054479] Pid: 18813, comm: mount Tainted: G O
3.2.42-oe64-00000-gd572330 #1 Supermicro C2SBC-Q/C2SBC-Q
[ 1001.054482] RIP: 0010:[<ffffffff812ff8ed>] [<ffffffff812ff8ed>]
assfail+0x1d/0x30
[ 1001.054488] RSP: 0000:ffff880112849c68 EFLAGS: 00010296
[ 1001.054490] RAX: 0000000000000071 RBX: ffff880108d77840 RCX:
ffff88013b006c00
[ 1001.054491] RDX: 00000000000000c2 RSI: 0000000000000000 RDI:
ffffffff81ded518
[ 1001.054493] RBP: ffff880112849c68 R08: ffff88013b006c00 R09:
ffff88013fd120c0
[ 1001.054494] R10: 0000000000000000 R11: 0000000000000002 R12:
ffff88013988d000
[ 1001.054496] R13: 0000000000000000 R14: ffff88013988d1e8 R15:
ffff88013988d1f8
[ 1001.054498] FS: 0000000000000000(0000) GS:ffff88013fd00000(0063)
knlGS:00000000f75386c0
[ 1001.054499] CS: 0010 DS: 002b ES: 002b CR0: 000000008005003b
[ 1001.054501] CR2: 00000000f75f5540 CR3: 0000000135d33000 CR4:
00000000000406e0
[ 1001.054502] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
[ 1001.054504] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7:
0000000000000400
[ 1001.054506] Process mount (pid: 18813, threadinfo ffff880112848000,
task ffff8801355cb410)
[ 1001.054507] Stack:
[ 1001.054508] ffff880112849ca8 ffffffff8134eb7a 0000000000000005
ffff88013988d000
[ 1001.054510] ffff88013988d018 0000000000000005 ffff88013988d000
0000000000000000
[ 1001.054513] ffff880112849cf8 ffffffff8135054d 0000000000000000
0000000000000000
[ 1001.054515] Call Trace:
[ 1001.054519] [<ffffffff8134eb7a>] xfs_free_perag+0x8a/0xc0
[ 1001.054521] [<ffffffff8135054d>] xfs_mountfs+0x31d/0x700
[ 1001.054524] [<ffffffff81301fab>] xfs_fs_fill_super+0x1cb/0x270
[ 1001.054527] [<ffffffff811476da>] mount_bdev+0x19a/0x1d0
[ 1001.054529] [<ffffffff81301de0>] ? xfs_fs_write_inode+0x180/0x180
[ 1001.054533] [<ffffffff8138b006>] ? selinux_sb_copy_data+0x156/0x1d0
[ 1001.054536] [<ffffffff81300200>] xfs_fs_mount+0x10/0x20
[ 1001.054538] [<ffffffff81146df1>] mount_fs+0x41/0x180
[ 1001.054541] [<ffffffff8115f7ae>] vfs_kern_mount+0x5e/0xc0
[ 1001.054543] [<ffffffff8116075e>] do_kern_mount+0x4e/0x100
[ 1001.054545] [<ffffffff81161f26>] do_mount+0x516/0x740
[ 1001.054548] [<ffffffff811064e9>] ? __get_free_pages+0x9/0x40
[ 1001.054551] [<ffffffff81187cc2>] compat_sys_mount+0xa2/0x220
[ 1001.054554] [<ffffffff8178be43>] ia32_do_call+0x13/0x13
[ 1001.054555] Code: 66 66 90 66 66 66 90 66 66 66 90 66 66 90 55 41 89
d0 48 89 f1 48 89 fa 48 c7 c6 b8 bf 9b 81 31 ff 48 89 e5 31 c0 e8 53 ff
ff ff <0f> 0b eb fe 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 55 31
[ 1001.054571] RIP [<ffffffff812ff8ed>] assfail+0x1d/0x30
[ 1001.054573] RSP <ffff880112849c68>
[ 1001.054575] ---[ end trace 9fa869a5d6931100 ]---
I also reproduced this call trace on kernel 3.4.39
[ 486.338190] md: bind<sda>
[ 486.342375] bio: create slab <bio-1> at 1
[ 486.342387] md0: detected capacity change from 0 to 500107771904
[ 486.354250] md0: p1
[ 486.709863] XFS (md0p1): Mounting Filesystem
[ 486.738741] XFS (md0p1): Ending clean mount
[ 486.739136] XFS (md0p1): Quotacheck needed: Please wait.
[ 486.767727] XFS (md0p1): Quotacheck: Done.
[ 487.808918] XFS (md0p1): Mounting Filesystem
[ 487.809500] XFS (md0p1): metadata I/O error: block 0x1905f
("xlog_bread_noalign") error 5 buf count 512
[ 487.871589] XFS (md0p1): empty log check failed
[ 487.871591] XFS (md0p1): log mount/recovery failed: error 5
[ 487.871667] XFS (md0p1): log mount failed
[ 488.899680] XFS (md0p1): Mounting Filesystem
[ 488.917484] XFS (md0p1): Ending clean mount
[ 489.943430] XFS (md0p1): last sector read failed
[ 490.957577] XFS (md0p1): Mounting Filesystem
[ 490.975022] XFS (md0p1): metadata I/O error: block 0x60
("xfs_trans_read_buf") error 5 buf count 4096
[ 491.037209] XFS (md0p1): Ending clean mount
[ 494.478260] Buffer I/O error on device md0p1, logical block 23
[ 494.479204] Buffer I/O error on device md0p1, logical block 63
[ 494.479540] Buffer I/O error on device md0p1, logical block 15
[ 498.577283] XFS (md0p1): Mounting Filesystem
[ 498.604225] XFS (md0p1): metadata I/O error: block 0x60
("xfs_trans_read_buf") error 5 buf count 4096
[ 498.666825] XFS (md0p1): Ending clean mount
[ 499.693310] XFS (md0p1): Mounting Filesystem
[ 499.719749] XFS (md0p1): metadata I/O error: block 0x40
("xfs_trans_read_buf") error 5 buf count 8192
[ 499.782405] XFS (md0p1): xfs_imap_to_bp: xfs_trans_read_buf()
returned error 5.
[ 499.782409] XFS (md0p1): failed to read root inode
[ 499.782482] XFS: Assertion failed: atomic_read(&pag->pag_ref) == 0,
file: fs/xfs/xfs_mount.c, line: 272
[ 499.846615] ------------[ cut here ]------------
[ 499.878410] kernel BUG at fs/xfs/xfs_message.c:101!
[ 499.878412] invalid opcode: 0000 [#1] SMP
[ 499.878415] CPU 0
[ 499.878416] Modules linked in: iscsi_scst(O) scst_vdisk(O) scst(O)
libcrc32c ext2 drbd(O) iscsi_tcp libiscsi_tcp libiscsi
scsi_transport_iscsi bonding sg e1000e(O) usbserial uhci_hcd ohci_hcd
ehci_hcd aufs [last unloaded: ohci_hcd]
[ 499.878426]
[ 499.878428] Pid: 17632, comm: mount Tainted: G O
3.4.39-oe64-00000-g8b0d7e5 #9 Supermicro C2SBC-Q/C2SBC-Q
[ 499.878431] RIP: 0010:[<ffffffff812fe68d>] [<ffffffff812fe68d>]
assfail+0x1d/0x30
[ 499.878437] RSP: 0000:ffff880135381c78 EFLAGS: 00010296
[ 499.878439] RAX: 0000000000000071 RBX: ffff88013a5c0540 RCX:
ffff88013b006c00
[ 499.878440] RDX: 00000000000000eb RSI: 0000000000000046 RDI:
0000000000000000
[ 499.878442] RBP: ffff880135381c78 R08: ffff88013b006c00 R09:
ffff88013fc12440
[ 499.878443] R10: ffff88013fd124e8 R11: 0000000000000000 R12:
ffff880139736000
[ 499.878445] R13: 0000000000000000 R14: ffff8801397361e8 R15:
ffff8801397361f8
[ 499.878446] FS: 0000000000000000(0000) GS:ffff88013fc00000(0063)
knlGS:00000000f75146c0
[ 499.878448] CS: 0010 DS: 002b ES: 002b CR0: 000000008005003b
[ 499.878449] CR2: 00000000f7751181 CR3: 00000001359b4000 CR4:
00000000000407f0
[ 499.878451] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
[ 499.878452] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7:
0000000000000400
[ 499.878454] Process mount (pid: 17632, threadinfo ffff880135380000,
task ffff880135005120)
[ 499.878455] Stack:
[ 499.878456] ffff880135381cb8 ffffffff8134e68b 0000000000000005
ffff880139736000
[ 499.878458] ffff880139736018 0000000000000005 ffff880139736000
ffff8801352a9c00
[ 499.878461] ffff880135381d08 ffffffff8135008d 0000000000000000
0000000000000000
[ 499.878463] Call Trace:
[ 499.878466] [<ffffffff8134e68b>] xfs_free_perag+0x8b/0xc0
[ 499.878469] [<ffffffff8135008d>] xfs_mountfs+0x31d/0x700
[ 499.878471] [<ffffffff81300dd0>] xfs_fs_fill_super+0x1e0/0x280
[ 499.878474] [<ffffffff8114dcab>] mount_bdev+0x19b/0x1d0
[ 499.878476] [<ffffffff81300bf0>] ? xfs_fs_evict_inode+0x130/0x130
[ 499.878479] [<ffffffff81388f46>] ? selinux_sb_copy_data+0x156/0x1d0
[ 499.878481] [<ffffffff812ff050>] xfs_fs_mount+0x10/0x20
[ 499.878483] [<ffffffff8114d341>] mount_fs+0x41/0x180
[ 499.878486] [<ffffffff81166f99>] vfs_kern_mount+0x69/0xf0
[ 499.878488] [<ffffffff811670ae>] do_kern_mount+0x4e/0x100
[ 499.878490] [<ffffffff8116805a>] do_mount+0x51a/0x760
[ 499.878492] [<ffffffff8110bee9>] ? __get_free_pages+0x9/0x40
[ 499.878496] [<ffffffff8118ee32>] compat_sys_mount+0xa2/0x220
[ 499.878498] [<ffffffff8108694f>] ? sys_rt_sigprocmask+0xbf/0xd0
[ 499.878501] [<ffffffff81794169>] ia32_do_call+0x13/0x13
[ 499.878502] Code: 66 66 90 66 66 66 90 66 66 66 90 66 66 90 55 41 89
d0 48 89 f1 48 89 fa 48 c7 c6 d0 cb 9b 81 31 ff 48 89 e5 31 c0 e8 53 ff
ff ff <0f> 0b eb fe 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 55 31
[ 499.878518] RIP [<ffffffff812fe68d>] assfail+0x1d/0x30
[ 499.878520] RSP <ffff880135381c78>
[ 499.878522] ---[ end trace 37e88031b68311f3 ]---
--
Best regards
Arkadiusz Bubała
More information about the xfs
mailing list