[PATCH 0/2] btrfs: Expose BTRFS commit stats through sysfs

[PATCH 0/2] btrfs: Expose BTRFS commit stats through sysfs

[Ioannis Angelakopoulos]

With this patch series we add the capability to BTRFS to expose some
commit stats through sysfs that might be useful for performance monitoring
and debugging purposes.

Specifically, through SYSFS we expose the following data:
  1) A counter for the commits that occurred so far.
  2) The duration in ms of the last commit.
  3) The maximum commit duration in ms seen so far.
  4) The total duration in ms of the commits seen so far.

The user also has the capability to reset the aforementioned data back to
zero, again through SYSFS.

Ioannis Angelakopoulos (2):
  btrfs: Add the capability of getting commit stats in BTRFS
  btrfs: Expose the BTRFS commit stats through sysfs

 fs/btrfs/ctree.h       | 14 ++++++++++++
 fs/btrfs/disk-io.c     |  6 ++++++
 fs/btrfs/sysfs.c       | 48 ++++++++++++++++++++++++++++++++++++++++++
 fs/btrfs/transaction.c | 38 ++++++++++++++++++++++++++++++++-
 4 files changed, 105 insertions(+), 1 deletion(-)

-- 
2.30.2

[PATCH 1/2] btrfs: Add the capability of getting commit stats in BTRFS

[Ioannis Angelakopoulos]

First we add  "struct btrfs_commit_stats" data structure under "fs_info"
to store the commit stats for BTRFS that will be exposed through sysfs

The stats exposed are: 1) The number of commits so far, 2) The duration of
the last commit in ms, 3) The maximum commit duration seen so far in ms
and 4) The total duration for all commits so far in ms.

The update of the commit stats occurs after the commit thread has gone
through all the logic that checks if there is another thread committing
at the same time. This means that we only account for actual commit work
in the commit stats we report and not the time the thread spends waiting
until it is ready to do the commit work.

Signed-off-by: Ioannis Angelakopoulos <iangelak@fb.com>
---
 fs/btrfs/ctree.h       | 14 ++++++++++++++
 fs/btrfs/disk-io.c     |  6 ++++++
 fs/btrfs/transaction.c | 38 +++++++++++++++++++++++++++++++++++++-
 3 files changed, 57 insertions(+), 1 deletion(-)

diff --git a/fs/btrfs/ctree.h b/fs/btrfs/ctree.h
index f7afdfd0bae7..d4cc38451c7b 100644
--- a/fs/btrfs/ctree.h
+++ b/fs/btrfs/ctree.h
@@ -660,6 +660,18 @@ enum btrfs_exclusive_operation {
 	BTRFS_EXCLOP_SWAP_ACTIVATE,
 };
 
+/* Storing data about btrfs commits. The data are accessible over sysfs */
+struct btrfs_commit_stats {
+	/* Total number of commits */
+	u64 commit_counter;
+	/* The maximum commit duration so far*/
+	u64 max_commit_dur;
+	/* The last commit duration */
+	u64 last_commit_dur;
+	/* The total commit duration */
+	u64 total_commit_dur;
+};
+
 struct btrfs_fs_info {
 	u8 chunk_tree_uuid[BTRFS_UUID_SIZE];
 	unsigned long flags;
@@ -1082,6 +1094,8 @@ struct btrfs_fs_info {
 	spinlock_t eb_leak_lock;
 	struct list_head allocated_ebs;
 #endif
+
+	struct btrfs_commit_stats *commit_stats;
 };
 
 static inline struct btrfs_fs_info *btrfs_sb(struct super_block *sb)
diff --git a/fs/btrfs/disk-io.c b/fs/btrfs/disk-io.c
index 800ad3a9c68e..1c366ea01a9f 100644
--- a/fs/btrfs/disk-io.c
+++ b/fs/btrfs/disk-io.c
@@ -1668,6 +1668,7 @@ void btrfs_free_fs_info(struct btrfs_fs_info *fs_info)
 	btrfs_free_ref_cache(fs_info);
 	kfree(fs_info->balance_ctl);
 	kfree(fs_info->delayed_root);
+	kfree(fs_info->commit_stats);
 	free_global_roots(fs_info);
 	btrfs_put_root(fs_info->tree_root);
 	btrfs_put_root(fs_info->chunk_root);
@@ -3174,6 +3175,11 @@ static int init_mount_fs_info(struct btrfs_fs_info *fs_info, struct super_block
 		return -ENOMEM;
 	btrfs_init_delayed_root(fs_info->delayed_root);
 
+	fs_info->commit_stats = kzalloc(sizeof(struct btrfs_commit_stats),
+					GFP_KERNEL);
+	if (!fs_info->commit_stats)
+		return -ENOMEM;
+
 	if (sb_rdonly(sb))
 		set_bit(BTRFS_FS_STATE_RO, &fs_info->fs_state);
 
diff --git a/fs/btrfs/transaction.c b/fs/btrfs/transaction.c
index 06c0a958d114..fb2a9bc9bae4 100644
--- a/fs/btrfs/transaction.c
+++ b/fs/btrfs/transaction.c
@@ -10,6 +10,7 @@
 #include <linux/pagemap.h>
 #include <linux/blkdev.h>
 #include <linux/uuid.h>
+#include <linux/timekeeping.h>
 #include "misc.h"
 #include "ctree.h"
 #include "disk-io.h"
@@ -674,7 +675,7 @@ start_transaction(struct btrfs_root *root, unsigned int num_items,
 	 * and then we deadlock with somebody doing a freeze.
 	 *
 	 * If we are ATTACH, it means we just want to catch the current
-	 * transaction and commit it, so we needn't do sb_start_intwrite(). 
+	 * transaction and commit it, so we needn't do sb_start_intwrite().
 	 */
 	if (type & __TRANS_FREEZABLE)
 		sb_start_intwrite(fs_info->sb);
@@ -2084,12 +2085,30 @@ static void add_pending_snapshot(struct btrfs_trans_handle *trans)
 	list_add(&trans->pending_snapshot->list, &cur_trans->pending_snapshots);
 }
 
+static void update_commit_stats(struct btrfs_fs_info *fs_info,
+								ktime_t interval)
+{
+	/* Increase the successful commits counter */
+	fs_info->commit_stats->commit_counter += 1;
+	/* Update the last commit duration */
+	fs_info->commit_stats->last_commit_dur = interval / 1000000;
+	/* Update the maximum commit duration */
+	fs_info->commit_stats->max_commit_dur =
+				fs_info->commit_stats->max_commit_dur >	interval / 1000000 ?
+				fs_info->commit_stats->max_commit_dur :	interval / 1000000;
+	/* Update the total commit duration */
+	fs_info->commit_stats->total_commit_dur += interval / 1000000;
+}
+
 int btrfs_commit_transaction(struct btrfs_trans_handle *trans)
 {
 	struct btrfs_fs_info *fs_info = trans->fs_info;
 	struct btrfs_transaction *cur_trans = trans->transaction;
 	struct btrfs_transaction *prev_trans = NULL;
 	int ret;
+	ktime_t start_time;
+	ktime_t end_time;
+	ktime_t interval;
 
 	ASSERT(refcount_read(&trans->use_count) == 1);
 
@@ -2214,6 +2233,12 @@ int btrfs_commit_transaction(struct btrfs_trans_handle *trans)
 		}
 	}
 
+	/*
+	 * Get the time spent on the work done by the commit thread and not
+	 * the time spent on a previous commit
+	 */
+	start_time = ktime_get_ns();
+
 	extwriter_counter_dec(cur_trans, trans->type);
 
 	ret = btrfs_start_delalloc_flush(fs_info);
@@ -2462,6 +2487,17 @@ int btrfs_commit_transaction(struct btrfs_trans_handle *trans)
 
 	kmem_cache_free(btrfs_trans_handle_cachep, trans);
 
+	end_time = ktime_get_ns();
+	interval = end_time - start_time;
+
+	/*
+	 * Protect the commit stats updates from concurrent updates through
+	 * sysfs.
+	 */
+	spin_lock(&fs_info->trans_lock);
+	update_commit_stats(fs_info, interval);
+	spin_unlock(&fs_info->trans_lock);
+
 	return ret;
 
 unlock_reloc:
-- 
2.30.2

[PATCH 2/2] btrfs: Expose the BTRFS commit stats through sysfs

[Ioannis Angelakopoulos]

Create a new sysfs entry named "commit_stats" for each mounted BTRFS
filesystem. The entry exposes: 1) The number of commits so far, 2) The
duration of the last commit in ms, 3) The maximum commit duration seen
so far in ms and 4) The total duration for all commits so far in ms.

