[Cluster-devel] [GFS2 PATCH] GFS2: Log the reason for log flushes in every log header

[Cluster-devel] [GFS2 PATCH] GFS2: Log the reason for log flushes in every log header

[Bob Peterson]

Hi,

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 <rpeterso@redhat.com>
---
 fs/gfs2/aops.c       |  2 +-
 fs/gfs2/file.c       |  3 ++-
 fs/gfs2/glops.c      | 13 +++++++------
 fs/gfs2/incore.h     | 22 ++++++++++++++++++++++
 fs/gfs2/log.c        | 19 +++++++++++--------
 fs/gfs2/log.h        |  3 ++-
 fs/gfs2/ops_fstype.c |  2 +-
 fs/gfs2/quota.c      |  3 ++-
 fs/gfs2/rgrp.c       |  3 ++-
 fs/gfs2/super.c      |  9 +++++----
 fs/gfs2/trans.c      |  2 +-
 11 files changed, 56 insertions(+), 25 deletions(-)

diff --git a/fs/gfs2/aops.c b/fs/gfs2/aops.c
index 658ca027cab9..10fa52321a73 100644
--- a/fs/gfs2/aops.c
+++ b/fs/gfs2/aops.c
@@ -445,7 +445,7 @@ 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, NORMAL_FLUSH);
+		gfs2_log_flush(sdp, ip->i_gl, NORMAL_FLUSH, LGF_JDATA_WPAGES);
 		ret = gfs2_write_cache_jdata(mapping, wbc);
 	}
 	return ret;
diff --git a/fs/gfs2/file.c b/fs/gfs2/file.c
index 58705ef8643a..e180df15e107 100644
--- a/fs/gfs2/file.c
+++ b/fs/gfs2/file.c
@@ -246,7 +246,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, NORMAL_FLUSH);
+			gfs2_log_flush(sdp, ip->i_gl, NORMAL_FLUSH,
+				       LGF_SET_FLAGS);
 		error = filemap_fdatawrite(inode->i_mapping);
 		if (error)
 			goto out;
diff --git a/fs/gfs2/glops.c b/fs/gfs2/glops.c
index cdd1c5f06f45..f661fbec259c 100644
--- a/fs/gfs2/glops.c
+++ b/fs/gfs2/glops.c
@@ -107,7 +107,7 @@ 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, NORMAL_FLUSH);
+	gfs2_log_flush(sdp, NULL, NORMAL_FLUSH, LGF_AIL_EMPTY_GL);
 }
 
 void gfs2_ail_flush(struct gfs2_glock *gl, bool fsync)
@@ -128,7 +128,7 @@ 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, NORMAL_FLUSH);
+	gfs2_log_flush(sdp, NULL, NORMAL_FLUSH, LGF_AIL_FLUSH);
 }
 
 /**
@@ -157,7 +157,7 @@ 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, NORMAL_FLUSH);
+	gfs2_log_flush(sdp, gl, NORMAL_FLUSH, LGF_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 +252,7 @@ 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, NORMAL_FLUSH);
+	gfs2_log_flush(gl->gl_name.ln_sbd, gl, NORMAL_FLUSH, LGF_INODE_GO_SYNC);
 	filemap_fdatawrite(metamapping);
 	if (isreg) {
 		struct address_space *mapping = ip->i_inode.i_mapping;
@@ -303,7 +303,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, NORMAL_FLUSH);
+		gfs2_log_flush(gl->gl_name.ln_sbd, NULL, NORMAL_FLUSH,
+			       LGF_INODE_GO_INVAL);
 		gl->gl_name.ln_sbd->sd_rindex_uptodate = 0;
 	}
 	if (ip && S_ISREG(ip->i_inode.i_mode))
@@ -495,7 +496,7 @@ 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, FREEZE_FLUSH);
+		gfs2_log_flush(sdp, NULL, FREEZE_FLUSH, LGF_FREEZE_GO_SYNC);
 	}
 }
 
diff --git a/fs/gfs2/incore.h b/fs/gfs2/incore.h
index 6e18e9793ec4..1e07fa2468f9 100644
--- a/fs/gfs2/incore.h
+++ b/fs/gfs2/incore.h
@@ -134,6 +134,28 @@ enum gfs2_state_bits {
 	BH_Zeronew = BH_PrivateStart + 2,
 };
 
+enum gfs2_log_flushers {
+	LGF_SHUTDOWN		= 0x701,
+	LGF_JDATA_WPAGES	= 0x702,
+	LGF_SET_FLAGS		= 0x703,
+	LGF_AIL_EMPTY_GL	= 0x704,
+	LGF_AIL_FLUSH		= 0x705,
+	LGF_RGRP_GO_SYNC	= 0x706,
+	LGF_INODE_GO_SYNC	= 0x707,
+	LGF_INODE_GO_INVAL	= 0x708,
+	LGF_FREEZE_GO_SYNC	= 0x709,
+	LGF_KILL_SB		= 0x70a,
+	LGF_DO_SYNC		= 0x70b,
+	LGF_INPLACE_RESERVE	= 0x70c,
+	LGF_WRITE_INODE		= 0x70d,
+	LGF_MAKE_FS_RO		= 0x70e,
+	LGF_SYNC_FS		= 0x70f,
+	LGF_EVICT_INODE		= 0x710,
+	LGF_TRANS_END		= 0x711,
+	LGF_LOGD_JFLUSH_REQD	= 0x712,
+	LGF_LOGD_AIL_FLUSH_REQD	= 0x712,
+};
+
 BUFFER_FNS(Pinned, pinned)
 TAS_BUFFER_FNS(Pinned, pinned)
 BUFFER_FNS(Escaped, escaped)
diff --git a/fs/gfs2/log.c b/fs/gfs2/log.c
index 311e22ec6716..b62f866220ee 100644
--- a/fs/gfs2/log.c
+++ b/fs/gfs2/log.c
@@ -654,7 +654,7 @@ void gfs2_write_revokes(struct gfs2_sbd *sdp)
  * Returns: the initialized log buffer descriptor
  */
 
