linux/fs/xfs
Darrick J. Wong 3c919b0910 xfs: reserve less log space when recovering log intent items
Wengang Wang reports that a customer's system was running a number of
truncate operations on a filesystem with a very small log.  Contention
on the reserve heads lead to other threads stalling on smaller updates
(e.g.  mtime updates) long enough to result in the node being rebooted
on account of the lack of responsivenes.  The node failed to recover
because log recovery of an EFI became stuck waiting for a grant of
reserve space.  From Wengang's report:

"For the file deletion, log bytes are reserved basing on
xfs_mount->tr_itruncate which is:

    tr_logres = 175488,
    tr_logcount = 2,
    tr_logflags = XFS_TRANS_PERM_LOG_RES,

"You see it's a permanent log reservation with two log operations (two
transactions in rolling mode).  After calculation (xlog_calc_unit_res()
adds space for various log headers), the final log space needed per
transaction changes from  175488 to 180208 bytes.  So the total log
space needed is 360416 bytes (180208 * 2).  [That quantity] of log space
(360416 bytes) needs to be reserved for both run time inode removing
(xfs_inactive_truncate()) and EFI recover (xfs_efi_item_recover())."

In other words, runtime pre-reserves 360K of space in anticipation of
running a chain of two transactions in which each transaction gets a
180K reservation.

Now that we've allocated the transaction, we delete the bmap mapping,
log an EFI to free the space, and roll the transaction as part of
finishing the deferops chain.  Rolling creates a new xfs_trans which
shares its ticket with the old transaction.  Next, xfs_trans_roll calls
__xfs_trans_commit with regrant == true, which calls xlog_cil_commit
with the same regrant parameter.

xlog_cil_commit calls xfs_log_ticket_regrant, which decrements t_cnt and
subtracts t_curr_res from the reservation and write heads.

If the filesystem is fresh and the first transaction only used (say)
20K, then t_curr_res will be 160K, and we give that much reservation
back to the reservation head.  Or if the file is really fragmented and
the first transaction actually uses 170K, then t_curr_res will be 10K,
and that's what we give back to the reservation.

Having done that, we're now headed into the second transaction with an
EFI and 180K of reservation.  Other threads apparently consumed all the
reservation for smaller transactions, such as timestamp updates.

Now let's say the first transaction gets written to disk and we crash
without ever completing the second transaction.  Now we remount the fs,
log recovery finds the unfinished EFI, and calls xfs_efi_recover to
finish the EFI.  However, xfs_efi_recover starts a new tr_itruncate
tranasction, which asks for 360K log reservation.  This is a lot more
than the 180K that we had reserved at the time of the crash.  If the
first EFI to be recovered is also pinning the tail of the log, we will
be unable to free any space in the log, and recovery livelocks.

Wengang confirmed this:

"Now we have the second transaction which has 180208 log bytes reserved
too. The second transaction is supposed to process intents including
extent freeing.  With my hacking patch, I blocked the extent freeing 5
hours. So in that 5 hours, 180208 (NOT 360416) log bytes are reserved.

"With my test case, other transactions (update timestamps) then happen.
As my hacking patch pins the journal tail, those timestamp-updating
transactions finally use up (almost) all the left available log space
(in memory in on disk).  And finally the on disk (and in memory)
available log space goes down near to 180208 bytes.  Those 180208 bytes
are reserved by [the] second (extent-free) transaction [in the chain]."

Wengang and I noticed that EFI recovery starts a transaction, completes
one step of the chain, and commits the transaction without completing
any other steps of the chain.  Those subsequent steps are completed by
xlog_finish_defer_ops, which allocates yet another transaction to
finish the rest of the chain.  That transaction gets the same tr_logres
as the head transaction, but with tr_logcount = 1 to force regranting
with every roll to avoid livelocks.

