diff mbox series

[RFC,4/7] btrfs: trace, add event btrfs_read_policy

Message ID e6e5c40113cd3e939441ab3ece823282049a596f.1603751876.git.anand.jain@oracle.com
State New, archived
Headers show
Series [RFC,1/7] block: export part_stat_read_all | expand

Commit Message

Anand Jain Oct. 26, 2020, 11:55 p.m. UTC
This patch adds trace event btrfs_read_policy, which is common to all the
read policies.

Signed-off-by: Anand Jain <anand.jain@oracle.com>
---
 fs/btrfs/volumes.c           | 28 ++++++++++++++++++++++++++--
 include/trace/events/btrfs.h | 20 ++++++++++++++++++++
 2 files changed, 46 insertions(+), 2 deletions(-)

Comments

Josef Bacik Oct. 27, 2020, 6:22 p.m. UTC | #1
On 10/26/20 7:55 PM, Anand Jain wrote:
> This patch adds trace event btrfs_read_policy, which is common to all the
> read policies.
> 
> Signed-off-by: Anand Jain <anand.jain@oracle.com>
> ---
>   fs/btrfs/volumes.c           | 28 ++++++++++++++++++++++++++--
>   include/trace/events/btrfs.h | 20 ++++++++++++++++++++
>   2 files changed, 46 insertions(+), 2 deletions(-)

Noooooo this isn't the way we do this.  Simply make a trace class with all the 
variations, and then add individual trace events that inherit from the class 
that print out the appropriate values.  Thanks,

Josef
Anand Jain Oct. 28, 2020, 8:59 a.m. UTC | #2
On 28/10/20 2:22 am, Josef Bacik wrote:
> On 10/26/20 7:55 PM, Anand Jain wrote:
>> This patch adds trace event btrfs_read_policy, which is common to all the
>> read policies.
>>
>> Signed-off-by: Anand Jain <anand.jain@oracle.com>
>> ---
>>   fs/btrfs/volumes.c           | 28 ++++++++++++++++++++++++++--
>>   include/trace/events/btrfs.h | 20 ++++++++++++++++++++
>>   2 files changed, 46 insertions(+), 2 deletions(-)
> 
> Noooooo this isn't the way we do this.  Simply make a trace class with 
> all the variations, and then add individual trace events that inherit 
> from the class that print out the appropriate values.  Thanks,
> 

I added this mainly to debug the inflight thing. I was kind of not so
successful in finding a relation between latency, queue depth, and
inflight. As it is gone now, I doubt if we still need tracing. I am ok
to drop this. Or we could add when we start digging anything around
this?

Thanks, Anand


> Josef
Josef Bacik Oct. 28, 2020, 12:41 p.m. UTC | #3
On 10/28/20 4:59 AM, Anand Jain wrote:
> On 28/10/20 2:22 am, Josef Bacik wrote:
>> On 10/26/20 7:55 PM, Anand Jain wrote:
>>> This patch adds trace event btrfs_read_policy, which is common to all the
>>> read policies.
>>>
>>> Signed-off-by: Anand Jain <anand.jain@oracle.com>
>>> ---
>>>   fs/btrfs/volumes.c           | 28 ++++++++++++++++++++++++++--
>>>   include/trace/events/btrfs.h | 20 ++++++++++++++++++++
>>>   2 files changed, 46 insertions(+), 2 deletions(-)
>>
>> Noooooo this isn't the way we do this.  Simply make a trace class with all the 
>> variations, and then add individual trace events that inherit from the class 
>> that print out the appropriate values.  Thanks,
>>
> 
> I added this mainly to debug the inflight thing. I was kind of not so
> successful in finding a relation between latency, queue depth, and
> inflight. As it is gone now, I doubt if we still need tracing. I am ok
> to drop this. Or we could add when we start digging anything around
> this?

If you were just using it for debugging then I say we just drop it and add 
something later if we need it.  Thanks,

Josef
diff mbox series

Patch

