[Cluster-devel] [GFS2 PATCH 1/4] gfs2: add more timing info to journal recovery process

[Andreas Gruenbacher]

On Tue, 16 Oct 2018 at 06:23, Abhi Das <adas at redhat.com> wrote:
>
> Tells you how many milliseconds map_journal_extents and find_jhead
> take.
>
> Signed-off-by: Abhi Das <adas at redhat.com>

Reviewed-by: Andreas Gruenbacher <agruenba at redhat.com>

Thanks,
Andreas

> ---
>  fs/gfs2/bmap.c     | 8 ++++++--
>  fs/gfs2/recovery.c | 2 ++
>  2 files changed, 8 insertions(+), 2 deletions(-)
>
> diff --git a/fs/gfs2/bmap.c b/fs/gfs2/bmap.c
> index 5f3ea07..aaf3682 100644
> --- a/fs/gfs2/bmap.c
> +++ b/fs/gfs2/bmap.c
> @@ -14,6 +14,7 @@
>  #include <linux/gfs2_ondisk.h>
>  #include <linux/crc32.h>
>  #include <linux/iomap.h>
> +#include <linux/ktime.h>
>
>  #include "gfs2.h"
>  #include "incore.h"
> @@ -2248,7 +2249,9 @@ int gfs2_map_journal_extents(struct gfs2_sbd *sdp, struct gfs2_jdesc *jd)
>         unsigned int shift = sdp->sd_sb.sb_bsize_shift;
>         u64 size;
>         int rc;
> +       ktime_t start, end;
>
> +       start = ktime_get();
>         lblock_stop = i_size_read(jd->jd_inode) >> shift;
>         size = (lblock_stop - lblock) << shift;
>         jd->nr_extents = 0;
> @@ -2268,8 +2271,9 @@ int gfs2_map_journal_extents(struct gfs2_sbd *sdp, struct gfs2_jdesc *jd)
>                 lblock += (bh.b_size >> ip->i_inode.i_blkbits);
>         } while(size > 0);
>
> -       fs_info(sdp, "journal %d mapped with %u extents\n", jd->jd_jid,
> -               jd->nr_extents);
> +       end = ktime_get();
> +       fs_info(sdp, "journal %d mapped with %u extents in %lldms\n", jd->jd_jid,
> +               jd->nr_extents, ktime_ms_delta(end, start));
>         return 0;
>
>  fail:
> diff --git a/fs/gfs2/recovery.c b/fs/gfs2/recovery.c
> index 0f501f9..b0717a0 100644
> --- a/fs/gfs2/recovery.c
> +++ b/fs/gfs2/recovery.c
> @@ -460,6 +460,8 @@ void gfs2_recover_func(struct work_struct *work)
>         if (error)
>                 goto fail_gunlock_ji;
>         t_jhd = ktime_get();
> +       fs_info(sdp, "jid=%u: Journal head lookup took %lldms\n", jd->jd_jid,
> +               ktime_ms_delta(t_jhd, t_jlck));
>
>         if (!(head.lh_flags & GFS2_LOG_HEAD_UNMOUNT)) {
>                 fs_info(sdp, "jid=%u: Acquiring the transaction lock...\n",
> --
> 2.4.11
>