gfs2: add more timing info to journal recovery process

Tells you how many milliseconds map_journal_extents and find_jhead
take.

Signed-off-by: Abhi Das <adas@redhat.com>
Signed-off-by: Bob Peterson <rpeterso@redhat.com>
Signed-off-by: Andreas Gruenbacher <agruenba@redhat.com>

diff --git a/fs/gfs2/bmap.c b/fs/gfs2/bmap.c
index 9a4a15d646ebb2f556828c410cb38c0bd1f30dd5..5292e10aaa8055e65dd72214491a8030882bd2f0 100644 (file)
--- 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 0f501f938d1cf526364663e9d89ccd980208d3fc..b0717a074543a710bee73a8b4ed4fd1d860fe878 100644 (file)
--- 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",