-static void log_write_header(struct gfs2_sbd *sdp, u32 flags)
+static void log_write_header(struct gfs2_sbd *sdp, u32 flags, u32 flusher)
 {
 	struct gfs2_log_header_v2 *lh2;
 	struct gfs2_log_header *lh;
@@ -692,6 +692,7 @@ static void log_write_header(struct gfs2_sbd *sdp, u32 flags)
 	lh2->lh_jinode = cpu_to_be64(GFS2_I(sdp->sd_jdesc->jd_inode)->i_no_addr);
 	lh2->lh_statfs_addr = cpu_to_be64(GFS2_I(sdp->sd_sc_inode)->i_no_addr);
 	lh2->lh_quota_addr = cpu_to_be64(GFS2_I(sdp->sd_qc_inode)->i_no_addr);
+	lh2->lh_log_flusher = cpu_to_be32(flusher);
 
 	spin_lock(&sdp->sd_statfs_spin);
 	lh2->lh_local_total = cpu_to_be64(l_sc->sc_total);
@@ -722,7 +723,7 @@ static void log_write_header(struct gfs2_sbd *sdp, u32 flags)
  */
 
 void gfs2_log_flush(struct gfs2_sbd *sdp, struct gfs2_glock *gl,
-		    enum gfs2_flush_type type)
+		    enum gfs2_flush_type type, enum gfs2_log_flushers lgf)
 {
 	struct gfs2_trans *tr;
 	enum gfs2_freeze_state state = atomic_read(&sdp->sd_freeze_state);
@@ -761,11 +762,11 @@ void gfs2_log_flush(struct gfs2_sbd *sdp, struct gfs2_glock *gl,
 
 	if (sdp->sd_log_head != sdp->sd_log_flush_head) {
 		log_flush_wait(sdp);
-		log_write_header(sdp, 0);
+		log_write_header(sdp, 0, lgf);
 	} else if (sdp->sd_log_tail != current_tail(sdp) && !sdp->sd_log_idle){
 		atomic_dec(&sdp->sd_log_blks_free); /* Adjust for unreserved buffer */
 		trace_gfs2_log_blocks(sdp, -1);
-		log_write_header(sdp, 0);
+		log_write_header(sdp, 0, lgf);
 	}
 	lops_after_commit(sdp, tr);
 
@@ -792,7 +793,7 @@ void gfs2_log_flush(struct gfs2_sbd *sdp, struct gfs2_glock *gl,
 			}
 			atomic_dec(&sdp->sd_log_blks_free); /* Adjust for unreserved buffer */
 			trace_gfs2_log_blocks(sdp, -1);
-			log_write_header(sdp, 0);
+			log_write_header(sdp, 0, lgf);
 			sdp->sd_log_head = sdp->sd_log_flush_head;
 		}
 		if (type == SHUTDOWN_FLUSH || type == FREEZE_FLUSH)
@@ -897,7 +898,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, LGF_SHUTDOWN);
 
 	gfs2_assert_warn(sdp, sdp->sd_log_head == sdp->sd_log_tail);
 	gfs2_assert_warn(sdp, list_empty(&sdp->sd_ail2_list));
@@ -953,7 +954,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, NORMAL_FLUSH);
+			gfs2_log_flush(sdp, NULL, NORMAL_FLUSH,
+				       LGF_LOGD_JFLUSH_REQD);
 			did_flush = true;
 		}
 
@@ -961,7 +963,8 @@ int gfs2_logd(void *data)
 			gfs2_ail1_start(sdp);
 			gfs2_ail1_wait(sdp);
 			gfs2_ail1_empty(sdp);
-			gfs2_log_flush(sdp, NULL, NORMAL_FLUSH);
+			gfs2_log_flush(sdp, NULL, NORMAL_FLUSH,
+				       LGF_LOGD_AIL_FLUSH_REQD);
 			did_flush = true;
 		}
 
diff --git a/fs/gfs2/log.h b/fs/gfs2/log.h
index 9499a6049212..32779b1e8fb5 100644
--- a/fs/gfs2/log.h
+++ b/fs/gfs2/log.h
@@ -72,7 +72,8 @@ enum gfs2_flush_type {
 	FREEZE_FLUSH
 };
 extern void gfs2_log_flush(struct gfs2_sbd *sdp, struct gfs2_glock *gl,
-			   enum gfs2_flush_type type);
+			   enum gfs2_flush_type type,
+			   enum gfs2_log_flushers lgf);
 extern void gfs2_log_commit(struct gfs2_sbd *sdp, struct gfs2_trans *trans);
 extern void gfs2_remove_from_ail(struct gfs2_bufdata *bd);
 extern void gfs2_ail1_flush(struct gfs2_sbd *sdp, struct writeback_control *wbc);
diff --git a/fs/gfs2/ops_fstype.c b/fs/gfs2/ops_fstype.c
index a3711f543405..d9795d2e54ea 100644
--- a/fs/gfs2/ops_fstype.c
+++ b/fs/gfs2/ops_fstype.c
@@ -1382,7 +1382,7 @@ static void gfs2_kill_sb(struct super_block *sb)
 		return;
 	}
 
-	gfs2_log_flush(sdp, NULL, SYNC_FLUSH);
+	gfs2_log_flush(sdp, NULL, SYNC_FLUSH, LGF_KILL_SB);
 	dput(sdp->sd_root_dir);
 	dput(sdp->sd_master_dir);
 	sdp->sd_root_dir = NULL;
diff --git a/fs/gfs2/quota.c b/fs/gfs2/quota.c
index e700fb162664..e70d9b0d848f 100644
--- a/fs/gfs2/quota.c
+++ b/fs/gfs2/quota.c
@@ -955,7 +955,8 @@ static int do_sync(unsigned int num_qd, struct gfs2_quota_data **qda)
 		gfs2_glock_dq_uninit(&ghs[qx]);
 	inode_unlock(&ip->i_inode);
 	kfree(ghs);
-	gfs2_log_flush(ip->i_gl->gl_name.ln_sbd, ip->i_gl, NORMAL_FLUSH);
+	gfs2_log_flush(ip->i_gl->gl_name.ln_sbd, ip->i_gl, NORMAL_FLUSH,
+		       LGF_DO_SYNC);
 	return error;
 }
 
diff --git a/fs/gfs2/rgrp.c b/fs/gfs2/rgrp.c
index b52c5c3ac445..a122181cee81 100644
--- a/fs/gfs2/rgrp.c
+++ b/fs/gfs2/rgrp.c
@@ -2072,7 +2072,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, NORMAL_FLUSH);
+			gfs2_log_flush(sdp, NULL, NORMAL_FLUSH,
+				       LGF_INPLACE_RESERVE);
 	}
 
 	return -ENOSPC;
diff --git a/fs/gfs2/super.c b/fs/gfs2/super.c
index 9cb5c9a97d69..d4af64d4551b 100644
--- a/fs/gfs2/super.c
+++ b/fs/gfs2/super.c
@@ -757,7 +757,8 @@ static int gfs2_write_inode(struct inode *inode, struct writeback_control *wbc)
 	bool flush_all = (wbc->sync_mode == WB_SYNC_ALL || gfs2_is_jdata(ip));
 
 	if (flush_all)
