On Thu, Jun 15, 2017 at 10:07:57AM -0700, Darrick J. Wong wrote:
> On Fri, Jun 09, 2017 at 01:38:09PM -0400, Brian Foster wrote:
> > Log recovery allocates in-core transaction and member item data
> > structures on-demand as it processes the on-disk log. Transactions
> > are allocated on first encounter on-disk and stored in a hash table
> > structure where they are easily accessible for subsequent lookups.
> > Transaction items are also allocated on demand and are attached to
> > the associated transactions.
> >
> > When a commit record is encountered in the log, the transaction is
> > committed to the fs and the in-core structures are freed. If a
> > filesystem crashes or shuts down before all in-core log buffers are
> > flushed to the log, however, not all transactions may have commit
> > records in the log. As expected, the modifications in such an
> > incomplete transaction are not replayed to the fs. The in-core data
> > structures for the partial transaction are never freed, however,
> > resulting in a memory leak.
> >
> > Update xlog_do_recovery_pass() to walk the hash table of transaction
> > lists as the last step before it goes out of scope and free any
> > transactions that may remain on the lists. This prevents a memory
> > leak of partial transactions in the log.
> >
> > Signed-off-by: Brian Foster <bfoster@xxxxxxxxxx>
> > ---
> >
> > FYI, I suspect this has been a problem for a while and and rare/harmless
> > enough that this can target 4.13.
> >
> > Brian
> >
> > fs/xfs/xfs_log_recover.c | 14 ++++++++++++++
> > 1 file changed, 14 insertions(+)
> >
> > diff --git a/fs/xfs/xfs_log_recover.c b/fs/xfs/xfs_log_recover.c
> > index 4a98762..37b34c5 100644
> > --- a/fs/xfs/xfs_log_recover.c
> > +++ b/fs/xfs/xfs_log_recover.c
> > @@ -5224,6 +5224,7 @@ xlog_do_recovery_pass(
> > int error2 = 0;
> > int bblks, split_bblks;
> > int hblks, split_hblks, wrapped_hblks;
> > + int i;
> > struct hlist_head rhash[XLOG_RHASH_SIZE];
> > LIST_HEAD (buffer_list);
> >
> > @@ -5466,6 +5467,19 @@ xlog_do_recovery_pass(
> > if (error && first_bad)
> > *first_bad = rhead_blk;
> >
> > + /*
> > + * Transactions are freed at commit time but transactions without commit
> > + * records on disk are never committed. Free any that may be left in the
> > + * hash table.
> > + */
> > + for (i = 0; i < XLOG_RHASH_SIZE; i++) {
> > + struct hlist_node *tmp;
> > + struct xlog_recover *trans;
> > +
> > + hlist_for_each_entry_safe(trans, tmp, &rhash[i], r_list)
> > + xlog_recover_free_trans(trans);
> > + }
>
> Hmm, I just got the following crash in xfs/051:
>
> [ 131.456722] XFS (dm-0): Mounting V5 Filesystem
> [ 131.462826] XFS (dm-0): Delaying log recovery for 10 seconds.
> [ 141.532271] XFS (dm-0): Starting recovery (logdev: internal)
> [ 141.534418] XFS (dm-0): metadata I/O error: block 0x182e70 ("xlog_bread_noalign") error 5 numblks 8
> [ 141.539561] general protection fault: 0000 [#1] PREEMPT SMP
Ugh, not sure how I missed that. Must have disabled debug mode or
something. Anyways, I can reproduce and I'll look into it. Thanks for
catching this.
Brian
> [ 141.542236] Dumping ftrace buffer:
> [ 141.542972] (ftrace buffer empty)
> [ 141.543083] Modules linked in: xfs dm_flakey libcrc32c dax_pmem device_dax nd_pmem binfmt_misc nfsd auth_rpcgss sch_fq_codel af_packet [last unloaded: xfs]
> [ 141.543083] CPU: 1 PID: 3246 Comm: mount Not tainted 4.12.0-rc5-dgc #1
> [ 141.543083] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS Ubuntu-1.8.2-1ubuntu1 04/01/2014
> [ 141.543083] task: ffff88006e0ca900 task.stack: ffffc90001d70000
> [ 141.543083] RIP: 0010:xlog_recover_free_trans+0x1d/0xb0 [xfs]
> [ 141.543083] RSP: 0018:ffffc90001d73b30 EFLAGS: 00010286
> [ 141.543083] RAX: ffffc90001d73bc0 RBX: 00000000fffffffb RCX: ffffc90001d73bc0
> [ 141.543083] RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffff8800756ae800
> [ 141.543083] RBP: ffffc90001d73b58 R08: 0000000000000001 R09: 0000000000000000
> [ 141.543083] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8800756ae830
> [ 141.543083] R13: ffff8800756ae800 R14: ffffc90001d73bd0 R15: 206b636f6c62203a
> [ 141.543083] FS: 00007fe28e0d6840(0000) GS:ffff88007f200000(0000) knlGS:0000000000000000
> [ 141.543083] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 141.543083] CR2: 00007fe28d6a0cf9 CR3: 000000007b3de000 CR4: 00000000001406e0
> [ 141.543083] Call Trace:
> [ 141.543083] xlog_do_recovery_pass+0x3ec/0x740 [xfs]
> [ 141.543083] ? rcu_read_lock_sched_held+0x72/0x80
> [ 141.543083] ? __kmalloc+0x26c/0x2d0
> [ 141.543083] ? kmem_alloc+0x81/0x100 [xfs]
> [ 141.543083] ? kmem_alloc+0x81/0x100 [xfs]
> [ 141.543083] xlog_do_log_recovery+0x70/0x150 [xfs]
> [ 141.543083] xlog_do_recover+0x1b/0x170 [xfs]
> [ 141.543083] xlog_recover+0xa2/0x130 [xfs]
> [ 141.543083] xfs_log_mount+0xdb/0x2e0 [xfs]
> [ 141.543083] xfs_mountfs+0x579/0xad0 [xfs]
> [ 141.543083] xfs_fs_fill_super+0x483/0x610 [xfs]
> [ 141.543083] mount_bdev+0x180/0x1b0
> [ 141.543083] ? xfs_finish_flags+0x150/0x150 [xfs]
> [ 141.543083] xfs_fs_mount+0x15/0x20 [xfs]
> [ 141.543083] mount_fs+0x14/0x80
> [ 141.543083] vfs_kern_mount+0x67/0x150
> [ 141.543083] do_mount+0x195/0xd10
> [ 141.543083] ? _copy_from_user+0x47/0x80
> [ 141.543083] ? memdup_user+0x60/0x90
> [ 141.543083] SyS_mount+0x95/0xe0
> [ 141.543083] entry_SYSCALL_64_fastpath+0x1f/0xbe
> [ 141.543083] RIP: 0033:0x7fe28d9b7faa
> [ 141.543083] RSP: 002b:00007ffe9168f628 EFLAGS: 00000206 ORIG_RAX: 00000000000000a5
> [ 141.543083] RAX: ffffffffffffffda RBX: 00007fe28dcb063a RCX: 00007fe28d9b7faa
> [ 141.543083] RDX: 0000000001ab2240 RSI: 0000000001ab2280 RDI: 0000000001ab2260
> [ 141.543083] RBP: 0000000001ab2120 R08: 0000000000000000 R09: 0000000000000012
> [ 141.543083] R10: 00000000c0ed0000 R11: 0000000000000206 R12: 00007fe28dec083c
> [ 141.543083] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000003
> [ 141.543083] Code: 5d c3 31 c0 c3 66 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 55 48 89 e5 41 57 41 56 41 55 41 54 4c 8d 67 30 53 4c 8b 7f 30 49 89 fd <49> 8b 1f 4d 39 e7 48 89 d8 74 6f 49 8b 57 08 45 31 f6 48 89 50
> [ 141.543083] RIP: xlog_recover_free_trans+0x1d/0xb0 [xfs] RSP: ffffc90001d73b30
> [ 141.591289] ---[ end trace b3d5b2775a86318f ]---
>
> FWIW I was testing 4.13 for-next with the following xfstest config:
>
> FSTYP -- xfs (debug)
> PLATFORM -- Linux/x86_64 birch-mtr0 4.12.0-rc5-dgc
> MKFS_OPTIONS -- -f -m reflink=1,rmapbt=1, -i sparse=1, /dev/pmem1
> MOUNT_OPTIONS -- /dev/pmem1 /opt
>
> --D
>
> > +
> > return error ? error : error2;
> > }
> >
> > --
> > 2.7.5
> >
> > --
> > To unsubscribe from this list: send the line "unsubscribe linux-xfs" in
> > the body of a message to majordomo@xxxxxxxxxxxxxxx
> > More majordomo info at http://vger.kernel.org/majordomo-info.html
> --
> To unsubscribe from this list: send the line "unsubscribe linux-xfs" in
> the body of a message to majordomo@xxxxxxxxxxxxxxx
> More majordomo info at http://vger.kernel.org/majordomo-info.html
--
To unsubscribe from this list: send the line "unsubscribe linux-xfs" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