The function "btrfs_commit_stats_show" is responsible for exposing the
stats to user space.

The function "btrfs_commit_stats_store" is responsible for resetting the
above values to zero.

Signed-off-by: Ioannis Angelakopoulos <iangelak@fb.com>
---
 fs/btrfs/sysfs.c | 48 ++++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 48 insertions(+)

diff --git a/fs/btrfs/sysfs.c b/fs/btrfs/sysfs.c
index b6cb5551050e..f68fc73006c0 100644
--- a/fs/btrfs/sysfs.c
+++ b/fs/btrfs/sysfs.c
@@ -991,6 +991,53 @@ static ssize_t btrfs_sectorsize_show(struct kobject *kobj,
 
 BTRFS_ATTR(, sectorsize, btrfs_sectorsize_show);
 
+static ssize_t btrfs_commit_stats_show(struct kobject *kobj,
+				struct kobj_attribute *a, char *buf)
+{
+	struct btrfs_fs_info *fs_info = to_fs_info(kobj);
+
+	/*
+	 * Expose the commits so far, the duration of the last commit, the
+	 * maximum duration of a commit so far and the total duration of
+	 * all the commits so far
+	 */
+	return sysfs_emit(buf, "Commits: %llu, Last: %llu ms, Max: %llu ms, Total: %llu ms\n",
+					  fs_info->commit_stats->commit_counter,
+					  fs_info->commit_stats->last_commit_dur,
+					  fs_info->commit_stats->max_commit_dur,
+					  fs_info->commit_stats->total_commit_dur);
+}
+
+static ssize_t btrfs_commit_stats_store(struct kobject *kobj,
+						struct kobj_attribute *a,
+						const char *buf, size_t len)
+{
+	struct btrfs_fs_info *fs_info = to_fs_info(kobj);
+
+	if (!fs_info)
+		return -EPERM;
+
+	if (!capable(CAP_SYS_RESOURCE))
+		return -EPERM;
+
+	/*
+	 * Just reset everything
+	 * Also take the trans_lock to avoid race conditions with the udpates
+	 * in btrfs_commit_transaction()
+	 */
+	spin_lock(&fs_info->trans_lock);
+	fs_info->commit_stats->commit_counter = 0;
+	fs_info->commit_stats->last_commit_dur = 0;
+	fs_info->commit_stats->max_commit_dur = 0;
+	fs_info->commit_stats->total_commit_dur = 0;
+	spin_unlock(&fs_info->trans_lock);
+
+	return len;
+}
+
+BTRFS_ATTR_RW(, commit_stats, btrfs_commit_stats_show,
+			  btrfs_commit_stats_store);
+
 static ssize_t btrfs_clone_alignment_show(struct kobject *kobj,
 				struct kobj_attribute *a, char *buf)
 {
@@ -1230,6 +1277,7 @@ static const struct attribute *btrfs_attrs[] = {
 	BTRFS_ATTR_PTR(, generation),
 	BTRFS_ATTR_PTR(, read_policy),
 	BTRFS_ATTR_PTR(, bg_reclaim_threshold),
+	BTRFS_ATTR_PTR(, commit_stats),
 	NULL,
 };
 
-- 
2.30.2

Re: [PATCH 1/2] btrfs: Add the capability of getting commit stats in BTRFS

[kernel test robot]

Hi Ioannis,

Thank you for the patch! Yet something to improve:

[auto build test ERROR on kdave/for-next]
[also build test ERROR on v5.19-rc1 next-20220610]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch]

url:    https://github.com/intel-lab-lkp/linux/commits/Ioannis-Angelakopoulos/btrfs-Expose-BTRFS-commit-stats-through-sysfs/20220611-045738
base:   https://git.kernel.org/pub/scm/linux/kernel/git/kdave/linux.git for-next
config: xtensa-allyesconfig (https://download.01.org/0day-ci/archive/20220611/202206111941.iKZ2myZc-lkp@intel.com/config)
compiler: xtensa-linux-gcc (GCC) 11.3.0
reproduce (this is a W=1 build):
        wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
        chmod +x ~/bin/make.cross
        # https://github.com/intel-lab-lkp/linux/commit/8f66d4d3d43f1502549101630cdc1291093b7596
        git remote add linux-review https://github.com/intel-lab-lkp/linux
        git fetch --no-tags linux-review Ioannis-Angelakopoulos/btrfs-Expose-BTRFS-commit-stats-through-sysfs/20220611-045738
        git checkout 8f66d4d3d43f1502549101630cdc1291093b7596
        # save the config file
        mkdir build_dir && cp config build_dir/.config
        COMPILER_INSTALL_PATH=$HOME/0day COMPILER=gcc-11.3.0 make.cross W=1 O=build_dir ARCH=xtensa SHELL=/bin/bash

If you fix the issue, kindly add following tag where applicable
Reported-by: kernel test robot <lkp@intel.com>

All errors (new ones prefixed by >>):

   `.exit.text' referenced in section `__jump_table' of fs/cifs/cifsfs.o: defined in discarded section `.exit.text' of fs/cifs/cifsfs.o
   `.exit.text' referenced in section `__jump_table' of fs/cifs/cifsfs.o: defined in discarded section `.exit.text' of fs/cifs/cifsfs.o
   `.exit.text' referenced in section `__jump_table' of fs/fuse/inode.o: defined in discarded section `.exit.text' of fs/fuse/inode.o
   `.exit.text' referenced in section `__jump_table' of fs/fuse/inode.o: defined in discarded section `.exit.text' of fs/fuse/inode.o
   xtensa-linux-ld: fs/btrfs/transaction.o: in function `btrfs_apply_pending_changes':
>> transaction.c:(.text+0x62f4): undefined reference to `__divdi3'
   xtensa-linux-ld: fs/btrfs/transaction.o: in function `btrfs_commit_transaction':
   transaction.c:(.text+0x7774): undefined reference to `__divdi3'
   `.exit.text' referenced in section `__jump_table' of fs/ceph/super.o: defined in discarded section `.exit.text' of fs/ceph/super.o
   `.exit.text' referenced in section `__jump_table' of fs/ceph/super.o: defined in discarded section `.exit.text' of fs/ceph/super.o
   `.exit.text' referenced in section `__jump_table' of drivers/rapidio/rio_cm.o: defined in discarded section `.exit.text' of drivers/rapidio/rio_cm.o
   `.exit.text' referenced in section `__jump_table' of drivers/rapidio/rio_cm.o: defined in discarded section `.exit.text' of drivers/rapidio/rio_cm.o
   `.exit.text' referenced in section `__jump_table' of drivers/rapidio/switches/idt_gen2.o: defined in discarded section `.exit.text' of drivers/rapidio/switches/idt_gen2.o
   `.exit.text' referenced in section `__jump_table' of drivers/rapidio/switches/idt_gen2.o: defined in discarded section `.exit.text' of drivers/rapidio/switches/idt_gen2.o
   `.exit.text' referenced in section `__jump_table' of drivers/rapidio/switches/idt_gen2.o: defined in discarded section `.exit.text' of drivers/rapidio/switches/idt_gen2.o
   `.exit.text' referenced in section `__jump_table' of drivers/rapidio/switches/idt_gen2.o: defined in discarded section `.exit.text' of drivers/rapidio/switches/idt_gen2.o
   `.exit.text' referenced in section `__jump_table' of drivers/rapidio/switches/idt_gen3.o: defined in discarded section `.exit.text' of drivers/rapidio/switches/idt_gen3.o
   `.exit.text' referenced in section `__jump_table' of drivers/rapidio/switches/idt_gen3.o: defined in discarded section `.exit.text' of drivers/rapidio/switches/idt_gen3.o
   `.exit.text' referenced in section `__jump_table' of drivers/rapidio/switches/idt_gen3.o: defined in discarded section `.exit.text' of drivers/rapidio/switches/idt_gen3.o
   `.exit.text' referenced in section `__jump_table' of drivers/rapidio/switches/idt_gen3.o: defined in discarded section `.exit.text' of drivers/rapidio/switches/idt_gen3.o
   `.exit.text' referenced in section `__jump_table' of drivers/video/fbdev/vt8623fb.o: defined in discarded section `.exit.text' of drivers/video/fbdev/vt8623fb.o
   `.exit.text' referenced in section `__jump_table' of drivers/video/fbdev/vt8623fb.o: defined in discarded section `.exit.text' of drivers/video/fbdev/vt8623fb.o
   `.exit.text' referenced in section `__jump_table' of drivers/video/fbdev/s3fb.o: defined in discarded section `.exit.text' of drivers/video/fbdev/s3fb.o
   `.exit.text' referenced in section `__jump_table' of drivers/video/fbdev/s3fb.o: defined in discarded section `.exit.text' of drivers/video/fbdev/s3fb.o
   `.exit.text' referenced in section `__jump_table' of drivers/video/fbdev/arkfb.o: defined in discarded section `.exit.text' of drivers/video/fbdev/arkfb.o
   `.exit.text' referenced in section `__jump_table' of drivers/video/fbdev/arkfb.o: defined in discarded section `.exit.text' of drivers/video/fbdev/arkfb.o
   `.exit.text' referenced in section `__jump_table' of drivers/misc/phantom.o: defined in discarded section `.exit.text' of drivers/misc/phantom.o
   `.exit.text' referenced in section `__jump_table' of drivers/misc/phantom.o: defined in discarded section `.exit.text' of drivers/misc/phantom.o
   `.exit.text' referenced in section `__jump_table' of drivers/misc/habanalabs/common/habanalabs_drv.o: defined in discarded section `.exit.text' of drivers/misc/habanalabs/common/habanalabs_drv.o
   `.exit.text' referenced in section `__jump_table' of drivers/misc/habanalabs/common/habanalabs_drv.o: defined in discarded section `.exit.text' of drivers/misc/habanalabs/common/habanalabs_drv.o
   `.exit.text' referenced in section `__jump_table' of drivers/scsi/fcoe/fcoe.o: defined in discarded section `.exit.text' of drivers/scsi/fcoe/fcoe.o
   `.exit.text' referenced in section `__jump_table' of drivers/scsi/fcoe/fcoe.o: defined in discarded section `.exit.text' of drivers/scsi/fcoe/fcoe.o
   `.exit.text' referenced in section `__jump_table' of drivers/scsi/cxgbi/libcxgbi.o: defined in discarded section `.exit.text' of drivers/scsi/cxgbi/libcxgbi.o
   `.exit.text' referenced in section `__jump_table' of drivers/scsi/cxgbi/libcxgbi.o: defined in discarded section `.exit.text' of drivers/scsi/cxgbi/libcxgbi.o
   `.exit.text' referenced in section `__jump_table' of drivers/target/target_core_configfs.o: defined in discarded section `.exit.text' of drivers/target/target_core_configfs.o
   `.exit.text' referenced in section `__jump_table' of drivers/target/target_core_configfs.o: defined in discarded section `.exit.text' of drivers/target/target_core_configfs.o
   `.exit.text' referenced in section `__jump_table' of drivers/mtd/maps/pcmciamtd.o: defined in discarded section `.exit.text' of drivers/mtd/maps/pcmciamtd.o
   `.exit.text' referenced in section `__jump_table' of drivers/mtd/maps/pcmciamtd.o: defined in discarded section `.exit.text' of drivers/mtd/maps/pcmciamtd.o
   `.exit.text' referenced in section `__jump_table' of drivers/net/wireless/purelifi/plfxlc/usb.o: defined in discarded section `.exit.text' of drivers/net/wireless/purelifi/plfxlc/usb.o
   `.exit.text' referenced in section `__jump_table' of drivers/net/wireless/purelifi/plfxlc/usb.o: defined in discarded section `.exit.text' of drivers/net/wireless/purelifi/plfxlc/usb.o
   `.exit.text' referenced in section `__jump_table' of drivers/net/wireless/zydas/zd1211rw/zd_usb.o: defined in discarded section `.exit.text' of drivers/net/wireless/zydas/zd1211rw/zd_usb.o
   `.exit.text' referenced in section `__jump_table' of drivers/net/wireless/zydas/zd1211rw/zd_usb.o: defined in discarded section `.exit.text' of drivers/net/wireless/zydas/zd1211rw/zd_usb.o
   `.exit.text' referenced in section `__jump_table' of drivers/net/wireless/ray_cs.o: defined in discarded section `.exit.text' of drivers/net/wireless/ray_cs.o
   `.exit.text' referenced in section `__jump_table' of drivers/net/wireless/ray_cs.o: defined in discarded section `.exit.text' of drivers/net/wireless/ray_cs.o
   `.exit.text' referenced in section `__jump_table' of drivers/net/wireless/mac80211_hwsim.o: defined in discarded section `.exit.text' of drivers/net/wireless/mac80211_hwsim.o
   `.exit.text' referenced in section `__jump_table' of drivers/net/wireless/mac80211_hwsim.o: defined in discarded section `.exit.text' of drivers/net/wireless/mac80211_hwsim.o
   `.exit.text' referenced in section `__jump_table' of drivers/usb/gadget/legacy/inode.o: defined in discarded section `.exit.text' of drivers/usb/gadget/legacy/inode.o
   `.exit.text' referenced in section `__jump_table' of drivers/usb/gadget/legacy/inode.o: defined in discarded section `.exit.text' of drivers/usb/gadget/legacy/inode.o
   `.exit.text' referenced in section `__jump_table' of drivers/usb/gadget/legacy/g_ffs.o: defined in discarded section `.exit.text' of drivers/usb/gadget/legacy/g_ffs.o
   `.exit.text' referenced in section `__jump_table' of drivers/usb/gadget/legacy/g_ffs.o: defined in discarded section `.exit.text' of drivers/usb/gadget/legacy/g_ffs.o
   `.exit.text' referenced in section `__jump_table' of drivers/media/common/siano/smscoreapi.o: defined in discarded section `.exit.text' of drivers/media/common/siano/smscoreapi.o
   `.exit.text' referenced in section `__jump_table' of drivers/media/common/siano/smscoreapi.o: defined in discarded section `.exit.text' of drivers/media/common/siano/smscoreapi.o
   `.exit.text' referenced in section `__jump_table' of drivers/vme/bridges/vme_fake.o: defined in discarded section `.exit.text' of drivers/vme/bridges/vme_fake.o
   `.exit.text' referenced in section `__jump_table' of drivers/vme/bridges/vme_fake.o: defined in discarded section `.exit.text' of drivers/vme/bridges/vme_fake.o
   `.exit.text' referenced in section `.data' of sound/soc/codecs/tlv320adc3xxx.o: defined in discarded section `.exit.text' of sound/soc/codecs/tlv320adc3xxx.o
   `.exit.text' referenced in section `__jump_table' of net/netfilter/nf_conntrack_h323_main.o: defined in discarded section `.exit.text' of net/netfilter/nf_conntrack_h323_main.o
   `.exit.text' referenced in section `__jump_table' of net/netfilter/nf_conntrack_h323_main.o: defined in discarded section `.exit.text' of net/netfilter/nf_conntrack_h323_main.o
   `.exit.text' referenced in section `__jump_table' of net/netfilter/ipset/ip_set_core.o: defined in discarded section `.exit.text' of net/netfilter/ipset/ip_set_core.o
   `.exit.text' referenced in section `__jump_table' of net/netfilter/ipset/ip_set_core.o: defined in discarded section `.exit.text' of net/netfilter/ipset/ip_set_core.o
   `.exit.text' referenced in section `__jump_table' of net/ceph/ceph_common.o: defined in discarded section `.exit.text' of net/ceph/ceph_common.o
   `.exit.text' referenced in section `__jump_table' of net/ceph/ceph_common.o: defined in discarded section `.exit.text' of net/ceph/ceph_common.o

-- 
0-DAY CI Kernel Test Service
https://01.org/lkp

Re: [PATCH 1/2] btrfs: Add the capability of getting commit stats in BTRFS

[kernel test robot]

Hi Ioannis,

Thank you for the patch! Yet something to improve:

[auto build test ERROR on kdave/for-next]
[also build test ERROR on v5.19-rc1 next-20220610]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch]

url:    https://github.com/intel-lab-lkp/linux/commits/Ioannis-Angelakopoulos/btrfs-Expose-BTRFS-commit-stats-through-sysfs/20220611-045738
base:   https://git.kernel.org/pub/scm/linux/kernel/git/kdave/linux.git for-next
config: microblaze-randconfig-r015-20220611 (https://download.01.org/0day-ci/archive/20220611/202206112045.UQwxPCB0-lkp@intel.com/config)
compiler: microblaze-linux-gcc (GCC) 11.3.0
reproduce (this is a W=1 build):
        wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
        chmod +x ~/bin/make.cross
        # https://github.com/intel-lab-lkp/linux/commit/8f66d4d3d43f1502549101630cdc1291093b7596
        git remote add linux-review https://github.com/intel-lab-lkp/linux
        git fetch --no-tags linux-review Ioannis-Angelakopoulos/btrfs-Expose-BTRFS-commit-stats-through-sysfs/20220611-045738
        git checkout 8f66d4d3d43f1502549101630cdc1291093b7596
        # save the config file
        mkdir build_dir && cp config build_dir/.config
        COMPILER_INSTALL_PATH=$HOME/0day COMPILER=gcc-11.3.0 make.cross W=1 O=build_dir ARCH=microblaze SHELL=/bin/bash

If you fix the issue, kindly add following tag where applicable
Reported-by: kernel test robot <lkp@intel.com>

All errors (new ones prefixed by >>):

   microblaze-linux-ld: fs/btrfs/transaction.o: in function `update_commit_stats':
>> fs/btrfs/transaction.c:2094: undefined reference to `__divdi3'


vim +2094 fs/btrfs/transaction.c

  2087	
  2088	static void update_commit_stats(struct btrfs_fs_info *fs_info,
  2089									ktime_t interval)
  2090	{
  2091		/* Increase the successful commits counter */
  2092		fs_info->commit_stats->commit_counter += 1;
  2093		/* Update the last commit duration */
> 2094		fs_info->commit_stats->last_commit_dur = interval / 1000000;
  2095		/* Update the maximum commit duration */
  2096		fs_info->commit_stats->max_commit_dur =
  2097					fs_info->commit_stats->max_commit_dur >	interval / 1000000 ?
  2098					fs_info->commit_stats->max_commit_dur :	interval / 1000000;
  2099		/* Update the total commit duration */
  2100		fs_info->commit_stats->total_commit_dur += interval / 1000000;
  2101	}
  2102	

-- 
0-DAY CI Kernel Test Service
https://01.org/lkp

Re: [PATCH 1/2] btrfs: Add the capability of getting commit stats in BTRFS

[David Sterba]

On Fri, Jun 10, 2022 at 01:54:07PM -0700, Ioannis Angelakopoulos wrote:
> First we add  "struct btrfs_commit_stats" data structure under "fs_info"
> to store the commit stats for BTRFS that will be exposed through sysfs
> 
> The stats exposed are: 1) The number of commits so far, 2) The duration of
> the last commit in ms, 3) The maximum commit duration seen so far in ms
> and 4) The total duration for all commits so far in ms.
> 
> The update of the commit stats occurs after the commit thread has gone
> through all the logic that checks if there is another thread committing
> at the same time. This means that we only account for actual commit work
> in the commit stats we report and not the time the thread spends waiting
> until it is ready to do the commit work.
> 
> Signed-off-by: Ioannis Angelakopoulos <iangelak@fb.com>
> ---
>  fs/btrfs/ctree.h       | 14 ++++++++++++++
>  fs/btrfs/disk-io.c     |  6 ++++++
>  fs/btrfs/transaction.c | 38 +++++++++++++++++++++++++++++++++++++-
>  3 files changed, 57 insertions(+), 1 deletion(-)
> 
> diff --git a/fs/btrfs/ctree.h b/fs/btrfs/ctree.h
> index f7afdfd0bae7..d4cc38451c7b 100644
> --- a/fs/btrfs/ctree.h
> +++ b/fs/btrfs/ctree.h
> @@ -660,6 +660,18 @@ enum btrfs_exclusive_operation {
>  	BTRFS_EXCLOP_SWAP_ACTIVATE,
>  };
>  
> +/* Storing data about btrfs commits. The data are accessible over sysfs */
> +struct btrfs_commit_stats {
> +	/* Total number of commits */
> +	u64 commit_counter;
> +	/* The maximum commit duration so far*/
> +	u64 max_commit_dur;
> +	/* The last commit duration */
> +	u64 last_commit_dur;
> +	/* The total commit duration */
> +	u64 total_commit_dur;
> +};
> +
>  struct btrfs_fs_info {
>  	u8 chunk_tree_uuid[BTRFS_UUID_SIZE];
>  	unsigned long flags;
> @@ -1082,6 +1094,8 @@ struct btrfs_fs_info {
>  	spinlock_t eb_leak_lock;
>  	struct list_head allocated_ebs;
>  #endif
> +
> +	struct btrfs_commit_stats *commit_stats;

As long as this is in fs_info and reasonable size I don't see a reason
to make the stats allocated dynamically, compared to being embedded
either as a struct or array of u64.

> --- a/fs/btrfs/transaction.c
> +++ b/fs/btrfs/transaction.c
> @@ -10,6 +10,7 @@
>  #include <linux/pagemap.h>
>  #include <linux/blkdev.h>
>  #include <linux/uuid.h>
> +#include <linux/timekeeping.h>
>  #include "misc.h"
>  #include "ctree.h"
>  #include "disk-io.h"
> @@ -674,7 +675,7 @@ start_transaction(struct btrfs_root *root, unsigned int num_items,
>  	 * and then we deadlock with somebody doing a freeze.
>  	 *
>  	 * If we are ATTACH, it means we just want to catch the current
> -	 * transaction and commit it, so we needn't do sb_start_intwrite(). 
> +	 * transaction and commit it, so we needn't do sb_start_intwrite().

Unrelated change.

>  	 */
>  	if (type & __TRANS_FREEZABLE)
>  		sb_start_intwrite(fs_info->sb);
> @@ -2084,12 +2085,30 @@ static void add_pending_snapshot(struct btrfs_trans_handle *trans)
>  	list_add(&trans->pending_snapshot->list, &cur_trans->pending_snapshots);
>  }
>  
> +static void update_commit_stats(struct btrfs_fs_info *fs_info,
> +								ktime_t interval)
> +{
> +	/* Increase the successful commits counter */

Such comments are really useless, it repeats in words what the code does
not why and does not bring any new information for understanding. I'd
not put any comment into this function at all, it's clear from the name
and it's short.

> +	fs_info->commit_stats->commit_counter += 1;
> +	/* Update the last commit duration */
> +	fs_info->commit_stats->last_commit_dur = interval / 1000000;
> +	/* Update the maximum commit duration */
> +	fs_info->commit_stats->max_commit_dur =
> +				fs_info->commit_stats->max_commit_dur >	interval / 1000000 ?
> +				fs_info->commit_stats->max_commit_dur :	interval / 1000000;
> +	/* Update the total commit duration */
> +	fs_info->commit_stats->total_commit_dur += interval / 1000000;

4 times repeated 'interfal / 1000000' that converts the parameter from
ns to ms, so that should be done already in the caller.

> +}
> +
>  int btrfs_commit_transaction(struct btrfs_trans_handle *trans)
>  {
>  	struct btrfs_fs_info *fs_info = trans->fs_info;
>  	struct btrfs_transaction *cur_trans = trans->transaction;
>  	struct btrfs_transaction *prev_trans = NULL;
>  	int ret;
> +	ktime_t start_time;
> +	ktime_t end_time;
> +	ktime_t interval;
>  
>  	ASSERT(refcount_read(&trans->use_count) == 1);
>  
> @@ -2214,6 +2233,12 @@ int btrfs_commit_transaction(struct btrfs_trans_handle *trans)
>  		}
>  	}
>  
> +	/*
> +	 * Get the time spent on the work done by the commit thread and not
> +	 * the time spent on a previous commit
> +	 */
> +	start_time = ktime_get_ns();
> +
>  	extwriter_counter_dec(cur_trans, trans->type);
>  
>  	ret = btrfs_start_delalloc_flush(fs_info);
> @@ -2462,6 +2487,17 @@ int btrfs_commit_transaction(struct btrfs_trans_handle *trans)
>  
>  	kmem_cache_free(btrfs_trans_handle_cachep, trans);
>  
> +	end_time = ktime_get_ns();

I'm not sure the end time should be read here, there's a tracepoint a
few lines above marking end of the transaction.

> +	interval = end_time - start_time;

end_time is used only once, not needed

> +
> +	/*
> +	 * Protect the commit stats updates from concurrent updates through
> +	 * sysfs.
> +	 */
> +	spin_lock(&fs_info->trans_lock);
> +	update_commit_stats(fs_info, interval);

So here pass interval/1000000

> +	spin_unlock(&fs_info->trans_lock);
> +
>  	return ret;
>  
>  unlock_reloc:
> -- 
> 2.30.2
> 

Re: [PATCH 2/2] btrfs: Expose the BTRFS commit stats through sysfs

[David Sterba]

On Fri, Jun 10, 2022 at 01:54:09PM -0700, Ioannis Angelakopoulos wrote:
> Create a new sysfs entry named "commit_stats" for each mounted BTRFS
> filesystem. The entry exposes: 1) The number of commits so far, 2) The
> duration of the last commit in ms, 3) The maximum commit duration seen
> so far in ms and 4) The total duration for all commits so far in ms.
> 
> The function "btrfs_commit_stats_show" is responsible for exposing the
> stats to user space.

