GFS2: Log the reason for log flushes in every log header

PATCH New Bob Peterson 1 participant 1 message Jan 8, 2018 1 message not in the archive GFS2 file system

lore

Share & tools

lore

A message that is not in the archive (sent off-list or not yet received): [email protected]

Bob Peterson

author

2018-01-08 15:34 UTC #1 lore raw

PATCH v2 1/1 GFS2: Log the reason for log flushes in every log header

Hi,

This is a newly revised version of my patch to track log flushes in the log header, which builds on my previous (log header v2) patch.

As suggested, it eliminates the enum and array in favor of defined flags. It also does away with the superblock variable, although we may want to reintroduce and enhance that at a later time.

Regards,

Bob
---
This patch just adds the capability for GFS2 to track which function called gfs2_log_flush. This should make it easier to diagnose problems based on the sequence of events found in the journals.

Signed-off-by Bob Peterson <[email protected]>

---
 fs/gfs2/aops.c                   |  3 ++-
 fs/gfs2/file.c                   |  3 ++-
 fs/gfs2/glops.c                  | 18 ++++++++++++------
 fs/gfs2/log.c                    | 14 ++++++++------
 fs/gfs2/ops_fstype.c             |  2 +-
 fs/gfs2/quota.c                  |  2 +-
 fs/gfs2/rgrp.c                   |  3 ++-
 fs/gfs2/super.c                  | 12 ++++++++----
 fs/gfs2/trace_gfs2.h             | 11 +++++++----
 fs/gfs2/trans.c                  |  3 ++-
 include/uapi/linux/gfs2_ondisk.h | 21 +++++++++++++++++++++
 11 files changed, 66 insertions(+), 26 deletions(-)

fs/gfs2/aops.c +2 -1

index 7c64925735d3..eb06f517004c 100644
@@ -445,7 +445,8 @@ static int gfs2_jdata_writepages(struct address_space *mapping,
 
 	ret = gfs2_write_cache_jdata(mapping, wbc);
 	if (ret == 0 && wbc->sync_mode == WB_SYNC_ALL) {
-		gfs2_log_flush(sdp, ip->i_gl, GFS2_LOG_HEAD_FLUSH_NORMAL);
+		gfs2_log_flush(sdp, ip->i_gl, GFS2_LOG_HEAD_FLUSH_NORMAL |
+			       GFS2_LFC_JDATA_WPAGES);
 		ret = gfs2_write_cache_jdata(mapping, wbc);
 	}
 	return ret;

fs/gfs2/file.c +2 -1

index 475c601ef4d8..8bec2976838d 100644
@@ -247,7 +247,8 @@ static int do_gfs2_set_flags(struct file *filp, u32 reqflags, u32 mask)
 	if ((flags ^ new_flags) & GFS2_DIF_JDATA) {
 		if (new_flags & GFS2_DIF_JDATA)
 			gfs2_log_flush(sdp, ip->i_gl,
-				       GFS2_LOG_HEAD_FLUSH_NORMAL);
+				       GFS2_LOG_HEAD_FLUSH_NORMAL |
+				       GFS2_LFC_SET_FLAGS);
 		error = filemap_fdatawrite(inode->i_mapping);
 		if (error)
 			goto out;

fs/gfs2/glops.c +12 -6

index 2daab13a9e0b..d8782a7a1e7d 100644
@@ -107,7 +107,8 @@ static void gfs2_ail_empty_gl(struct gfs2_glock *gl)
 	__gfs2_ail_flush(gl, 0, tr.tr_revokes);
 
 	gfs2_trans_end(sdp);
-	gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL);
+	gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL |
+		       GFS2_LFC_AIL_EMPTY_GL);
 }
 
 void gfs2_ail_flush(struct gfs2_glock *gl, bool fsync)

@@ -128,7 +129,8 @@ void gfs2_ail_flush(struct gfs2_glock *gl, bool fsync)
 		return;
 	__gfs2_ail_flush(gl, fsync, max_revokes);
 	gfs2_trans_end(sdp);
