Re: [PATCH 03/18] xfs: Do background CIL flushes via a workqueue

Dave Chinner
2012-04-18T01:47:10Z

On Tue, Apr 17, 2012 at 04:49:56PM -0500, Ben Myers wrote:
> On Tue, Apr 17, 2012 at 04:21:55PM -0500, Ben Myers wrote:
> > Gah! I just hit this assert.
> >
> > v3.4-rc2-3-g8a00ebe with:
> > Christoph's ilock series
> > Christoph's xfsbufd series
> > Jan's freeze series
> > Dave's queue.
> >
> > nfs7 login: [ 1175.172406] XFS: Assertion failed: push_seq > 0 && push_seq <= ctx->sequence, file: /root/xfs/fs/xfs/xfs_log_cil.c, line: 406

which has probably resulted in a log corruption.

> [ 390.097633] ---[ end trace 33a9795b638157b9 ]---
>
> Here it is from the system log
>
> Apr 17 16:35:12 linux kernel: [ 389.637543] XFS (264=211361P۔300): Mounting Filesystem
> Apr 17 16:35:12 linux kernel: [ 389.912402] XFS (264=211361P۔300): Starting recovery (logdev: internal)
> Apr 17 16:35:12 linux kernel: [ 390.054357] XFS (264=211361P۔300): xlog_recover_inode_pass2: Bad inode magic number, dip = 0xf0ffd800, dino bp = 0xef89c480, ino = 25541592
> Apr 17 16:35:12 linux kernel: [ 390.066290] XFS (264=211361P۔300): Internal error xlog_recover_inode_pass2(1) at line 2248 of file /root/xfs/fs/xfs/xfs_log_recover.c. Caller 0xfaa08ffa

Because log recovery has read a bad inode from disk, which means an
allocation transaction has probably not been replayed.

....

> Apr 17 16:35:12 linux kernel: [ 390.082084] XFS (264=211361P۔300): log mount/recovery failed: error 117
> Apr 17 16:35:12 linux kernel: [ 390.082209] XFS (264=211361P۔300): log mount failed
> Apr 17 16:35:12 linux kernel: [ 390.082217] XFS: Assertion failed: atomic_read(&pag->pag_ref) == 0, file: /root/xfs/fs/xfs/xfs_mount.c, line: 272
>
> Apr 17 16:35:12 linux kernel: [ 390.092542] ------------[ cut here ]------------
> Apr 17 16:35:12 linux kernel: [ 390.097004] kernel BUG at /root/xfs/fs/xfs/xfs_message.c:101!
> Apr 17 16:35:12 linux kernel: [ 390.097004] invalid opcode: 0000 [#1] PREEMPT SMP
> Apr 17 16:35:12 linux kernel: [ 390.097004] Modules linked in: xfs(O) exportfs af_packet dm_mod e1000 e100 sr_mod shpchp iTCO_wdt cdrom i2c_i801 e7xxx_edac iTCO_vendor_support sg floppy pci_hotplug serio_raw button edac_core pcspkr autofs4 processor thermal_sys ata_generic
> Apr 17 16:35:12 linux kernel: [ 390.097004]
> Apr 17 16:35:12 linux kernel: [ 390.097004] Pid: 5217, comm: mount Tainted: G O 3.4.0-rc2-1.2-desktop+ #15 TYAN Computer Corp. S2721-533 Thunder i7501 Pro/S2721-533 Thunder i7501 Pro
> Apr 17 16:35:12 linux kernel: [ 390.097004] EIP: 0060:[<fa9b8d56>] EFLAGS: 00010286 CPU: 3
> Apr 17 16:35:12 linux kernel: [ 390.097004] EIP is at assfail+0x26/0x30 [xfs]
> Apr 17 16:35:12 linux kernel: [ 390.097004] EAX: 0000007b EBX: f0f87680 ECX: 000000f3 EDX: 00000046
> Apr 17 16:35:12 linux kernel: [ 390.097004] ESI: 00000000 EDI: f1d089a8 EBP: f1d67ddc ESP: f1d67dc8
> Apr 17 16:35:12 linux kernel: [ 390.097004] DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
> Apr 17 16:35:12 linux kernel: [ 390.097004] CR0: 8005003b CR2: b7735580 CR3: 2ff82000 CR4: 000007f0
> Apr 17 16:35:12 linux kernel: [ 390.097004] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
> Apr 17 16:35:12 linux kernel: [ 390.097004] DR6: ffff0ff0 DR7: 00000400
> Apr 17 16:35:12 linux kernel: [ 390.097004] Process mount (pid: 5217, ti=f1d66000 task=f0d99060 task.ti=f1d66000)
> Apr 17 16:35:12 linux kernel: [ 390.097004] Stack:
> Apr 17 16:35:12 linux kernel: [ 390.097004] 00000000 faa31844 faa399d4 faa41a7f 00000110 f1d67df8 faa0b125 f1d0899c
> Apr 17 16:35:12 linux kernel: [ 390.097004] f1d08800 00000075 f1d08800 00000014 f1d67e50 faa0dfe9 f1d08800 faa41c34
> Apr 17 16:35:12 linux kernel: [ 390.097004] 00005000 ef82b700 fa9aea50 f1d67e24 f1d08acc 00000000 00000002 00000003
> Apr 17 16:35:12 linux kernel: [ 390.097004] Call Trace:
> Apr 17 16:35:12 linux kernel: [ 390.097004] [<faa0b125>] xfs_free_perag+0x75/0xa0 [xfs]
> Apr 17 16:35:12 linux kernel: [ 390.097004] [<faa0dfe9>] xfs_mountfs+0x2d9/0x710 [xfs]
> Apr 17 16:35:12 linux kernel: [ 390.097004] [<fa9aea50>] ? _xfs_filestream_pick_ag+0x1b0/0x1b0 [xfs]
> Apr 17 16:35:12 linux kernel: [ 390.097004] [<fa9bb5d6>] xfs_fs_fill_super+0x196/0x240 [xfs]
> Apr 17 16:35:12 linux kernel: [ 390.097004] [<c031ce72>] mount_bdev+0x172/0x1b0
> Apr 17 16:35:12 linux kernel: [ 390.097004] [<fa9b965a>] xfs_fs_mount+0x1a/0x20 [xfs]

And that's a different problem that Eric tripped over a couple of
weeks ago, but hasn't sent a new patch to fix:

http://oss.sgi.com/archives/xfs/2012-04/msg00035.html
http://oss.sgi.com/archives/xfs/2012-04/msg00115.html

Cheers,

Dave.
--
Dave Chinner
david@fromorbit.com