-		gfs2_log_flush(GFS2_SB(inode), ip->i_gl, NORMAL_FLUSH);
+		gfs2_log_flush(GFS2_SB(inode), ip->i_gl, NORMAL_FLUSH,
+			       LGF_WRITE_INODE);
 	if (bdi->wb.dirty_exceeded)
 		gfs2_ail1_flush(sdp, wbc);
 	else
@@ -853,7 +854,7 @@ 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, SHUTDOWN_FLUSH);
+	gfs2_log_flush(sdp, NULL, SHUTDOWN_FLUSH, LGF_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);
 
@@ -946,7 +947,7 @@ static int gfs2_sync_fs(struct super_block *sb, int wait)
 
 	gfs2_quota_sync(sb, -1);
 	if (wait)
-		gfs2_log_flush(sdp, NULL, NORMAL_FLUSH);
+		gfs2_log_flush(sdp, NULL, NORMAL_FLUSH, LGF_SYNC_FS);
 	return sdp->sd_log_error;
 }
 
@@ -1650,7 +1651,7 @@ static void gfs2_evict_inode(struct inode *inode)
 	goto out_unlock;
 
 out_truncate:
-	gfs2_log_flush(sdp, ip->i_gl, NORMAL_FLUSH);
+	gfs2_log_flush(sdp, ip->i_gl, NORMAL_FLUSH, LGF_EVICT_INODE);
 	metamapping = gfs2_glock2aspace(ip->i_gl);
 	if (test_bit(GLF_DIRTY, &ip->i_gl->gl_flags)) {
 		filemap_fdatawrite(metamapping);
diff --git a/fs/gfs2/trans.c b/fs/gfs2/trans.c
index a85ca8b2c9ba..1f06dd9e4ff4 100644
--- a/fs/gfs2/trans.c
+++ b/fs/gfs2/trans.c
@@ -118,7 +118,7 @@ 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, NORMAL_FLUSH);
+		gfs2_log_flush(sdp, NULL, NORMAL_FLUSH, LGF_TRANS_END);
 	if (alloced)
 		sb_end_intwrite(sdp->sd_vfs);
 }

[Cluster-devel] [GFS2 PATCH] GFS2: Log the reason for log flushes in every log header

[Steven Whitehouse]

Hi,


On 01/12/17 19:34, Bob Peterson wrote:
> Hi,
>
> 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 <rpeterso@redhat.com>
> ---
>   fs/gfs2/aops.c       |  2 +-
>   fs/gfs2/file.c       |  3 ++-
>   fs/gfs2/glops.c      | 13 +++++++------
>   fs/gfs2/incore.h     | 22 ++++++++++++++++++++++
>   fs/gfs2/log.c        | 19 +++++++++++--------
>   fs/gfs2/log.h        |  3 ++-
>   fs/gfs2/ops_fstype.c |  2 +-
>   fs/gfs2/quota.c      |  3 ++-
>   fs/gfs2/rgrp.c       |  3 ++-
>   fs/gfs2/super.c      |  9 +++++----
>   fs/gfs2/trans.c      |  2 +-
>   11 files changed, 56 insertions(+), 25 deletions(-)
>
> diff --git a/fs/gfs2/aops.c b/fs/gfs2/aops.c
> index 658ca027cab9..10fa52321a73 100644
> --- a/fs/gfs2/aops.c
> +++ b/fs/gfs2/aops.c
> @@ -445,7 +445,7 @@ 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, NORMAL_FLUSH);
> +		gfs2_log_flush(sdp, ip->i_gl, NORMAL_FLUSH, LGF_JDATA_WPAGES);
>   		ret = gfs2_write_cache_jdata(mapping, wbc);
>   	}
>   	return ret;
Since we already have a flags field for gfs2_log_flush, lets make these 
the same field to avoid having to send two sets of flags.