-	gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL);
+	gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL |
+		       GFS2_LFC_AIL_FLUSH);
 }
 
 /**

@@ -157,7 +159,8 @@ static void rgrp_go_sync(struct gfs2_glock *gl)
 		return;
 	GLOCK_BUG_ON(gl, gl->gl_state != LM_ST_EXCLUSIVE);
 
-	gfs2_log_flush(sdp, gl, GFS2_LOG_HEAD_FLUSH_NORMAL);
+	gfs2_log_flush(sdp, gl, GFS2_LOG_HEAD_FLUSH_NORMAL |
+		       GFS2_LFC_RGRP_GO_SYNC);
 	filemap_fdatawrite_range(mapping, gl->gl_vm.start, gl->gl_vm.end);
 	error = filemap_fdatawait_range(mapping, gl->gl_vm.start, gl->gl_vm.end);
 	mapping_set_error(mapping, error);

@@ -252,7 +255,8 @@ static void inode_go_sync(struct gfs2_glock *gl)
 
 	GLOCK_BUG_ON(gl, gl->gl_state != LM_ST_EXCLUSIVE);
 
-	gfs2_log_flush(gl->gl_name.ln_sbd, gl, GFS2_LOG_HEAD_FLUSH_NORMAL);
+	gfs2_log_flush(gl->gl_name.ln_sbd, gl, GFS2_LOG_HEAD_FLUSH_NORMAL |
+		       GFS2_LFC_INODE_GO_SYNC);
 	filemap_fdatawrite(metamapping);
 	if (isreg) {
 		struct address_space *mapping = ip->i_inode.i_mapping;

@@ -304,7 +308,8 @@ static void inode_go_inval(struct gfs2_glock *gl, int flags)
 
 	if (ip == GFS2_I(gl->gl_name.ln_sbd->sd_rindex)) {
 		gfs2_log_flush(gl->gl_name.ln_sbd, NULL,
-			       GFS2_LOG_HEAD_FLUSH_NORMAL);
+			       GFS2_LOG_HEAD_FLUSH_NORMAL |
+			       GFS2_LFC_INODE_GO_INVAL);
 		gl->gl_name.ln_sbd->sd_rindex_uptodate = 0;
 	}
 	if (ip && S_ISREG(ip->i_inode.i_mode))

@@ -496,7 +501,8 @@ static void freeze_go_sync(struct gfs2_glock *gl)
 			gfs2_assert_withdraw(sdp, 0);
 		}
 		queue_work(gfs2_freeze_wq, &sdp->sd_freeze_work);
-		gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_FREEZE);
+		gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_FREEZE |
+			       GFS2_LFC_FREEZE_GO_SYNC);
 	}
 }

fs/gfs2/log.c +8 -6

index e526cc6ad604..a871f0462e60 100644
@@ -747,7 +747,7 @@ static void log_write_header(struct gfs2_sbd *sdp, u32 flags)
  * gfs2_log_flush - flush incore transaction(s)
  * @sdp: the filesystem
  * @gl: The glock structure to flush.  If NULL, flush the whole incore log
- * @flags: The log header flags: GFS2_LOG_HEAD_FLUSH_*
+ * @flags: The log header flags: GFS2_LOG_HEAD_FLUSH_* and debug flags
  *
  */

@@ -763,7 +763,7 @@ void gfs2_log_flush(struct gfs2_sbd *sdp, struct gfs2_glock *gl, u32 flags)
 		up_write(&sdp->sd_log_flush_lock);
 		return;
 	}
-	trace_gfs2_log_flush(sdp, 1);
+	trace_gfs2_log_flush(sdp, 1, flags);
 
 	if (flags & GFS2_LOG_HEAD_FLUSH_SHUTDOWN)
 		clear_bit(SDF_JOURNAL_LIVE, &sdp->sd_flags);

@@ -831,7 +831,7 @@ void gfs2_log_flush(struct gfs2_sbd *sdp, struct gfs2_glock *gl, u32 flags)
 			atomic_set(&sdp->sd_freeze_state, SFS_FROZEN);
 	}
 
-	trace_gfs2_log_flush(sdp, 0);
+	trace_gfs2_log_flush(sdp, 0, flags);
 	up_write(&sdp->sd_log_flush_lock);
 
 	kfree(tr);

@@ -927,7 +927,7 @@ void gfs2_log_shutdown(struct gfs2_sbd *sdp)
 
 	sdp->sd_log_flush_head = sdp->sd_log_head;
 
-	log_write_header(sdp, GFS2_LOG_HEAD_UNMOUNT);
+	log_write_header(sdp, GFS2_LOG_HEAD_UNMOUNT | GFS2_LFC_SHUTDOWN);
 
 	gfs2_assert_warn(sdp, sdp->sd_log_head == sdp->sd_log_tail);
 	gfs2_assert_warn(sdp, list_empty(&sdp->sd_ail2_list));

