hardirqs: Optimize output information and increase CPU display (#5228)

Combine the previous count and time into one,
and increase CPU independent statistics and maximum interrupt time

Before:
./hardirqs
Tracing hard irq event time... Hit Ctrl-C to end.
^C
HARDIRQ                    TOTAL_usecs
enp0s3                             254
snd_intel8x0                       368

./hardirqs -C
Tracing hard irq events... Hit Ctrl-C to end.
^C
HARDIRQ                    TOTAL_count
enp0s3                              14
ata_piix                             2

After:
./hardirqs
Tracing hard irq event time... Hit Ctrl-C to end.
^C
HARDIRQ                   TOTAL_count TOTAL_usecs MAX_usecs
ata_piix                            2          32        21
enp0s3                             19         318        42

./hardirqs -C
Tracing hard irq event time... Hit Ctrl-C to end.
^C
HARDIRQ                   TOTAL_count TOTAL_usecs MAX_usecs CPU
enp0s3                         111375     1420732       303   2
enp0s3                           1546       21826        39   9
ata_piix                            8         162        33   8

Signed-off-by: Feng Yang <[email protected]>

Author: kknjh

libbpf-tools/hardirqs.bpf.c

@@ -13,7 +13,7 @@
 const volatile bool filter_cg = false;
 const volatile bool targ_dist = false;
 const volatile bool targ_ns = false;
-const volatile bool do_count = false;
+const volatile bool cpu = false;
 const volatile int targ_cpu = -1;
 
 struct {
@@ -53,26 +53,12 @@ static int handle_entry(int irq, struct irqaction *action)
 	if (!is_target_cpu())
 		return 0;
 
-	if (do_count) {
-		struct irq_key key = {};
-		struct info *info;
-
-		bpf_probe_read_kernel_str(&key.name, sizeof(key.name), BPF_CORE_READ(action, name));
-		info = bpf_map_lookup_or_try_init(&infos, &key, &zero);
-		if (!info)
-			return 0;
-		info->count += 1;
-		return 0;
-	} else {
-		u64 ts = bpf_ktime_get_ns();
-		u32 key = 0;
+	u64 ts = bpf_ktime_get_ns();
+	u32 key = 0;
 
-		if (filter_cg && !bpf_current_task_under_cgroup(&cgroup_map, 0))
-			return 0;
+	bpf_map_update_elem(&start, &key, &ts, BPF_ANY);
 
-		bpf_map_update_elem(&start, &key, &ts, BPF_ANY);
-		return 0;
-	}
+	return 0;
 }
 
 static int handle_exit(int irq, struct irqaction *action)
@@ -98,12 +84,18 @@ static int handle_exit(int irq, struct irqaction *action)
 		delta /= 1000U;
 
 	bpf_probe_read_kernel_str(&ikey.name, sizeof(ikey.name), BPF_CORE_READ(action, name));
+	if (cpu)
+		ikey.cpu = bpf_get_smp_processor_id();
 	info = bpf_map_lookup_or_try_init(&infos, &ikey, &zero);
 	if (!info)
 		return 0;
 
+	info->count += 1;
+
 	if (!targ_dist) {
-		info->count += delta;
+		info->total_time += delta;
+		if (delta > info->max_time)
+			info->max_time = delta;
 	} else {
 		u64 slot;
 

libbpf-tools/hardirqs.c

@@ -18,7 +18,7 @@
 #include "trace_helpers.h"
 
 struct env {
-	bool count;
+	bool cpu;
 	bool distributed;
 	bool nanoseconds;
 	time_t interval;
@@ -42,18 +42,19 @@ const char *argp_program_bug_address =
 const char argp_program_doc[] =
 "Summarize hard irq event time as histograms.\n"
 "\n"
-"USAGE: hardirqs [--help] [-T] [-N] [-d] [interval] [count] [-c CG]\n"
+"USAGE: hardirqs [--help] [-T] [-N] [-d] [-C] [interval] [count] [-c CG]\n"
 "\n"
 "EXAMPLES:\n"
 "    hardirqs            # sum hard irq event time\n"
 "    hardirqs -d         # show hard irq event time as histograms\n"
 "    hardirqs 1 10       # print 1 second summaries, 10 times\n"
 "    hardirqs -c CG      # Trace process under cgroupsPath CG\n"
 "    hardirqs --cpu 1    # only stat irq on cpu 1\n"
+"    hardirqs -C         # display separately by CPU\n"
 "    hardirqs -NT 1      # 1s summaries, nanoseconds, and timestamps\n";
 
 static const struct argp_option opts[] = {
-	{ "count", 'C', NULL, 0, "Show event counts instead of timing", 0 },
+	{ "CPU", 'C', NULL, 0, "Display separately by CPU", 0 },
 	{ "distributed", 'd', NULL, 0, "Show distributions as histograms", 0 },
 	{ "cgroup", 'c', "/sys/fs/cgroup/unified", 0, "Trace process in cgroup path", 0 },
 	{ "cpu", 's', "CPU", 0, "Only stat irq on selected cpu", 0 },
@@ -79,7 +80,7 @@ static error_t parse_arg(int key, char *arg, struct argp_state *state)
 		env.distributed = true;
 		break;
 	case 'C':
-		env.count = true;
+		env.cpu = true;
 		break;
 	case 's':
 		errno = 0;
@@ -142,14 +143,16 @@ static int print_map(struct bpf_map *map)
 {
 	struct irq_key lookup_key = {}, next_key;
 	struct info info;
+	const char *units = env.nanoseconds ? "nsecs" : "usecs";
 	int fd, err;
 
-	if (env.count) {
-		printf("%-26s %11s\n", "HARDIRQ", "TOTAL_count");
-	} else if (!env.distributed) {
-		const char *units = env.nanoseconds ? "nsecs" : "usecs";
-
-		printf("%-26s %6s%5s\n", "HARDIRQ", "TOTAL_", units);
+	if (!env.distributed) {
+		printf("%-33s %11s %6s%5s %4s%5s", "HARDIRQ", "TOTAL_count",
+			"TOTAL_", units, "MAX_", units);
+		if (env.cpu)
+			printf(" %3s\n", "CPU");
+		else
+			printf("\n");
 	}
 
 	fd = bpf_map__fd(map);
@@ -160,10 +163,15 @@ static int print_map(struct bpf_map *map)
 			return -1;
 		}
 		if (!env.distributed)
-			printf("%-26s %11llu\n", next_key.name, info.count);
+			if (env.cpu)
+				printf("%-33s %11llu %11llu %9llu %3u\n", next_key.name,
+				       info.count, info.total_time, info.max_time, next_key.cpu);
+			else
+				printf("%-33s %11llu %11llu %9llu\n", next_key.name,
+				       info.count, info.total_time, info.max_time);
 		else {
-			const char *units = env.nanoseconds ? "nsecs" : "usecs";
-
+			if (env.cpu)
+				printf("cpu = %u ", next_key.cpu);
 			printf("hardirq = %s\n", next_key.name);
 			print_log2_hist(info.slots, MAX_SLOTS, units);
 		}
@@ -203,11 +211,6 @@ int main(int argc, char **argv)
 	if (err)
 		return err;
 
-	if (env.count && env.distributed) {
-		fprintf(stderr, "count, distributed cann't be used together.\n");
-		return 1;
-	}
-
 	libbpf_set_print(libbpf_print_fn);
 
 	obj = hardirqs_bpf__open();
@@ -219,24 +222,17 @@ int main(int argc, char **argv)
 	if (probe_tp_btf("irq_handler_entry")) {
 		bpf_program__set_autoload(obj->progs.irq_handler_entry, false);
 		bpf_program__set_autoload(obj->progs.irq_handler_exit, false);
-		if (env.count)
-			bpf_program__set_autoload(obj->progs.irq_handler_exit_btf, false);
 	} else {
 		bpf_program__set_autoload(obj->progs.irq_handler_entry_btf, false);
 		bpf_program__set_autoload(obj->progs.irq_handler_exit_btf, false);
-		if (env.count)
-			bpf_program__set_autoload(obj->progs.irq_handler_exit, false);
 	}
 
+	/* initialize global data (filtering options) */
 	obj->rodata->filter_cg = env.cg;
-	obj->rodata->do_count = env.count;
+	obj->rodata->cpu = env.cpu;
 	obj->rodata->targ_cpu = env.targ_cpu;
-
-	/* initialize global data (filtering options) */
-	if (!env.count) {
-		obj->rodata->targ_dist = env.distributed;
-		obj->rodata->targ_ns = env.nanoseconds;
-	}
+	obj->rodata->targ_dist = env.distributed;
+	obj->rodata->targ_ns = env.nanoseconds;
 
 	err = hardirqs_bpf__load(obj);
 	if (err) {
@@ -267,10 +263,7 @@ int main(int argc, char **argv)
 
 	signal(SIGINT, sig_handler);
 
-	if (env.count)
-		printf("Tracing hard irq events... Hit Ctrl-C to end.\n");
-	else
-		printf("Tracing hard irq event time... Hit Ctrl-C to end.\n");
+	printf("Tracing hard irq event time... Hit Ctrl-C to end.\n");
 
 	/* main: poll */
 	while (1) {

libbpf-tools/hardirqs.h

@@ -6,10 +6,13 @@
 
 struct irq_key {
 	char name[32];
+	__u32 cpu;
 };
 
 struct info {
 	__u64 count;
+	__u64 total_time;
+	__u64 max_time;
 	__u32 slots[MAX_SLOTS];
 };