> diff --git a/fs/gfs2/file.c b/fs/gfs2/file.c
> index 58705ef8643a..e180df15e107 100644
> --- a/fs/gfs2/file.c
> +++ b/fs/gfs2/file.c
> @@ -246,7 +246,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, NORMAL_FLUSH);
> +			gfs2_log_flush(sdp, ip->i_gl, NORMAL_FLUSH,
> +				       LGF_SET_FLAGS);
>   		error = filemap_fdatawrite(inode->i_mapping);
>   		if (error)
>   			goto out;
> diff --git a/fs/gfs2/glops.c b/fs/gfs2/glops.c
> index cdd1c5f06f45..f661fbec259c 100644
> --- a/fs/gfs2/glops.c
> +++ b/fs/gfs2/glops.c
> @@ -107,7 +107,7 @@ 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, NORMAL_FLUSH);
> +	gfs2_log_flush(sdp, NULL, NORMAL_FLUSH, LGF_AIL_EMPTY_GL);
>   }
>   
>   void gfs2_ail_flush(struct gfs2_glock *gl, bool fsync)
> @@ -128,7 +128,7 @@ 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, NORMAL_FLUSH);
> +	gfs2_log_flush(sdp, NULL, NORMAL_FLUSH, LGF_AIL_FLUSH);
>   }
>   
>   /**
> @@ -157,7 +157,7 @@ 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, NORMAL_FLUSH);
> +	gfs2_log_flush(sdp, gl, NORMAL_FLUSH, LGF_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 +252,7 @@ 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, NORMAL_FLUSH);
> +	gfs2_log_flush(gl->gl_name.ln_sbd, gl, NORMAL_FLUSH, LGF_INODE_GO_SYNC);
>   	filemap_fdatawrite(metamapping);
>   	if (isreg) {
>   		struct address_space *mapping = ip->i_inode.i_mapping;
> @@ -303,7 +303,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, NORMAL_FLUSH);
> +		gfs2_log_flush(gl->gl_name.ln_sbd, NULL, NORMAL_FLUSH,
> +			       LGF_INODE_GO_INVAL);
>   		gl->gl_name.ln_sbd->sd_rindex_uptodate = 0;
>   	}
>   	if (ip && S_ISREG(ip->i_inode.i_mode))
> @@ -495,7 +496,7 @@ 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, FREEZE_FLUSH);
> +		gfs2_log_flush(sdp, NULL, FREEZE_FLUSH, LGF_FREEZE_GO_SYNC);
>   	}
>   }
>   
> diff --git a/fs/gfs2/incore.h b/fs/gfs2/incore.h
> index 6e18e9793ec4..1e07fa2468f9 100644
> --- a/fs/gfs2/incore.h
> +++ b/fs/gfs2/incore.h
> @@ -134,6 +134,28 @@ enum gfs2_state_bits {
>   	BH_Zeronew = BH_PrivateStart + 2,
>   };
>   
> +enum gfs2_log_flushers {
> +	LGF_SHUTDOWN		= 0x701,
> +	LGF_JDATA_WPAGES	= 0x702,
> +	LGF_SET_FLAGS		= 0x703,
> +	LGF_AIL_EMPTY_GL	= 0x704,
> +	LGF_AIL_FLUSH		= 0x705,
> +	LGF_RGRP_GO_SYNC	= 0x706,
> +	LGF_INODE_GO_SYNC	= 0x707,
> +	LGF_INODE_GO_INVAL	= 0x708,
> +	LGF_FREEZE_GO_SYNC	= 0x709,
> +	LGF_KILL_SB		= 0x70a,
> +	LGF_DO_SYNC		= 0x70b,
> +	LGF_INPLACE_RESERVE	= 0x70c,
> +	LGF_WRITE_INODE		= 0x70d,
> +	LGF_MAKE_FS_RO		= 0x70e,
> +	LGF_SYNC_FS		= 0x70f,
> +	LGF_EVICT_INODE		= 0x710,
> +	LGF_TRANS_END		= 0x711,
> +	LGF_LOGD_JFLUSH_REQD	= 0x712,
> +	LGF_LOGD_AIL_FLUSH_REQD	= 0x712,
> +};
> +
These constants are written to disk, so they need to be in the ondisk 
header file in order that the utils can access them.

Steve.

[Cluster-devel] [GFS2 PATCH] GFS2: Log the reason for log flushes in every log header

[Bob Peterson]

Hi,

This is a version 2 replacement for this patch, with some improvements.
---
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 <rpeterso@redhat.com>
---
 fs/gfs2/aops.c                   |  2 +-
 fs/gfs2/file.c                   |  2 +-
 fs/gfs2/glops.c                  | 12 ++++----
 fs/gfs2/incore.h                 |  1 +
 fs/gfs2/log.c                    | 61 +++++++++++++++++++++++++++++++++-------
 fs/gfs2/log.h                    |  8 +-----
 fs/gfs2/ops_fstype.c             |  2 +-
 fs/gfs2/quota.c                  |  2 +-
 fs/gfs2/rgrp.c                   |  2 +-
 fs/gfs2/super.c                  |  8 +++---
 fs/gfs2/trace_gfs2.h             | 11 +++++---
 fs/gfs2/trans.c                  |  2 +-
 include/uapi/linux/gfs2_ondisk.h | 36 ++++++++++++++++++++++++
 13 files changed, 112 insertions(+), 37 deletions(-)

diff --git a/fs/gfs2/aops.c b/fs/gfs2/aops.c
index 658ca027cab9..4ef09ad463d4 100644
--- a/fs/gfs2/aops.c
+++ b/fs/gfs2/aops.c
@@ -445,7 +445,7 @@ 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, NORMAL_FLUSH);
+		gfs2_log_flush(sdp, ip->i_gl, LHF_JDATA_WPAGES);
 		ret = gfs2_write_cache_jdata(mapping, wbc);
 	}
 	return ret;
diff --git a/fs/gfs2/file.c b/fs/gfs2/file.c
index 58705ef8643a..68fee09efdf2 100644
--- a/fs/gfs2/file.c
+++ b/fs/gfs2/file.c
@@ -246,7 +246,7 @@ 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, NORMAL_FLUSH);
+			gfs2_log_flush(sdp, ip->i_gl, LHF_SET_FLAGS);
 		error = filemap_fdatawrite(inode->i_mapping);
 		if (error)
 			goto out;
diff --git a/fs/gfs2/glops.c b/fs/gfs2/glops.c
index cdd1c5f06f45..1e95c0bdbc3b 100644
--- a/fs/gfs2/glops.c
+++ b/fs/gfs2/glops.c
@@ -107,7 +107,7 @@ 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, NORMAL_FLUSH);
+	gfs2_log_flush(sdp, NULL, LHF_AIL_EMPTY_GL);
 }
 
 void gfs2_ail_flush(struct gfs2_glock *gl, bool fsync)
@@ -128,7 +128,7 @@ 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, NORMAL_FLUSH);
+	gfs2_log_flush(sdp, NULL, LHF_AIL_FLUSH);
 }
 
 /**
@@ -157,7 +157,7 @@ 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, NORMAL_FLUSH);
+	gfs2_log_flush(sdp, gl, LHF_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 +252,7 @@ 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, NORMAL_FLUSH);
+	gfs2_log_flush(gl->gl_name.ln_sbd, gl, LHF_INODE_GO_SYNC);
 	filemap_fdatawrite(metamapping);
 	if (isreg) {
 		struct address_space *mapping = ip->i_inode.i_mapping;
@@ -303,7 +303,7 @@ 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, NORMAL_FLUSH);
+		gfs2_log_flush(gl->gl_name.ln_sbd, NULL, LHF_INODE_GO_INVAL);
 		gl->gl_name.ln_sbd->sd_rindex_uptodate = 0;
 	}
 	if (ip && S_ISREG(ip->i_inode.i_mode))
@@ -495,7 +495,7 @@ 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, FREEZE_FLUSH);
+		gfs2_log_flush(sdp, NULL, LHF_FREEZE_GO_SYNC);
 	}
 }
 
diff --git a/fs/gfs2/incore.h b/fs/gfs2/incore.h
index 6e18e9793ec4..4a45c2590b1b 100644
--- a/fs/gfs2/incore.h
+++ b/fs/gfs2/incore.h
@@ -844,6 +844,7 @@ struct gfs2_sbd {
 	struct dentry *debugfs_dentry_glocks;
 	struct dentry *debugfs_dentry_glstats;
 	struct dentry *debugfs_dentry_sbstats;
+	unsigned long sd_log_flushers;
 };
 
 static inline void gfs2_glstats_inc(struct gfs2_glock *gl, int which)
diff --git a/fs/gfs2/log.c b/fs/gfs2/log.c
index 508b6edefab7..b64b15c0f1eb 100644
--- a/fs/gfs2/log.c
+++ b/fs/gfs2/log.c
@@ -33,6 +33,35 @@
 #include "dir.h"
 #include "trace_gfs2.h"
 
+enum gfs2_flush_type {
+	NORMAL_FLUSH = 0,
+	SYNC_FLUSH,
+	SHUTDOWN_FLUSH,
+	FREEZE_FLUSH
+};
+
+static const enum gfs2_flush_type log_flush_types[LHF_LOG_FLUSHERS] = {
+	NORMAL_FLUSH,		/* LHF_SHUTDOWN */
+	NORMAL_FLUSH,		/* LHF_JDATA_WPAGES */
+	NORMAL_FLUSH,		/* LHF_SET_FLAGS */
+	NORMAL_FLUSH,		/* LHF_AIL_EMPTY_GL */
+	NORMAL_FLUSH,		/* LHF_AIL_FLUSH */
+	NORMAL_FLUSH,		/* LHF_RGRP_GO_SYNC */
+	NORMAL_FLUSH,		/* LHF_INODE_GO_SYNC */
+	NORMAL_FLUSH,		/* LHF_INODE_GO_INVAL */
+	FREEZE_FLUSH,		/* LHF_FREEZE_GO_SYNC */
+	SYNC_FLUSH,		/* LHF_KILL_SB */
+	NORMAL_FLUSH,		/* LHF_DO_SYNC */
+	NORMAL_FLUSH,		/* LHF_INPLACE_RESERVE */
+	NORMAL_FLUSH,		/* LHF_WRITE_INODE */
+	SHUTDOWN_FLUSH,		/* LHF_MAKE_FS_RO */
+	NORMAL_FLUSH,		/* LHF_SYNC_FS */
+	NORMAL_FLUSH,		/* LHF_EVICT_INODE */
+	NORMAL_FLUSH,		/* LHF_TRANS_END */
+	NORMAL_FLUSH,		/* LHF_LOGD_JFLUSH_REQD */
+	NORMAL_FLUSH,		/* LHF_LOGD_AIL_FLUSH_REQD */
+};
+
 /**
  * gfs2_struct2blk - compute stuff
  * @sdp: the filesystem
@@ -654,7 +683,8 @@ void gfs2_write_revokes(struct gfs2_sbd *sdp)
  * Returns: the initialized log buffer descriptor
  */
 