In other words, we already figured this out in commit 929b92f640
("xfs: xfs_defer_capture should absorb remaining transaction
reservation"), but should have applied that logic to each intent item's
recovery function.  For Wengang's case, the xfs_trans_alloc call in the
EFI recovery function should only be asking for a single transaction's
worth of log reservation -- 180K, not 360K.

Quoting Wengang again:

"With log recovery, during EFI recovery, we use tr_itruncate again to
reserve two transactions that needs 360416 log bytes.  Reserving 360416
bytes fails [stalls] because we now only have about 180208 available.

"Actually during the EFI recover, we only need one transaction to free
the extents just like the 2nd transaction at RUNTIME.  So it only needs
to reserve 180208 rather than 360416 bytes.  We have (a bit) more than
180208 available log bytes on disk, so [if we decrease the reservation
to 180K] the reservation goes and the recovery [finishes].  That is to
say: we can fix the log recover part to fix the issue. We can introduce
a new xfs_trans_res xfs_mount->tr_ext_free

{
  tr_logres = 175488,
  tr_logcount = 0,
  tr_logflags = 0,
}

"and use tr_ext_free instead of tr_itruncate in EFI recover."

However, I don't think it quite makes sense to create an entirely new
transaction reservation type to handle single-stepping during log
recovery.  Instead, we should copy the transaction reservation
information in the xfs_mount, change tr_logcount to 1, and pass that
into xfs_trans_alloc.  We know this won't risk changing the min log size
computation since we always ask for a fraction of the reservation for
all known transaction types.

This looks like it's been lurking in the codebase since commit
3d3c8b5222, which changed the xfs_trans_reserve call in
xlog_recover_process_efi to use the tr_logcount in tr_itruncate.
That changed the EFI recovery transaction from making a
non-XFS_TRANS_PERM_LOG_RES request for one transaction's worth of log
space to a XFS_TRANS_PERM_LOG_RES request for two transactions worth.

Fixes: 3d3c8b5222 ("xfs: refactor xfs_trans_reserve() interface")
Complements: 929b92f640 ("xfs: xfs_defer_capture should absorb remaining transaction reservation")
Suggested-by: Wengang Wang <wen.gang.wang@oracle.com>
Cc: Srikanth C S <srikanth.c.s@oracle.com>
[djwong: apply the same transformation to all log intent recovery]
Signed-off-by: Darrick J. Wong <djwong@kernel.org>
Reviewed-by: Dave Chinner <dchinner@redhat.com>
2023-09-12 10:31:07 -07:00
..
libxfs xfs: reserve less log space when recovering log intent items 2023-09-12 10:31:07 -07:00
scrub New code for 6.6: 2023-08-30 12:34:12 -07:00
Kconfig xfs: track usage statistics of online fsck 2023-08-10 07:48:07 -07:00
kmem.c mm: introduce memalloc_retry_wait() 2022-01-15 16:30:29 +02:00
kmem.h
Makefile xfs: move the realtime summary file scrubber to a separate source file 2023-08-10 07:48:09 -07:00
mrlock.h
xfs_acl.c xfs: convert to ctime accessor functions 2023-07-24 10:30:06 +02:00
xfs_acl.h fs: port ->set_acl() to pass mnt_idmap 2023-01-19 09:24:27 +01:00
xfs_aops.c New code for 6.6: 2023-08-30 12:34:12 -07:00
xfs_aops.h
xfs_attr_inactive.c xfs: don't leak memory when attr fork loading fails 2022-07-20 16:40:39 -07:00
xfs_attr_item.c xfs: reserve less log space when recovering log intent items 2023-09-12 10:31:07 -07:00
xfs_attr_item.h xfs: share xattr name and value buffers when logging xattr updates 2022-05-23 08:43:46 +10:00
xfs_attr_list.c xfs: use XFS_IFORK_Q to determine the presence of an xattr fork 2022-07-09 15:17:21 -07:00
xfs_bio_io.c fs/xfs: Use the enum req_op and blk_opf_t types 2022-07-14 12:14:33 -06:00
xfs_bmap_item.c xfs: reserve less log space when recovering log intent items 2023-09-12 10:31:07 -07:00
xfs_bmap_item.h
xfs_bmap_util.c xfs: convert to ctime accessor functions 2023-07-24 10:30:06 +02:00
xfs_bmap_util.h xfs: xfs_bmap_punch_delalloc_range() should take a byte range 2022-11-29 09:09:17 +11:00
xfs_buf_item_recover.c xfs: verify buffer contents when we skip log replay 2023-04-12 15:49:23 +10:00
xfs_buf_item.c xfs: buffer pins need to hold a buffer reference 2023-06-05 04:05:27 +10:00
xfs_buf_item.h xfs: convert buffer log item flags to unsigned. 2022-04-21 10:46:40 +10:00
xfs_buf.c New code for 6.6: 2023-08-30 12:34:12 -07:00
xfs_buf.h xfs: allow scanning ranges of the buffer cache for live buffers 2023-08-10 07:48:03 -07:00
xfs_dahash_test.c xfs: test the ascii case-insensitive hash 2023-04-11 19:05:05 -07:00
xfs_dahash_test.h xfs: test dir/attr hash when loading module 2023-03-19 09:55:49 -07:00
xfs_dir2_readdir.c xfs: rearrange the logic and remove the broken comment for xfs_dir2_isxx 2022-10-04 16:39:58 +11:00
xfs_discard.c xfs: convert trim to use for_each_perag_range 2023-02-13 09:14:54 +11:00
xfs_discard.h
xfs_dquot_item_recover.c
xfs_dquot_item.c
xfs_dquot_item.h
xfs_dquot.c xfs: fix dqiterate thinko 2023-08-18 13:42:36 +05:30
xfs_dquot.h xfs: remove warning counters from struct xfs_dquot_res 2022-05-11 17:12:09 +10:00
xfs_drain.c xfs: minimize overhead of drain wakeups by using jump labels 2023-04-11 18:59:59 -07:00
xfs_drain.h xfs: minimize overhead of drain wakeups by using jump labels 2023-04-11 18:59:59 -07:00
xfs_error.c xfs: make kobj_type structures constant 2023-02-10 08:59:48 -08:00
xfs_error.h xfs: allow setting full range of panic tags 2023-02-09 18:36:17 -08:00
xfs_export.c
xfs_export.h
xfs_extent_busy.c xfs: don't block in busy flushing when freeing extents 2023-06-29 09:28:24 -07:00
xfs_extent_busy.h xfs: don't block in busy flushing when freeing extents 2023-06-29 09:28:24 -07:00
xfs_extfree_item.c xfs: reserve less log space when recovering log intent items 2023-09-12 10:31:07 -07:00
xfs_extfree_item.h xfs: refactor all the EFI/EFD log item sizeof logic 2022-10-31 08:58:20 -07:00
xfs_file.c mm: remove enum page_entry_size 2023-08-24 16:20:30 -07:00
xfs_filestream.c xfs: fix double xfs_perag_rele() in xfs_filestream_pick_ag() 2023-06-05 14:48:15 +10:00
xfs_filestream.h xfs: pass perag to filestreams tracing 2023-02-13 09:14:56 +11:00
xfs_fsmap.c xfs: fix an agbno overflow in __xfs_getfsmap_datadev 2023-09-11 08:39:02 -07:00
xfs_fsmap.h
xfs_fsops.c Minor cleanups for 6.5: 2023-07-09 09:50:42 -07:00
xfs_fsops.h
xfs_globals.c xfs: allow setting full range of panic tags 2023-02-09 18:36:17 -08:00
xfs_health.c
xfs_icache.c xfs: use per-mount cpumask to track nonempty percpu inodegc lists 2023-09-11 08:39:03 -07:00
xfs_icache.h xfs: use per-mount cpumask to track nonempty percpu inodegc lists 2023-09-11 08:39:03 -07:00
xfs_icreate_item.c xfs: fix potential log item leak 2022-05-04 11:45:11 +10:00
xfs_icreate_item.h
xfs_inode_item_recover.c xfs: clean up "%Ld/%Lu" which doesn't meet C standard 2022-09-19 06:47:14 +10:00
xfs_inode_item.c xfs: convert to ctime accessor functions 2023-07-24 10:30:06 +02:00
xfs_inode_item.h xfs: fix AGF vs inode cluster buffer deadlock 2023-06-05 04:08:27 +10:00
xfs_inode.c xfs: allow inode inactivation during a ro mount log recovery 2023-09-12 10:31:07 -07:00
xfs_inode.h xfs: collect errors from inodegc for unlinked inode recovery 2023-06-05 14:48:15 +10:00
xfs_ioctl32.c fs: port i_{g,u}id_into_vfs{g,u}id() to mnt_idmap 2023-01-19 09:24:29 +01:00
xfs_ioctl32.h xfs: remove unused xfs_ioctl32.h declarations 2022-01-18 10:18:36 -08:00
xfs_ioctl.c fs.idmapped.v6.3 2023-02-20 11:53:11 -08:00
xfs_ioctl.h fs: port ->fileattr_set() to pass mnt_idmap 2023-01-19 09:24:27 +01:00
xfs_iomap.c xfs: don't allocate into the data fork for an unshare request 2023-05-02 09:14:51 +10:00
xfs_iomap.h xfs: use iomap_valid method to detect stale cached iomaps 2022-11-29 09:09:17 +11:00
xfs_iops.c xfs: switch to multigrain timestamps 2023-08-11 09:04:57 +02:00
xfs_iops.h fs: port ->setattr() to pass mnt_idmap 2023-01-19 09:24:02 +01:00
xfs_itable.c xfs: convert to ctime accessor functions 2023-07-24 10:30:06 +02:00
xfs_itable.h fs: port i_{g,u}id_into_vfs{g,u}id() to mnt_idmap 2023-01-19 09:24:29 +01:00
xfs_iunlink_item.c xfs: create traced helper to get extra perag references 2023-04-11 18:59:55 -07:00
xfs_iunlink_item.h xfs: add in-memory iunlink log item 2022-07-14 11:47:42 +10:00
xfs_iwalk.c xfs: create traced helper to get extra perag references 2023-04-11 18:59:55 -07:00
xfs_iwalk.h xfs: Decouple XFS_IBULK flags from XFS_IWALK flags 2022-04-13 07:02:44 +00:00
xfs_linux.h xfs: create scaffolding for creating debugfs entries 2023-08-10 07:48:07 -07:00
xfs_log_cil.c xfs: fix per-cpu CIL structure aggregation racing with dying cpus 2023-09-11 08:39:02 -07:00
xfs_log_priv.h xfs: fix per-cpu CIL structure aggregation racing with dying cpus 2023-09-11 08:39:02 -07:00
xfs_log_recover.c xfs: collect errors from inodegc for unlinked inode recovery 2023-06-05 14:48:15 +10:00
xfs_log.c xfs: fix log recovery when unknown rocompat bits are set 2023-09-12 10:31:07 -07:00
xfs_log.h xfs: move CIL ordering to the logvec chain 2022-07-07 18:56:08 +10:00
xfs_message.c Merge branch 'guilt/xfs-unsigned-flags-5.18' into xfs-5.19-for-next 2022-04-21 16:45:03 +10:00
xfs_message.h xfs: implement per-mount warnings for scrub and shrink usage 2022-05-27 10:31:34 +10:00
xfs_mount.c xfs: track usage statistics of online fsck 2023-08-10 07:48:07 -07:00
xfs_mount.h xfs: remove the all-mounts list 2023-09-11 08:39:04 -07:00
xfs_mru_cache.c
xfs_mru_cache.h
xfs_notify_failure.c xfs: fix the calculation for "end" and "length" 2023-07-02 09:26:19 -07:00
xfs_ondisk.h xfs: convert flex-array declarations in xfs attr shortform objects 2023-07-17 08:48:56 -07:00
xfs_pnfs.c fs: port ->setattr() to pass mnt_idmap 2023-01-19 09:24:02 +01:00
xfs_pnfs.h
xfs_pwork.c
xfs_pwork.h
xfs_qm_bhv.c
xfs_qm_syscalls.c xfs: introduce xfs_inodegc_push() 2022-06-23 13:34:38 -07:00
xfs_qm.c xfs: quotacheck failure can race with background inode inactivation 2023-03-05 15:13:22 -08:00
xfs_qm.h xfs: remove quota warning limit from struct xfs_quota_limits 2022-05-11 17:12:09 +10:00
xfs_quota.h
xfs_quotaops.c xfs: don't set quota warning values 2022-05-11 17:12:09 +10:00
xfs_refcount_item.c xfs: reserve less log space when recovering log intent items 2023-09-12 10:31:07 -07:00
xfs_refcount_item.h
xfs_reflink.c xfs: use deferred frees for btree block freeing 2023-06-29 09:28:23 -07:00
xfs_reflink.h xfs: pass perag to xfs_alloc_read_agf() 2022-07-07 19:07:40 +10:00
xfs_rmap_item.c xfs: reserve less log space when recovering log intent items 2023-09-12 10:31:07 -07:00
xfs_rmap_item.h
xfs_rtalloc.c xfs: make rtbitmap ILOCKing consistent when scanning the rt bitmap file 2022-11-16 15:25:03 -08:00
xfs_rtalloc.h xfs: recalculate free rt extents after log recovery 2022-04-12 06:49:42 +10:00
xfs_stats.c xfs: replace unnecessary seq_printf with seq_puts 2022-09-19 06:48:14 +10:00
xfs_stats.h
xfs_super.c xfs: remove CPU hotplug infrastructure 2023-09-11 08:39:04 -07:00
xfs_super.h xfs: create scaffolding for creating debugfs entries 2023-08-10 07:48:07 -07:00
xfs_symlink.c fs: port fs{g,u}id helpers to mnt_idmap 2023-01-19 09:24:30 +01:00
xfs_symlink.h fs: port inode_init_owner() to mnt_idmap 2023-01-19 09:24:28 +01:00
xfs_sysctl.c xfs: simplify two-level sysctl registration for xfs_table 2023-04-13 11:49:35 -07:00
xfs_sysctl.h xfs: Add larp debug option 2022-05-11 17:01:22 +10:00
xfs_sysfs.c xfs: make kobj_type structures constant 2023-02-10 08:59:48 -08:00
xfs_sysfs.h xfs: make kobj_type structures constant 2023-02-10 08:59:48 -08:00
xfs_trace.c xfs: add debug knob to slow down writeback for fun 2022-11-28 17:24:35 -08:00
xfs_trace.h New code for 6.6: 2023-08-30 12:34:12 -07:00
xfs_trans_ail.c xfs: don't reverse order of items in bulk AIL insertion 2023-06-29 09:28:23 -07:00
xfs_trans_buf.c
xfs_trans_dquot.c xfs: remove quota warning limit from struct xfs_quota_limits 2022-05-11 17:12:09 +10:00
xfs_trans_priv.h xfs: convert log vector chain to use list heads 2022-07-07 18:55:59 +10:00
xfs_trans.c xfs: collect errors from inodegc for unlinked inode recovery 2023-06-05 14:48:15 +10:00
xfs_trans.h xfs: t_firstblock is tracking AGs not blocks 2023-02-11 04:11:06 +11:00
xfs_xattr.c fs: drop unused posix acl handlers 2023-03-06 09:57:12 +01:00
xfs_xattr.h xfs: move xfs_attr_use_log_assist usage out of libxfs 2022-05-27 10:34:04 +10:00
xfs.h