@@ -983,7 +983,8 @@ int gfs2_logd(void *data)
 		did_flush = false;
 		if (gfs2_jrnl_flush_reqd(sdp) || t == 0) {
 			gfs2_ail1_empty(sdp);
-			gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL);
+			gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL |
+				       GFS2_LFC_LOGD_JFLUSH_REQD);
 			did_flush = true;
 		}

@@ -991,7 +992,8 @@ int gfs2_logd(void *data)
 			gfs2_ail1_start(sdp);
 			gfs2_ail1_wait(sdp);
 			gfs2_ail1_empty(sdp);
-			gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL);
+			gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL |
+				       GFS2_LFC_LOGD_AIL_FLUSH_REQD);
 			did_flush = true;
 		}

fs/gfs2/ops_fstype.c +1 -1

index d80c1e433f87..1b13d81427ca 100644
@@ -1382,7 +1382,7 @@ static void gfs2_kill_sb(struct super_block *sb)
 		return;
 	}
 
-	gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_SYNC);
+	gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_SYNC | GFS2_LFC_KILL_SB);
 	dput(sdp->sd_root_dir);
 	dput(sdp->sd_master_dir);
 	sdp->sd_root_dir = NULL;

fs/gfs2/quota.c +1 -1

index 2092df19e433..7a98abd340ee 100644
@@ -956,7 +956,7 @@ static int do_sync(unsigned int num_qd, struct gfs2_quota_data **qda)
 	inode_unlock(&ip->i_inode);
 	kfree(ghs);
 	gfs2_log_flush(ip->i_gl->gl_name.ln_sbd, ip->i_gl,
-		       GFS2_LOG_HEAD_FLUSH_NORMAL);
+		       GFS2_LOG_HEAD_FLUSH_NORMAL | GFS2_LFC_DO_SYNC);
 	return error;
 }

fs/gfs2/rgrp.c +2 -1

index 44879546613f..a0bd0b7d13dc 100644
@@ -2086,7 +2086,8 @@ int gfs2_inplace_reserve(struct gfs2_inode *ip, struct gfs2_alloc_parms *ap)
 		}
 		/* Flushing the log may release space */
 		if (loops == 2)
-			gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL);
+			gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL |
+				       GFS2_LFC_INPLACE_RESERVE);
 	}
 
 	return -ENOSPC;

fs/gfs2/super.c +8 -4

index d57d29c32523..6b2c30e3614a 100644
@@ -758,7 +758,8 @@ static int gfs2_write_inode(struct inode *inode, struct writeback_control *wbc)
 
 	if (flush_all)
 		gfs2_log_flush(GFS2_SB(inode), ip->i_gl,
-			       GFS2_LOG_HEAD_FLUSH_NORMAL);
+			       GFS2_LOG_HEAD_FLUSH_NORMAL |
+			       GFS2_LFC_WRITE_INODE);
 	if (bdi->wb.dirty_exceeded)
 		gfs2_ail1_flush(sdp, wbc);
 	else

@@ -854,7 +855,8 @@ static int gfs2_make_fs_ro(struct gfs2_sbd *sdp)
 	gfs2_quota_sync(sdp->sd_vfs, 0);
 	gfs2_statfs_sync(sdp->sd_vfs, 0);
 
-	gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_SHUTDOWN);
+	gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_SHUTDOWN |
+		       GFS2_LFC_MAKE_FS_RO);
 	wait_event(sdp->sd_reserving_log_wait, atomic_read(&sdp->sd_reserving_log) == 0);
 	gfs2_assert_warn(sdp, atomic_read(&sdp->sd_log_blks_free) == sdp->sd_jdesc->jd_blocks);

@@ -947,7 +949,8 @@ static int gfs2_sync_fs(struct super_block *sb, int wait)
 
 	gfs2_quota_sync(sb, -1);
 	if (wait)
-		gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL);
+		gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL |
+			       GFS2_LFC_SYNC_FS);
 	return sdp->sd_log_error;
 }

@@ -1651,7 +1654,8 @@ static void gfs2_evict_inode(struct inode *inode)
 	goto out_unlock;
 
 out_truncate:
