On Thu, Mar 14, 2019 at 02:29:12PM -0700, Darrick J. Wong wrote:
> From: Darrick J. Wong <darrick.wong@xxxxxxxxxx>
>
> This is a debugging patch to keep track of cases where transaction
> reservations with permanent reservations do not reserve enough logcount
> to handle the entire workflow.
>
> Signed-off-by: Darrick J. Wong <darrick.wong@xxxxxxxxxx>
> ---
> fs/xfs/xfs_log.c | 11 +++++++++++
> fs/xfs/xfs_log_priv.h | 3 +++
> fs/xfs/xfs_trace.h | 10 +++++++++-
> 3 files changed, 23 insertions(+), 1 deletion(-)
>
>
> diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c
> index c3b610b687d1..8832cc86566f 100644
> --- a/fs/xfs/xfs_log.c
> +++ b/fs/xfs/xfs_log.c
> @@ -385,6 +385,9 @@ xfs_log_regrant(
>
> if (tic->t_cnt > 0)
> return 0;
> +#ifdef DEBUG
> + tic->t_spillcnt++;
> +#endif
>
> trace_xfs_log_regrant(log, tic);
>
Don't we already kind of have this contextual information with the
xfs_log_regrant* tracepoints? I guess we don't have the count
information explicitly, but it seems it can be deduced from a trace
dump.
We also already have an 'xs_try_logspace' stat in the reservation cases.
I wonder if a similar regrant stat for the exhausted reservation case
might be useful enough (and not require debug code) to determine whether
a particular workload is experiencing this problem.
Brian
> @@ -3124,6 +3127,9 @@ xlog_regrant_reserve_log_space(
> /* just return if we still have some of the pre-reserved space */
> if (ticket->t_cnt > 0)
> return;
> +#ifdef DEBUG
> + ticket->t_spillcnt++;
> +#endif
>
> xlog_grant_add_space(log, &log->l_reserve_head.grant,
> ticket->t_unit_res);
> @@ -3159,6 +3165,11 @@ xlog_ungrant_log_space(
> if (ticket->t_cnt > 0)
> ticket->t_cnt--;
>
> +#ifdef DEBUG
> + if (ticket->t_spillcnt > 0)
> + trace_xfs_log_ungrant_spill(log, ticket);
> +#endif
> +
> trace_xfs_log_ungrant_enter(log, ticket);
> trace_xfs_log_ungrant_sub(log, ticket);
>
> diff --git a/fs/xfs/xfs_log_priv.h b/fs/xfs/xfs_log_priv.h
> index b5f82cb36202..37302d2ad288 100644
> --- a/fs/xfs/xfs_log_priv.h
> +++ b/fs/xfs/xfs_log_priv.h
> @@ -161,6 +161,9 @@ typedef struct xlog_ticket {
> int t_unit_res; /* unit reservation in bytes : 4 */
> char t_ocnt; /* original count : 1 */
> char t_cnt; /* current count : 1 */
> +#ifdef DEBUG
> + char t_spillcnt; /* underestimation of ocnt : 1 */
> +#endif
> char t_clientid; /* who does this belong to; : 1 */
> char t_flags; /* properties of reservation : 1 */
>
> diff --git a/fs/xfs/xfs_trace.h b/fs/xfs/xfs_trace.h
> index bd9a48fa80ba..b765b2761382 100644
> --- a/fs/xfs/xfs_trace.h
> +++ b/fs/xfs/xfs_trace.h
> @@ -937,6 +937,7 @@ DECLARE_EVENT_CLASS(xfs_loggrant_class,
> __field(dev_t, dev)
> __field(char, ocnt)
> __field(char, cnt)
> + __field(int, spillcnt)
> __field(int, curr_res)
> __field(int, unit_res)
> __field(unsigned int, flags)
> @@ -954,6 +955,11 @@ DECLARE_EVENT_CLASS(xfs_loggrant_class,
> __entry->dev = log->l_mp->m_super->s_dev;
> __entry->ocnt = tic->t_ocnt;
> __entry->cnt = tic->t_cnt;
> +#ifdef DEBUG
> + __entry->spillcnt = tic->t_spillcnt;
> +#else
> + __entry->spillcnt = -1;
> +#endif
> __entry->curr_res = tic->t_curr_res;
> __entry->unit_res = tic->t_unit_res;
> __entry->flags = tic->t_flags;
> @@ -969,7 +975,7 @@ DECLARE_EVENT_CLASS(xfs_loggrant_class,
> __entry->curr_block = log->l_curr_block;
> __entry->tail_lsn = atomic64_read(&log->l_tail_lsn);
> ),
> - TP_printk("dev %d:%d t_ocnt %u t_cnt %u t_curr_res %u "
> + TP_printk("dev %d:%d t_ocnt %u t_cnt %u spill %u t_curr_res %u "
> "t_unit_res %u t_flags %s reserveq %s "
> "writeq %s grant_reserve_cycle %d "
> "grant_reserve_bytes %d grant_write_cycle %d "
> @@ -978,6 +984,7 @@ DECLARE_EVENT_CLASS(xfs_loggrant_class,
> MAJOR(__entry->dev), MINOR(__entry->dev),
> __entry->ocnt,
> __entry->cnt,
> + __entry->spillcnt,
> __entry->curr_res,
> __entry->unit_res,
> __print_flags(__entry->flags, "|", XLOG_TIC_FLAGS),
> @@ -1014,6 +1021,7 @@ DEFINE_LOGGRANT_EVENT(xfs_log_regrant_reserve_sub);
> DEFINE_LOGGRANT_EVENT(xfs_log_ungrant_enter);
> DEFINE_LOGGRANT_EVENT(xfs_log_ungrant_exit);
> DEFINE_LOGGRANT_EVENT(xfs_log_ungrant_sub);
> +DEFINE_LOGGRANT_EVENT(xfs_log_ungrant_spill);
>
> DECLARE_EVENT_CLASS(xfs_log_item_class,
> TP_PROTO(struct xfs_log_item *lip),
>