-static void log_write_header(struct gfs2_sbd *sdp, u32 flags)
+static void log_write_header(struct gfs2_sbd *sdp,
+			     enum gfs2_log_flushers flusher)
 {
 	struct gfs2_log_header_v2 *lh2;
 	struct gfs2_log_header *lh;
@@ -665,6 +695,14 @@ static void log_write_header(struct gfs2_sbd *sdp, u32 flags)
 	enum gfs2_freeze_state state = atomic_read(&sdp->sd_freeze_state);
 	struct gfs2_statfs_change_host *l_sc = &sdp->sd_statfs_local;
 	struct timespec64 tv;
+	u32 flags = (flusher == LHF_SHUTDOWN) ? GFS2_LOG_HEAD_UNMOUNT : 0;
+
+	BUG_ON(flusher >= LHF_LOG_FLUSHERS);
+	/* Although not necessary, we funnel the flusher passed to this func
+	   through a common superblock variable in sdp. That way, if we have
+	   competing calls to this function, we ought to see multiple bits
+	   set in the resulting LH, and maybe in multiple LH blocks. */
+	set_bit(flusher, &sdp->sd_log_flushers);
 
 	lh2 = page_address(page);
 	clear_page(lh2);
@@ -692,6 +730,8 @@ static void log_write_header(struct gfs2_sbd *sdp, u32 flags)
 	lh2->lh_jinode = cpu_to_be64(GFS2_I(sdp->sd_jdesc->jd_inode)->i_no_addr);
 	lh2->lh_statfs_addr = cpu_to_be64(GFS2_I(sdp->sd_sc_inode)->i_no_addr);
 	lh2->lh_quota_addr = cpu_to_be64(GFS2_I(sdp->sd_qc_inode)->i_no_addr);
+	lh2->lh_log_flushers = cpu_to_be32(sdp->sd_log_flushers);
+	sdp->sd_log_flushers = 0;
 
 	spin_lock(&sdp->sd_statfs_spin);
 	lh2->lh_local_total = cpu_to_be64(l_sc->sc_total);
@@ -724,10 +764,11 @@ static void log_write_header(struct gfs2_sbd *sdp, u32 flags)
  */
 
 void gfs2_log_flush(struct gfs2_sbd *sdp, struct gfs2_glock *gl,
-		    enum gfs2_flush_type type)
+		    enum gfs2_log_flushers flusher)
 {
 	struct gfs2_trans *tr;
 	enum gfs2_freeze_state state = atomic_read(&sdp->sd_freeze_state);
+	u32 type = log_flush_types[flusher];
 
 	down_write(&sdp->sd_log_flush_lock);
 
@@ -736,7 +777,7 @@ void gfs2_log_flush(struct gfs2_sbd *sdp, struct gfs2_glock *gl,
 		up_write(&sdp->sd_log_flush_lock);
 		return;
 	}
-	trace_gfs2_log_flush(sdp, 1);
+	trace_gfs2_log_flush(sdp, 1, flusher);
 
 	if (type == SHUTDOWN_FLUSH)
 		clear_bit(SDF_JOURNAL_LIVE, &sdp->sd_flags);
@@ -763,11 +804,11 @@ void gfs2_log_flush(struct gfs2_sbd *sdp, struct gfs2_glock *gl,
 
 	if (sdp->sd_log_head != sdp->sd_log_flush_head) {
 		log_flush_wait(sdp);
-		log_write_header(sdp, 0);
+		log_write_header(sdp, flusher);
 	} else if (sdp->sd_log_tail != current_tail(sdp) && !sdp->sd_log_idle){
 		atomic_dec(&sdp->sd_log_blks_free); /* Adjust for unreserved buffer */
 		trace_gfs2_log_blocks(sdp, -1);
-		log_write_header(sdp, 0);
+		log_write_header(sdp, flusher);
 	}
 	lops_after_commit(sdp, tr);
 
@@ -794,7 +835,7 @@ void gfs2_log_flush(struct gfs2_sbd *sdp, struct gfs2_glock *gl,
 			}
 			atomic_dec(&sdp->sd_log_blks_free); /* Adjust for unreserved buffer */
 			trace_gfs2_log_blocks(sdp, -1);
-			log_write_header(sdp, 0);
+			log_write_header(sdp, flusher);
 			sdp->sd_log_head = sdp->sd_log_flush_head;
 		}
 		if (type == SHUTDOWN_FLUSH || type == FREEZE_FLUSH)
@@ -803,7 +844,7 @@ void gfs2_log_flush(struct gfs2_sbd *sdp, struct gfs2_glock *gl,
 			atomic_set(&sdp->sd_freeze_state, SFS_FROZEN);
 	}
 
-	trace_gfs2_log_flush(sdp, 0);
+	trace_gfs2_log_flush(sdp, 0, flusher);
 	up_write(&sdp->sd_log_flush_lock);
 
 	kfree(tr);
@@ -899,7 +940,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, LHF_SHUTDOWN);
 
 	gfs2_assert_warn(sdp, sdp->sd_log_head == sdp->sd_log_tail);
 	gfs2_assert_warn(sdp, list_empty(&sdp->sd_ail2_list));