-	gfs2_log_flush(sdp, ip->i_gl, GFS2_LOG_HEAD_FLUSH_NORMAL);
+	gfs2_log_flush(sdp, ip->i_gl, GFS2_LOG_HEAD_FLUSH_NORMAL |
+		       GFS2_LFC_EVICT_INODE);
 	metamapping = gfs2_glock2aspace(ip->i_gl);
 	if (test_bit(GLF_DIRTY, &ip->i_gl->gl_flags)) {
 		filemap_fdatawrite(metamapping);

fs/gfs2/trace_gfs2.h +7 -4

index f67a709589d3..b9318b49ff8f 100644
@@ -353,26 +353,29 @@ TRACE_EVENT(gfs2_pin,
 /* Flushing the log */
 TRACE_EVENT(gfs2_log_flush,
 
-	TP_PROTO(const struct gfs2_sbd *sdp, int start),
+	TP_PROTO(const struct gfs2_sbd *sdp, int start, u32 flags),
 
-	TP_ARGS(sdp, start),
+	TP_ARGS(sdp, start, flags),
 
 	TP_STRUCT__entry(
 		__field(        dev_t,  dev                     )
 		__field(	int,	start			)
 		__field(	u64,	log_seq			)
+		__field(	u32,	flags			)
 	),
 
 	TP_fast_assign(
 		__entry->dev            = sdp->sd_vfs->s_dev;
 		__entry->start		= start;
 		__entry->log_seq	= sdp->sd_log_sequence;
+		__entry->flags		= flags;
 	),
 
-	TP_printk("%u,%u log flush %s %llu",
+	TP_printk("%u,%u log flush %s %llu %llx",
 		  MAJOR(__entry->dev), MINOR(__entry->dev),
 		  __entry->start ? "start" : "end",
-		  (unsigned long long)__entry->log_seq)
+		  (unsigned long long)__entry->log_seq,
+		  (unsigned long long)__entry->flags)
 );
 
 /* Reserving/releasing blocks in the log */

fs/gfs2/trans.c +2 -1

index 5ab1bf69c788..73fb98534415 100644
@@ -118,7 +118,8 @@ void gfs2_trans_end(struct gfs2_sbd *sdp)
 	up_read(&sdp->sd_log_flush_lock);
 
 	if (sdp->sd_vfs->s_flags & MS_SYNCHRONOUS)
-		gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL);
+		gfs2_log_flush(sdp, NULL, GFS2_LOG_HEAD_FLUSH_NORMAL |
+			       GFS2_LFC_TRANS_END);
 	if (alloced)
 		sb_end_intwrite(sdp->sd_vfs);
 }

include/uapi/linux/gfs2_ondisk.h +21 -0

index 7eb73c32272f..04585f8e44bb 100644
@@ -411,6 +411,27 @@ struct gfs2_ea_header {
 #define GFS2_LOG_HEAD_RECOVERY		0x00000020 /* Journal recovery */
 #define GFS2_LOG_HEAD_USERSPACE		0x80000000 /* Written by gfs2-utils */
 
+/* Log flush callers */
+#define GFS2_LFC_SHUTDOWN		0x00000100
+#define GFS2_LFC_JDATA_WPAGES		0x00000200
+#define GFS2_LFC_SET_FLAGS		0x00000400
+#define GFS2_LFC_AIL_EMPTY_GL		0x00000800
+#define GFS2_LFC_AIL_FLUSH		0x00001000
+#define GFS2_LFC_RGRP_GO_SYNC		0x00002000
+#define GFS2_LFC_INODE_GO_SYNC		0x00004000
+#define GFS2_LFC_INODE_GO_INVAL		0x00008000
+#define GFS2_LFC_FREEZE_GO_SYNC		0x00010000
+#define GFS2_LFC_KILL_SB		0x00020000
+#define GFS2_LFC_DO_SYNC		0x00040000
+#define GFS2_LFC_INPLACE_RESERVE	0x00080000
+#define GFS2_LFC_WRITE_INODE		0x00100000
+#define GFS2_LFC_MAKE_FS_RO		0x00200000
+#define GFS2_LFC_SYNC_FS		0x00400000
+#define GFS2_LFC_EVICT_INODE		0x00800000
+#define GFS2_LFC_TRANS_END		0x01000000
+#define GFS2_LFC_LOGD_JFLUSH_REQD	0x02000000
+#define GFS2_LFC_LOGD_AIL_FLUSH_REQD	0x04000000
+
 #define LH_V1_SIZE (offsetofend(struct gfs2_log_header, lh_hash))
 
 struct gfs2_log_header {