diff --git a/fs/btrfs/volumes.c b/fs/btrfs/volumes.c
index 9bab6080cebf..b51e690b3b18 100644
--- a/fs/btrfs/volumes.c
+++ b/fs/btrfs/volumes.c
@@ -5494,9 +5494,10 @@  static u64 btrfs_estimate_read(struct btrfs_device *device,
 
 static int btrfs_find_best_stripe(struct btrfs_fs_info *fs_info,
 				  struct map_lookup *map, int first,
-				  int num_stripe)
+				  int num_stripe, char *log, int logsz)
 {
 	int index;
+	int lognr;
 	int best_stripe = 0;
 	int est_wait = -EINVAL;
 	int last = first + num_stripe;
@@ -5509,6 +5510,8 @@  static int btrfs_find_best_stripe(struct btrfs_fs_info *fs_info,
 			return -ENOENT;
 	}
 
+	lognr = scnprintf(log, logsz, ": first %d num_stripe %d [",
+			  first, num_stripe);
 	for (index = first; index < last; index++) {
 		struct btrfs_device *device = map->stripes[index].dev;
 		u64 avg_wait;
@@ -5517,11 +5520,19 @@  static int btrfs_find_best_stripe(struct btrfs_fs_info *fs_info,
 		avg_wait = btrfs_estimate_read(device, &inflight);
 		final_wait = avg_wait + (avg_wait * (inflight / 10));
 
+		lognr = lognr + scnprintf(log + lognr, logsz - lognr,
+		 " stripe %d devid %llu wait %llu inflight %lu final %llu,",
+					  index, device->devid, avg_wait,
+					  inflight, final_wait);
+
 		if (est_wait == 0 || est_wait > final_wait) {
 			est_wait = final_wait;
 			best_stripe = index;
 		}
 	}
+	lognr = lognr + scnprintf(log + lognr, logsz - lognr,
+				  "] best_stripe %d devid %llu", best_stripe,
+				  map->stripes[best_stripe].dev->devid);
 
 	return best_stripe;
 }
@@ -5535,6 +5546,8 @@  static int find_live_mirror(struct btrfs_fs_info *fs_info,
 	int preferred_mirror;
 	int tolerance;
 	struct btrfs_device *srcdev;
+	int logsz = 400;
+	char log[400] = {0};
 
 	ASSERT((map->type &
 		 (BTRFS_BLOCK_GROUP_RAID1_MASK | BTRFS_BLOCK_GROUP_RAID10)));
@@ -5557,7 +5570,8 @@  static int find_live_mirror(struct btrfs_fs_info *fs_info,
 		break;
 	case BTRFS_READ_POLICY_LATENCY:
 		preferred_mirror = btrfs_find_best_stripe(fs_info, map, first,
-							  num_stripes);
+							  num_stripes, log,
+							  logsz);
 		if (preferred_mirror >= 0)
 			break;
 
@@ -5567,9 +5581,19 @@  static int find_live_mirror(struct btrfs_fs_info *fs_info,
 		fallthrough;
 	case BTRFS_READ_POLICY_PID:
 		preferred_mirror = first + current->pid % num_stripes;
+		scnprintf(log, logsz,
+			  "first %d num_stripe %d %s (%d) preferred %d",
+			  first, num_stripes, current->comm, task_pid_nr(current),
+			  preferred_mirror);
 		break;
 	}
 
+	/*
+	 * we could enhance tracing to trace other policies as well, so please
+	 * keep this in the parent function.
+	 */
+	trace_btrfs_read_policy(fs_info, log);
+
 	if (dev_replace_is_ongoing &&
 	    fs_info->dev_replace.cont_reading_from_srcdev_mode ==
 	     BTRFS_DEV_REPLACE_ITEM_CONT_READING_FROM_SRCDEV_MODE_AVOID)
diff --git a/include/trace/events/btrfs.h b/include/trace/events/btrfs.h
index ecd24c719de4..8df7e7d0b336 100644
--- a/include/trace/events/btrfs.h
+++ b/include/trace/events/btrfs.h
@@ -2148,6 +2148,26 @@  DEFINE_EVENT(btrfs__space_info_update, update_bytes_pinned,
 	TP_ARGS(fs_info, sinfo, old, diff)
 );
 
+TRACE_EVENT(btrfs_read_policy,
+
+	TP_PROTO(const struct btrfs_fs_info *fs_info, const char *log),
+
+	TP_ARGS(fs_info, log),
+
+	TP_STRUCT__entry_btrfs(
+		__string(	log,	log		)
+		__field(	int,	read_policy	)
+	),
+
+	TP_fast_assign_btrfs(fs_info,
+		__assign_str(log, log);
+		__entry->read_policy	= fs_info->fs_devices->read_policy;
+	),
+
+	TP_printk_btrfs("read_policy %d %s",
+			__entry->read_policy, __get_str(log))
+);
+
 #endif /* _TRACE_BTRFS_H */
 
 /* This part must be outside protection */