@@ -955,7 +996,7 @@ 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, NORMAL_FLUSH);
+			gfs2_log_flush(sdp, NULL, LHF_LOGD_JFLUSH_REQD);
 			did_flush = true;
 		}
 
@@ -963,7 +1004,7 @@ int gfs2_logd(void *data)
 			gfs2_ail1_start(sdp);
 			gfs2_ail1_wait(sdp);
 			gfs2_ail1_empty(sdp);
-			gfs2_log_flush(sdp, NULL, NORMAL_FLUSH);
+			gfs2_log_flush(sdp, NULL, LHF_LOGD_AIL_FLUSH_REQD);
 			did_flush = true;
 		}
 
diff --git a/fs/gfs2/log.h b/fs/gfs2/log.h
index 9499a6049212..aad2b2c69d54 100644
--- a/fs/gfs2/log.h
+++ b/fs/gfs2/log.h
@@ -65,14 +65,8 @@ extern unsigned int gfs2_struct2blk(struct gfs2_sbd *sdp, unsigned int nstruct,
 
 extern void gfs2_log_release(struct gfs2_sbd *sdp, unsigned int blks);
 extern int gfs2_log_reserve(struct gfs2_sbd *sdp, unsigned int blks);
-enum gfs2_flush_type {
-	NORMAL_FLUSH = 0,
-	SYNC_FLUSH,
-	SHUTDOWN_FLUSH,
-	FREEZE_FLUSH
-};
 extern void gfs2_log_flush(struct gfs2_sbd *sdp, struct gfs2_glock *gl,
-			   enum gfs2_flush_type type);
+			   enum gfs2_log_flushers flusher);
 extern void gfs2_log_commit(struct gfs2_sbd *sdp, struct gfs2_trans *trans);
 extern void gfs2_remove_from_ail(struct gfs2_bufdata *bd);
 extern void gfs2_ail1_flush(struct gfs2_sbd *sdp, struct writeback_control *wbc);
diff --git a/fs/gfs2/ops_fstype.c b/fs/gfs2/ops_fstype.c
index a3711f543405..b53cf3e111e1 100644
--- a/fs/gfs2/ops_fstype.c
+++ b/fs/gfs2/ops_fstype.c
@@ -1382,7 +1382,7 @@ static void gfs2_kill_sb(struct super_block *sb)
 		return;
 	}
 
-	gfs2_log_flush(sdp, NULL, SYNC_FLUSH);
+	gfs2_log_flush(sdp, NULL, LHF_KILL_SB);
 	dput(sdp->sd_root_dir);
 	dput(sdp->sd_master_dir);
 	sdp->sd_root_dir = NULL;
diff --git a/fs/gfs2/quota.c b/fs/gfs2/quota.c
index e700fb162664..a90ccd8855aa 100644
--- a/fs/gfs2/quota.c
+++ b/fs/gfs2/quota.c
@@ -955,7 +955,7 @@ static int do_sync(unsigned int num_qd, struct gfs2_quota_data **qda)
 		gfs2_glock_dq_uninit(&ghs[qx]);
 	inode_unlock(&ip->i_inode);
 	kfree(ghs);
-	gfs2_log_flush(ip->i_gl->gl_name.ln_sbd, ip->i_gl, NORMAL_FLUSH);
+	gfs2_log_flush(ip->i_gl->gl_name.ln_sbd, ip->i_gl, LHF_DO_SYNC);
 	return error;
 }
 
diff --git a/fs/gfs2/rgrp.c b/fs/gfs2/rgrp.c
index b52c5c3ac445..f9b00836ce1a 100644
--- a/fs/gfs2/rgrp.c
+++ b/fs/gfs2/rgrp.c
@@ -2072,7 +2072,7 @@ 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, NORMAL_FLUSH);
+			gfs2_log_flush(sdp, NULL, LHF_INPLACE_RESERVE);
 	}
 
 	return -ENOSPC;
diff --git a/fs/gfs2/super.c b/fs/gfs2/super.c
index 9cb5c9a97d69..5bf53ac15ab3 100644
--- a/fs/gfs2/super.c
+++ b/fs/gfs2/super.c
@@ -757,7 +757,7 @@ static int gfs2_write_inode(struct inode *inode, struct writeback_control *wbc)
 	bool flush_all = (wbc->sync_mode == WB_SYNC_ALL || gfs2_is_jdata(ip));
 
 	if (flush_all)
-		gfs2_log_flush(GFS2_SB(inode), ip->i_gl, NORMAL_FLUSH);
+		gfs2_log_flush(GFS2_SB(inode), ip->i_gl, LHF_WRITE_INODE);
 	if (bdi->wb.dirty_exceeded)
 		gfs2_ail1_flush(sdp, wbc);
 	else
@@ -853,7 +853,7 @@ 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, SHUTDOWN_FLUSH);
+	gfs2_log_flush(sdp, NULL, LHF_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);
 
@@ -946,7 +946,7 @@ static int gfs2_sync_fs(struct super_block *sb, int wait)
 
 	gfs2_quota_sync(sb, -1);
 	if (wait)
-		gfs2_log_flush(sdp, NULL, NORMAL_FLUSH);
+		gfs2_log_flush(sdp, NULL, LHF_SYNC_FS);
 	return sdp->sd_log_error;
 }
 
@@ -1650,7 +1650,7 @@ static void gfs2_evict_inode(struct inode *inode)
 	goto out_unlock;
 
 out_truncate:
-	gfs2_log_flush(sdp, ip->i_gl, NORMAL_FLUSH);
+	gfs2_log_flush(sdp, ip->i_gl, LHF_EVICT_INODE);
 	metamapping = gfs2_glock2aspace(ip->i_gl);
 	if (test_bit(GLF_DIRTY, &ip->i_gl->gl_flags)) {
 		filemap_fdatawrite(metamapping);
diff --git a/fs/gfs2/trace_gfs2.h b/fs/gfs2/trace_gfs2.h
index f67a709589d3..62ada4847250 100644
--- a/fs/gfs2/trace_gfs2.h
+++ b/fs/gfs2/trace_gfs2.h
@@ -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 flusher),
 
-	TP_ARGS(sdp, start),
+	TP_ARGS(sdp, start, flusher),
 
 	TP_STRUCT__entry(
 		__field(        dev_t,  dev                     )
 		__field(	int,	start			)
 		__field(	u64,	log_seq			)
+		__field(	u32,	flusher			)
 	),
 
 	TP_fast_assign(
 		__entry->dev            = sdp->sd_vfs->s_dev;
 		__entry->start		= start;
 		__entry->log_seq	= sdp->sd_log_sequence;
+		__entry->flusher	= flusher;
 	),
 