Please mention the actual path of the file, the callbacks are
implementation detail. Also mention the path at the description at the
beginning of sysfs.c.

> The function "btrfs_commit_stats_store" is responsible for resetting the
> above values to zero.
> 
> Signed-off-by: Ioannis Angelakopoulos <iangelak@fb.com>
> ---
>  fs/btrfs/sysfs.c | 48 ++++++++++++++++++++++++++++++++++++++++++++++++
>  1 file changed, 48 insertions(+)
> 
> diff --git a/fs/btrfs/sysfs.c b/fs/btrfs/sysfs.c
> index b6cb5551050e..f68fc73006c0 100644
> --- a/fs/btrfs/sysfs.c
> +++ b/fs/btrfs/sysfs.c
> @@ -991,6 +991,53 @@ static ssize_t btrfs_sectorsize_show(struct kobject *kobj,
>  
>  BTRFS_ATTR(, sectorsize, btrfs_sectorsize_show);
>  
> +static ssize_t btrfs_commit_stats_show(struct kobject *kobj,
> +				struct kobj_attribute *a, char *buf)
> +{
> +	struct btrfs_fs_info *fs_info = to_fs_info(kobj);
> +
> +	/*
> +	 * Expose the commits so far, the duration of the last commit, the
> +	 * maximum duration of a commit so far and the total duration of
> +	 * all the commits so far
> +	 */

Comment not necessary

> +	return sysfs_emit(buf, "Commits: %llu, Last: %llu ms, Max: %llu ms, Total: %llu ms\n",

So this is another format of sysfs output that does not follow any
established format. There are two: one file per value, or list of
"name space value newline" in one file (which is suitable for a set of
stats as it allow to grab a consistent snapshot). See eg.
btrfs_devinfo_error_stats_show .

> +					  fs_info->commit_stats->commit_counter,
> +					  fs_info->commit_stats->last_commit_dur,
> +					  fs_info->commit_stats->max_commit_dur,
> +					  fs_info->commit_stats->total_commit_dur);
> +}
> +
> +static ssize_t btrfs_commit_stats_store(struct kobject *kobj,
> +						struct kobj_attribute *a,
> +						const char *buf, size_t len)
> +{
> +	struct btrfs_fs_info *fs_info = to_fs_info(kobj);
> +
> +	if (!fs_info)
> +		return -EPERM;
> +
> +	if (!capable(CAP_SYS_RESOURCE))
> +		return -EPERM;

Should this accept only numeric value? Right now it would accept
anything, that's not common.

> +
> +	/*
> +	 * Just reset everything
> +	 * Also take the trans_lock to avoid race conditions with the udpates
> +	 * in btrfs_commit_transaction()

Comment not necessary, this is obvious.

> +	 */
> +	spin_lock(&fs_info->trans_lock);

Also I think the trans_lock is not the right one, it's a lock used for
transaction locking and more related to the transaction itself, while
the stats are a long term object and the super_lock is more sutable.

> +	fs_info->commit_stats->commit_counter = 0;
> +	fs_info->commit_stats->last_commit_dur = 0;
> +	fs_info->commit_stats->max_commit_dur = 0;
> +	fs_info->commit_stats->total_commit_dur = 0;
> +	spin_unlock(&fs_info->trans_lock);
> +
> +	return len;
> +}
> +
> +BTRFS_ATTR_RW(, commit_stats, btrfs_commit_stats_show,
> +			  btrfs_commit_stats_store);
> +
>  static ssize_t btrfs_clone_alignment_show(struct kobject *kobj,
>  				struct kobj_attribute *a, char *buf)
>  {
> @@ -1230,6 +1277,7 @@ static const struct attribute *btrfs_attrs[] = {
>  	BTRFS_ATTR_PTR(, generation),
>  	BTRFS_ATTR_PTR(, read_policy),
>  	BTRFS_ATTR_PTR(, bg_reclaim_threshold),
> +	BTRFS_ATTR_PTR(, commit_stats),
>  	NULL,
>  };
>  
> -- 
> 2.30.2
> 

Re: [PATCH 1/2] btrfs: Add the capability of getting commit stats in BTRFS

[Sweet Tea Dorminy]

On 6/10/22 16:54, Ioannis Angelakopoulos wrote:
> First we add  "struct btrfs_commit_stats" data structure under "fs_info"
> to store the commit stats for BTRFS that will be exposed through sysfs
> 
> The stats exposed are: 1) The number of commits so far, 2) The duration of
> the last commit in ms, 3) The maximum commit duration seen so far in ms
> and 4) The total duration for all commits so far in ms.
> 
> The update of the commit stats occurs after the commit thread has gone
> through all the logic that checks if there is another thread committing
> at the same time. This means that we only account for actual commit work
> in the commit stats we report and not the time the thread spends waiting
> until it is ready to do the commit work.
> 
> Signed-off-by: Ioannis Angelakopoulos <iangelak@fb.com>
> ---
>   fs/btrfs/ctree.h       | 14 ++++++++++++++
>   fs/btrfs/disk-io.c     |  6 ++++++
>   fs/btrfs/transaction.c | 38 +++++++++++++++++++++++++++++++++++++-
>   3 files changed, 57 insertions(+), 1 deletion(-)
> 
> diff --git a/fs/btrfs/ctree.h b/fs/btrfs/ctree.h
> index f7afdfd0bae7..d4cc38451c7b 100644
> --- a/fs/btrfs/ctree.h
> +++ b/fs/btrfs/ctree.h
> @@ -660,6 +660,18 @@ enum btrfs_exclusive_operation {
>   	BTRFS_EXCLOP_SWAP_ACTIVATE,
>   };
>   
> +/* Storing data about btrfs commits. The data are accessible over sysfs */
> +struct btrfs_commit_stats {
> +	/* Total number of commits */
> +	u64 commit_counter;
> +	/* The maximum commit duration so far*/
> +	u64 max_commit_dur;
> +	/* The last commit duration */
> +	u64 last_commit_dur;
> +	/* The total commit duration */
> +	u64 total_commit_dur;
> +};
> +
>   struct btrfs_fs_info {
>   	u8 chunk_tree_uuid[BTRFS_UUID_SIZE];
>   	unsigned long flags;
> @@ -1082,6 +1094,8 @@ struct btrfs_fs_info {
>   	spinlock_t eb_leak_lock;
>   	struct list_head allocated_ebs;
>   #endif
> +
> +	struct btrfs_commit_stats *commit_stats;
>   };
>   
>   static inline struct btrfs_fs_info *btrfs_sb(struct super_block *sb)
> diff --git a/fs/btrfs/disk-io.c b/fs/btrfs/disk-io.c
> index 800ad3a9c68e..1c366ea01a9f 100644
> --- a/fs/btrfs/disk-io.c
> +++ b/fs/btrfs/disk-io.c
> @@ -1668,6 +1668,7 @@ void btrfs_free_fs_info(struct btrfs_fs_info *fs_info)
>   	btrfs_free_ref_cache(fs_info);
>   	kfree(fs_info->balance_ctl);
>   	kfree(fs_info->delayed_root);
> +	kfree(fs_info->commit_stats);
>   	free_global_roots(fs_info);
>   	btrfs_put_root(fs_info->tree_root);
>   	btrfs_put_root(fs_info->chunk_root);
> @@ -3174,6 +3175,11 @@ static int init_mount_fs_info(struct btrfs_fs_info *fs_info, struct super_block
>   		return -ENOMEM;
>   	btrfs_init_delayed_root(fs_info->delayed_root);
>   
> +	fs_info->commit_stats = kzalloc(sizeof(struct btrfs_commit_stats),
> +					GFP_KERNEL);
> +	if (!fs_info->commit_stats)
> +		return -ENOMEM;
> +
>   	if (sb_rdonly(sb))
>   		set_bit(BTRFS_FS_STATE_RO, &fs_info->fs_state);
>   
> diff --git a/fs/btrfs/transaction.c b/fs/btrfs/transaction.c
> index 06c0a958d114..fb2a9bc9bae4 100644
> --- a/fs/btrfs/transaction.c
> +++ b/fs/btrfs/transaction.c
> @@ -10,6 +10,7 @@
>   #include <linux/pagemap.h>
>   #include <linux/blkdev.h>
>   #include <linux/uuid.h>
> +#include <linux/timekeeping.h>
>   #include "misc.h"
>   #include "ctree.h"
>   #include "disk-io.h"
> @@ -674,7 +675,7 @@ start_transaction(struct btrfs_root *root, unsigned int num_items,
>   	 * and then we deadlock with somebody doing a freeze.
>   	 *
>   	 * If we are ATTACH, it means we just want to catch the current
> -	 * transaction and commit it, so we needn't do sb_start_intwrite().
> +	 * transaction and commit it, so we needn't do sb_start_intwrite().
>   	 */
>   	if (type & __TRANS_FREEZABLE)
>   		sb_start_intwrite(fs_info->sb);
> @@ -2084,12 +2085,30 @@ static void add_pending_snapshot(struct btrfs_trans_handle *trans)
>   	list_add(&trans->pending_snapshot->list, &cur_trans->pending_snapshots);
>   }
>   
> +static void update_commit_stats(struct btrfs_fs_info *fs_info,
> +								ktime_t interval)
> +{
> +	/* Increase the successful commits counter */
> +	fs_info->commit_stats->commit_counter += 1;
> +	/* Update the last commit duration */
> +	fs_info->commit_stats->last_commit_dur = interval / 1000000;
> +	/* Update the maximum commit duration */
> +	fs_info->commit_stats->max_commit_dur =
> +				fs_info->commit_stats->max_commit_dur >	interval / 1000000 ?
> +				fs_info->commit_stats->max_commit_dur :	interval / 1000000;
could use max(fs_info->commit_stats->max_commit_dur, interval) for less 
duplication.
> +	/* Update the total commit duration */
> +	fs_info->commit_stats->total_commit_dur += interval / 1000000;
> +}

Why not store as ns? You could do the conversion at display time for a 
slight increase in accuracy of total_commit_dur (consider samples of 2.8 
ms, 2.8 ms, 1.4 ms: this code would print total duration of 5 ms, if I 
understand rightly, but 7 ms is the actual total).

Might also use the macro NSEC_PER_MSEC instead of 1000000.

> +
>   int btrfs_commit_transaction(struct btrfs_trans_handle *trans)
>   {
>   	struct btrfs_fs_info *fs_info = trans->fs_info;
>   	struct btrfs_transaction *cur_trans = trans->transaction;
>   	struct btrfs_transaction *prev_trans = NULL;
>   	int ret;
> +	ktime_t start_time;
> +	ktime_t end_time;
> +	ktime_t interval;
>   
>   	ASSERT(refcount_read(&trans->use_count) == 1);
>   
> @@ -2214,6 +2233,12 @@ int btrfs_commit_transaction(struct btrfs_trans_handle *trans)
>   		}
>   	}
>   
> +	/*
> +	 * Get the time spent on the work done by the commit thread and not
> +	 * the time spent on a previous commit
> +	 */
> +	start_time = ktime_get_ns();
> +
>   	extwriter_counter_dec(cur_trans, trans->type);
>   
>   	ret = btrfs_start_delalloc_flush(fs_info);
> @@ -2462,6 +2487,17 @@ int btrfs_commit_transaction(struct btrfs_trans_handle *trans)
>   
>   	kmem_cache_free(btrfs_trans_handle_cachep, trans);
>   
> +	end_time = ktime_get_ns();
> +	interval = end_time - start_time;
> +
> +	/*
> +	 * Protect the commit stats updates from concurrent updates through
> +	 * sysfs.
> +	 */
> +	spin_lock(&fs_info->trans_lock);
> +	update_commit_stats(fs_info, interval);
> +	spin_unlock(&fs_info->trans_lock)
> +
>   	return ret;
>   
>   unlock_reloc:

Re: [PATCH 1/2] btrfs: Add the capability of getting commit stats in BTRFS

[David Sterba]

On Mon, Jun 13, 2022 at 05:05:05PM -0400, Sweet Tea Dorminy wrote:
> > +	/* Update the total commit duration */
> > +	fs_info->commit_stats->total_commit_dur += interval / 1000000;
> > +}
> 
> Why not store as ns? You could do the conversion at display time for a 
> slight increase in accuracy of total_commit_dur (consider samples of 2.8 
> ms, 2.8 ms, 1.4 ms: this code would print total duration of 5 ms, if I 
> understand rightly, but 7 ms is the actual total).

Good point, what's the reasonable granularity and precision? Tracking in
ns but printing as ms sounds OK to me and should cover most use cases.

A think a full commit could be faster than 1ms on contemporary systems,
eg. memory backed device, small amount of data to write, but that's
probably an edge case. You could also gather some samples so we get a
better idea.