-	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->flusher)
 );
 
 /* Reserving/releasing blocks in the log */
diff --git a/fs/gfs2/trans.c b/fs/gfs2/trans.c
index a85ca8b2c9ba..9842778e32d1 100644
--- a/fs/gfs2/trans.c
+++ b/fs/gfs2/trans.c
@@ -118,7 +118,7 @@ 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, NORMAL_FLUSH);
+		gfs2_log_flush(sdp, NULL, LHF_TRANS_END);
 	if (alloced)
 		sb_end_intwrite(sdp->sd_vfs);
 }
diff --git a/include/uapi/linux/gfs2_ondisk.h b/include/uapi/linux/gfs2_ondisk.h
index 96d9676ac354..cf867896436d 100644
--- a/include/uapi/linux/gfs2_ondisk.h
+++ b/include/uapi/linux/gfs2_ondisk.h
@@ -406,6 +406,42 @@ struct gfs2_log_header {
 	__be32 lh_hash;
 };
 
+/*
+ * Log Header version 2 constants - actor who wrote a log header
+ */
+
+enum gfs2_log_flushers {
+	/* Constants reserved for kernel space */
+	LHF_SHUTDOWN		= 0,
+	LHF_JDATA_WPAGES	= 1,
+	LHF_SET_FLAGS		= 2,
+	LHF_AIL_EMPTY_GL	= 3,
+	LHF_AIL_FLUSH		= 4,
+	LHF_RGRP_GO_SYNC	= 5,
+	LHF_INODE_GO_SYNC	= 6,
+	LHF_INODE_GO_INVAL	= 7,
+	LHF_FREEZE_GO_SYNC	= 8,
+	LHF_KILL_SB		= 9,
+	LHF_DO_SYNC		= 10,
+	LHF_INPLACE_RESERVE	= 11,
+	LHF_WRITE_INODE		= 12,
+	LHF_MAKE_FS_RO		= 13,
+	LHF_SYNC_FS		= 14,
+	LHF_EVICT_INODE		= 15,
+	LHF_TRANS_END		= 16,
+	LHF_LOGD_JFLUSH_REQD	= 17,
+	LHF_LOGD_AIL_FLUSH_REQD	= 18,
+	LHF_LOG_FLUSHERS	= 19, /* number of kernel log flushers */
+
+	/* Constants reserved for user space / gfs2-utils */
+	LHF_GFS2_CONVERT       	= 26,
+	LHF_GFS2_EDIT		= 27,
+	LHF_GFS2_FSCK		= 28,
+	LHF_GFS2_FSCK_JREPLAY	= 29,
+	LHF_GFS2_MKFS		= 30,
+	LHF_GFS2_JADD		= 31
+};
+
 struct gfs2_log_header_v2 {
 	struct gfs2_log_header lhv1;
 

[Cluster-devel] [GFS2 PATCH] GFS2: Log the reason for log flushes in every log header

[Andrew Price]

On 08/12/17 15:30, Bob Peterson wrote:
> Hi,
> 
> This is a version 2 replacement for this patch, with some improvements.
> ---
> 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 <rpeterso@redhat.com>
<snip>
> --- a/include/uapi/linux/gfs2_ondisk.h
> +++ b/include/uapi/linux/gfs2_ondisk.h
> @@ -406,6 +406,42 @@ struct gfs2_log_header {
>   	__be32 lh_hash;
>   };
>   
> +/*
> + * Log Header version 2 constants - actor who wrote a log header
> + */
> +
> +enum gfs2_log_flushers {
> +	/* Constants reserved for kernel space */
> +	LHF_SHUTDOWN		= 0,

Should 0 be used for "unknown"?

> +	LHF_JDATA_WPAGES	= 1,
> +	LHF_SET_FLAGS		= 2,
> +	LHF_AIL_EMPTY_GL	= 3,
> +	LHF_AIL_FLUSH		= 4,
> +	LHF_RGRP_GO_SYNC	= 5,
> +	LHF_INODE_GO_SYNC	= 6,
> +	LHF_INODE_GO_INVAL	= 7,
> +	LHF_FREEZE_GO_SYNC	= 8,
> +	LHF_KILL_SB		= 9,
> +	LHF_DO_SYNC		= 10,
> +	LHF_INPLACE_RESERVE	= 11,
> +	LHF_WRITE_INODE		= 12,
> +	LHF_MAKE_FS_RO		= 13,
> +	LHF_SYNC_FS		= 14,
> +	LHF_EVICT_INODE		= 15,
> +	LHF_TRANS_END		= 16,
> +	LHF_LOGD_JFLUSH_REQD	= 17,
> +	LHF_LOGD_AIL_FLUSH_REQD	= 18,
> +	LHF_LOG_FLUSHERS	= 19, /* number of kernel log flushers */
> +
> +	/* Constants reserved for user space / gfs2-utils */
> +	LHF_GFS2_CONVERT       	= 26,
> +	LHF_GFS2_EDIT		= 27,
> +	LHF_GFS2_FSCK		= 28,
> +	LHF_GFS2_FSCK_JREPLAY	= 29,
> +	LHF_GFS2_MKFS		= 30,
> +	LHF_GFS2_JADD		= 31

Would it be better to have values for the purposes that the utils would 
need to touch the log header, e.g. LHF_UTIL_REPLAY, LHF_UTIL_FIX or 
LHF_UTIL_CREATE. That way, if a util is renamed or a new util is written 
(even some third party tool that we don't know about) they would still 
have a sensible value to use.

Cheers,
Andy

[Cluster-devel] [GFS2 PATCH] GFS2: Log the reason for log flushes in every log header

[Steven Whitehouse]

Hi,


On 11/12/17 11:53, Andrew Price wrote:
> On 08/12/17 15:30, Bob Peterson wrote:
>> Hi,
>>
>> This is a version 2 replacement for this patch, with some improvements.
>> ---
>> 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 <rpeterso@redhat.com>
> <snip>
>> --- a/include/uapi/linux/gfs2_ondisk.h
>> +++ b/include/uapi/linux/gfs2_ondisk.h
>> @@ -406,6 +406,42 @@ struct gfs2_log_header {
>> ????? __be32 lh_hash;
>> ? };
>> ? +/*
>> + * Log Header version 2 constants - actor who wrote a log header
>> + */
>> +
>> +enum gfs2_log_flushers {
>> +??? /* Constants reserved for kernel space */
>> +??? LHF_SHUTDOWN??????? = 0,
>
> Should 0 be used for "unknown"?
>
Yes
>> +??? LHF_JDATA_WPAGES??? = 1,
>> +??? LHF_SET_FLAGS??????? = 2,
>> +??? LHF_AIL_EMPTY_GL??? = 3,
>> +??? LHF_AIL_FLUSH??????? = 4,
>> +??? LHF_RGRP_GO_SYNC??? = 5,
>> +??? LHF_INODE_GO_SYNC??? = 6,
>> +??? LHF_INODE_GO_INVAL??? = 7,
>> +??? LHF_FREEZE_GO_SYNC??? = 8,
>> +??? LHF_KILL_SB??????? = 9,
>> +??? LHF_DO_SYNC??????? = 10,
>> +??? LHF_INPLACE_RESERVE??? = 11,
>> +??? LHF_WRITE_INODE??????? = 12,
>> +??? LHF_MAKE_FS_RO??????? = 13,
>> +??? LHF_SYNC_FS??????? = 14,
>> +??? LHF_EVICT_INODE??????? = 15,
>> +??? LHF_TRANS_END??????? = 16,
>> +??? LHF_LOGD_JFLUSH_REQD??? = 17,
>> +??? LHF_LOGD_AIL_FLUSH_REQD??? = 18,
>> +??? LHF_LOG_FLUSHERS??? = 19, /* number of kernel log flushers */
>> +
>> +??? /* Constants reserved for user space / gfs2-utils */
>> +??? LHF_GFS2_CONVERT?????????? = 26,
>> +??? LHF_GFS2_EDIT??????? = 27,
>> +??? LHF_GFS2_FSCK??????? = 28,
>> +??? LHF_GFS2_FSCK_JREPLAY??? = 29,
>> +??? LHF_GFS2_MKFS??????? = 30,
>> +??? LHF_GFS2_JADD??????? = 31
>
> Would it be better to have values for the purposes that the utils 
> would need to touch the log header, e.g. LHF_UTIL_REPLAY, LHF_UTIL_FIX 
> or LHF_UTIL_CREATE. That way, if a util is renamed or a new util is 
> written (even some third party tool that we don't know about) they 
> would still have a sensible value to use.
>
> Cheers,
> Andy
>
Yes. Also lets not make this an enum. It would make more sense to have 
it as a set of flags. That way we can have a single field but containing 
two different meanings. One set would give us the reason for the log 
header (normal log flush, recovery, freeze, or whatever) and another 
single bit flag telling us whether it is userspace or kernel space. We 
can then have an origin, which can be numbered independently in 
userspace and kernel space which indicates which function it was called 
from.

That also gets rid of that big log_flush_types array. So a typical call 
to gfs2_log_flush() would look like:

gfs2_log_flush(sdp, NULL, GFS2_LF_SYNC|GFS2_LO_KILLSB);

in this case assuming it is called from gfs2_kill_sb(). The flag for the 
kernel would be added automatically in log_write_header(), since it 
would be needed for everything. That would make the code rather easier 
to understand, since the two independent fields would be declared 
separately. There are 32 bits to use, so no issue to divide it into two 
16 bit sub fields for example,

Steve.

[Cluster-devel] [GFS2 PATCH] GFS2: Log the reason for log flushes in every log header

[Bob Peterson]

Hi,

----- Original Message -----
| > +	LHF_SHUTDOWN		= 0, 
| Should 0 be used for "unknown"?

Good idea. I'll add that.
(snip)
| > +	/* Constants reserved for user space / gfs2-utils */
| > +	LHF_GFS2_CONVERT       	= 26,
| > +	LHF_GFS2_EDIT		= 27,
| > +	LHF_GFS2_FSCK		= 28,
| > +	LHF_GFS2_FSCK_JREPLAY	= 29,
| > +	LHF_GFS2_MKFS		= 30,
| > +	LHF_GFS2_JADD		= 31
| 
| Would it be better to have values for the purposes that the utils would
| need to touch the log header, e.g. LHF_UTIL_REPLAY, LHF_UTIL_FIX or
| LHF_UTIL_CREATE. That way, if a util is renamed or a new util is written
| (even some third party tool that we don't know about) they would still
| have a sensible value to use.
| 
| Cheers,
| Andy

Actually, yes, I was kind of hoping you would suggest some useful
values for user space. I didn't go over how gfs2-utils works with log
headers because I didn't want to delay posting a prototype further.

I only allocated one 32-bit set of flags, with some space in the middle
carved out for user space, but it seems a bit confining. Obviously this
is still just a prototype, so we can add another 32-bit flag (one for
kernel space and one for user space?) or improve it any other way that
would be useful. I'm open to suggestions.

Regards,

Bob Peterson
Red Hat File Systems

[Cluster-devel] [GFS2 PATCH] GFS2: Log the reason for log flushes in every log header

[Andrew Price]

On 11/12/17 13:23, Bob Peterson wrote:
> Hi,
> 
> ----- Original Message -----
> | > +	LHF_SHUTDOWN		= 0,
> | Should 0 be used for "unknown"?
> 
> Good idea. I'll add that.
> (snip)
> | > +	/* Constants reserved for user space / gfs2-utils */
> | > +	LHF_GFS2_CONVERT       	= 26,
> | > +	LHF_GFS2_EDIT		= 27,
> | > +	LHF_GFS2_FSCK		= 28,
> | > +	LHF_GFS2_FSCK_JREPLAY	= 29,
> | > +	LHF_GFS2_MKFS		= 30,
> | > +	LHF_GFS2_JADD		= 31
> |
> | Would it be better to have values for the purposes that the utils would
> | need to touch the log header, e.g. LHF_UTIL_REPLAY, LHF_UTIL_FIX or
> | LHF_UTIL_CREATE. That way, if a util is renamed or a new util is written
> | (even some third party tool that we don't know about) they would still
> | have a sensible value to use.
> |
> | Cheers,
> | Andy
> 
> Actually, yes, I was kind of hoping you would suggest some useful
> values for user space. I didn't go over how gfs2-utils works with log
> headers because I didn't want to delay posting a prototype further.
> 
> I only allocated one 32-bit set of flags, with some space in the middle
> carved out for user space, but it seems a bit confining. Obviously this
> is still just a prototype, so we can add another 32-bit flag (one for
> kernel space and one for user space?) or improve it any other way that
> would be useful. I'm open to suggestions.

Well I like Steve's suggestion of switching to bit flags assuming it's 
generally practical.

It might be useful to move the definitions of the values/flags into the 
same patch as the new log header struct is defined.

Cheers,
Andy