uftrace: Increase TID length to 7

On recent distros, the PID is often goes to 7 digits (bigger than 1,000,000). So let's increase the length and update the code to use the TASK_ID_LEN macro. Signed-off-by: Namhyung Kim <[email protected]>
namhyung · May 28, 2024 · b52b0fd · b52b0fd
1 parent a4963f8
commit b52b0fd
Show file tree

Hide file tree

Showing 12 changed files with 54 additions and 48 deletions.
diff --git a/cmds/dump.c b/cmds/dump.c
@@ -601,8 +601,8 @@ static void dump_raw_task_rstack(struct uftrace_dump_ops *ops, struct uftrace_ta
 		name = event_get_name(task->h, frs->addr);
 
 	pr_time(frs->time);
-	pr_out("%5d: [%s] %s(%" PRIx64 ") depth: %u\n", task->tid, rstack_type(frs), name,
-	       frs->addr, frs->depth);
+	pr_out("%*d: [%s] %s(%" PRIx64 ") depth: %u\n", TASK_ID_LEN, task->tid, rstack_type(frs),
+	       name, frs->addr, frs->depth);
 	pr_hex(&raw->file_offset, frs, sizeof(*frs));
 
 	if (frs->type == UFTRACE_EVENT)
@@ -611,13 +611,15 @@ static void dump_raw_task_rstack(struct uftrace_dump_ops *ops, struct uftrace_ta
 	if (frs->more && show_args) {
 		if (frs->type == UFTRACE_ENTRY) {
 			pr_time(frs->time);
-			pr_out("%5d: [%s] length = %d\n", task->tid, "args ", task->args.len);
+			pr_out("%*d: [%s] length = %d\n", TASK_ID_LEN, task->tid, "args ",
+			       task->args.len);
 			pr_args(&task->args);
 			pr_hex(&raw->file_offset, task->args.data, ALIGN(task->args.len, 8));
 		}
 		else if (frs->type == UFTRACE_EXIT) {
 			pr_time(frs->time);
-			pr_out("%5d: [%s] length = %d\n", task->tid, "retval", task->args.len);
+			pr_out("%*d: [%s] length = %d\n", TASK_ID_LEN, task->tid, "retval",
+			       task->args.len);
 			pr_retval(&task->args);
 			pr_hex(&raw->file_offset, task->args.data, ALIGN(task->args.len, 8));
 		}
@@ -633,13 +635,13 @@ static void dump_raw_task_event(struct uftrace_dump_ops *ops, struct uftrace_tas
 	char *name = event_get_name(task->h, frs->addr);
 
 	pr_time(frs->time);
-	pr_out("%5d: [%s] %s(%" PRIx64 ") depth: %u\n", task->tid, rstack_type(frs), name,
-	       frs->addr, frs->depth);
+	pr_out("%*d: [%s] %s(%" PRIx64 ") depth: %u\n", TASK_ID_LEN, task->tid, rstack_type(frs),
+	       name, frs->addr, frs->depth);
 	pr_hex(&raw->file_offset, frs, sizeof(*frs));
 
 	if (frs->more && show_args) {
 		pr_time(frs->time);
-		pr_out("%5d: [%s] length = %d\n", task->tid, "data ", task->args.len);
+		pr_out("%*d: [%s] length = %d\n", TASK_ID_LEN, task->tid, "data ", task->args.len);
 		pr_event(task, frs->addr);
 		pr_hex(&raw->file_offset, task->args.data, ALIGN(task->args.len, 8));
 	}
@@ -692,8 +694,8 @@ static void dump_raw_kernel_rstack(struct uftrace_dump_ops *ops,
 			timestamp = ((uint64_t)upper << 27) + (lower >> 5);
 
 			pr_time(frs->time - timestamp);
-			pr_out("%5d: [%s] %s (+%" PRIu64 " nsec)\n", tid, "time ", "extend",
-			       timestamp);
+			pr_out("%*d: [%s] %s (+%" PRIu64 " nsec)\n", TASK_ID_LEN, tid, "time ",
+			       "extend", timestamp);
 
 			if (debug)
 				pr_hex(&offset, tmp, 8);
@@ -705,8 +707,8 @@ static void dump_raw_kernel_rstack(struct uftrace_dump_ops *ops,
 	}
 
 	pr_time(frs->time);
-	pr_out("%5d: [%s] %s(%" PRIx64 ") depth: %u\n", tid, rstack_type(frs), name, frs->addr,
-	       frs->depth);
+	pr_out("%*d: [%s] %s(%" PRIx64 ") depth: %u\n", TASK_ID_LEN, tid, rstack_type(frs), name,
+	       frs->addr, frs->depth);
 
 	if (debug) {
 		/* this is only needed for hex dump */
@@ -744,7 +746,8 @@ static void dump_raw_kernel_event(struct uftrace_dump_ops *ops,
 	event_data = read_kernel_event(kernel, cpu, &size);
 
 	pr_time(frs->time);
-	pr_out("%5d: [%s] %s(%ld) %.*s\n", tid, rstack_type(frs), buf, frs->addr, size, event_data);
+	pr_out("%*d: [%s] %s(%ld) %.*s\n", TASK_ID_LEN, tid, rstack_type(frs), buf, frs->addr, size,
+	       event_data);
 
 	if (debug) {
 		/* this is only needed for hex dump */
@@ -765,7 +768,7 @@ static void dump_raw_kernel_event(struct uftrace_dump_ops *ops,
 static void dump_raw_kernel_lost(struct uftrace_dump_ops *ops, uint64_t time, int tid, int losts)
 {
 	pr_time(time);
-	pr_red("%5d: [%s ]: %d events\n", tid, "lost", losts);
+	pr_red("%*d: [%s ]: %d events\n", TASK_ID_LEN, tid, "lost", losts);
 }
 
 static void dump_raw_perf_start(struct uftrace_dump_ops *ops, struct uftrace_perf_reader *perf,
@@ -788,7 +791,8 @@ static void dump_raw_perf_event(struct uftrace_dump_ops *ops, struct uftrace_per
 	char *evt_name = event_get_name(NULL, frs->addr);
 
 	pr_time(frs->time);
-	pr_out("%5d: [%s] %s(%" PRIu64 ")\n", perf->tid, rstack_type(frs), evt_name, frs->addr);
+	pr_out("%*d: [%s] %s(%" PRIu64 ")\n", TASK_ID_LEN, perf->tid, rstack_type(frs), evt_name,
+	       frs->addr);
 
 	if (debug) {
 		/* XXX: this is different from file contents */

diff --git a/cmds/graph.c b/cmds/graph.c
@@ -128,7 +128,7 @@ static void print_task_self_time(struct field_data *fd)
 static void print_task_tid(struct field_data *fd)
 {
 	struct uftrace_task *task = fd->arg;
-	pr_out("[%6d]", task->tid);
+	pr_out("[%*d]", TASK_ID_LEN, task->tid);
 }
 
 static struct display_field field_task_total_time = {
@@ -154,8 +154,8 @@ static struct display_field field_task_self_time = {
 static struct display_field field_task_tid = {
 	.id = GRAPH_F_TASK_TID,
 	.name = "tid",
-	.header = "   TID  ",
-	.length = 8,
+	.header = "   TID   ",
+	.length = TASK_ID_LEN + 2, /* +2 for "[ ]" */
 	.print = print_task_tid,
 	.list = LIST_HEAD_INIT(field_task_tid.list),
 };

diff --git a/cmds/info.c b/cmds/info.c
@@ -1215,7 +1215,7 @@ static void print_task(struct uftrace_data *handle, struct uftrace_task *t)
 	/* TIMESTAMP */
 	pr_out(" %13lu.%09lu ", t->time.stamp / NSEC_PER_SEC, t->time.stamp % NSEC_PER_SEC);
 	/* FLAGS  TID  COMM */
-	pr_out(" %s  [%6d]  %-16s ", flags, t->tid, t->comm);
+	pr_out(" %s  [%*d]  %-16s ", flags, TASK_ID_LEN, t->tid, t->comm);
 	/* DATA SIZE */
 	if (stbuf.st_size) {
 		uint64_t size_kb = stbuf.st_size / 1024;
@@ -1235,8 +1235,8 @@ static void print_task_info(struct uftrace_data *handle)
 	struct rb_node *n;
 	struct uftrace_task *t;
 
-	pr_out("#%23s  %5s  %8s  %-16s  %s\n", "TIMESTAMP     ", "FLAGS", "  TID  ", "TASK",
-	       "DATA SIZE");
+	pr_out("#%23s  %5s  %*s  %-16s  %s\n", "TIMESTAMP     ", "FLAGS", TASK_ID_LEN + 2,
+	       "   TID   ", "TASK", "DATA SIZE");
 
 	n = rb_first(&handle->sessions.tasks);
 	while (n != NULL) {

diff --git a/cmds/replay.c b/cmds/replay.c
@@ -38,7 +38,7 @@ static void print_duration(struct field_data *fd)
 static void print_tid(struct field_data *fd)
 {
 	struct uftrace_task_reader *task = fd->task;
-	pr_out("[%6d]", task->tid);
+	pr_out("[%*d]", TASK_ID_LEN, task->tid);
 }
 
 static void print_addr(struct field_data *fd)
@@ -87,7 +87,8 @@ static void print_task(struct field_data *fd)
 {
 	struct uftrace_task_reader *task = fd->task;
 
-	pr_out("%*s", 15, task->t->comm);
+	/* The task (command) name contains NUL at the end */
+	pr_out("%*s", TASK_COMM_LEN - 1, task->t->comm);
 }
 
 static void print_module(struct field_data *fd)
@@ -131,8 +132,8 @@ static struct display_field field_duration = {
 static struct display_field field_tid = {
 	.id = REPLAY_F_TID,
 	.name = "tid",
-	.header = "   TID  ",
-	.length = 8,
+	.header = "   TID   ",
+	.length = TASK_ID_LEN + 2, /* +2 for "[ ]" */
 	.print = print_tid,
 	.list = LIST_HEAD_INIT(field_tid.list),
 };
@@ -182,7 +183,7 @@ static struct display_field field_task = {
 	.id = REPLAY_F_TASK,
 	.name = "task",
 	.header = "      TASK NAME",
-	.length = 15,
+	.length = TASK_COMM_LEN - 1, /* -1 due to NUL at the end */
 	.print = print_task,
 	.list = LIST_HEAD_INIT(field_task.list),
 };

diff --git a/cmds/report.c b/cmds/report.c
@@ -361,7 +361,7 @@ static void print_task(struct uftrace_report_node *node, void *arg, int space)
 	print_field(node, space);
 
 	pr_out("%*s", space, " ");
-	pr_out("%-16s\n", t->comm);
+	pr_out("%-*s\n", TASK_COMM_LEN, t->comm);
 }
 
 static void report_task(struct uftrace_data *handle, struct uftrace_opts *opts)

diff --git a/scripts/dump.lua b/scripts/dump.lua
@@ -20,7 +20,7 @@ function uftrace_entry(ctx)
     local _name       = ctx['name']
 
     local unit = 1000000000
-    print(string.format('%d.%09d %6d: [entry] %s(%x) depth: %d',
+    print(string.format('%d.%09d %7d: [entry] %s(%x) depth: %d',
             _time / unit, _time % unit, _tid, _name, _address, _depth))
 
     if ctx['args'] ~= nil then
@@ -39,7 +39,7 @@ function uftrace_exit(ctx)
     local _name       = ctx["name"]
 
     local unit = 1000000000
-    print(string.format('%d.%09d %6d: [exit ] %s(%x) depth: %d',
+    print(string.format('%d.%09d %7d: [exit ] %s(%x) depth: %d',
             _time / unit, _time % unit, _tid, _name, _address, _depth))
 
     if ctx['retval'] ~= nil then
@@ -55,7 +55,7 @@ function uftrace_event(ctx)
     local _name       = ctx["name"]
 
     local unit = 1000000000
-    print(string.format('%d.%09d %6d: [event] %s(%x)',
+    print(string.format('%d.%09d %7d: [event] %s(%x)',
             _time / unit, _time % unit, _tid, _name, _address))
 end
 

diff --git a/scripts/dump.py b/scripts/dump.py
@@ -28,7 +28,7 @@ def uftrace_entry(ctx):
     _name       = ctx["name"]
 
     unit = 10 ** 9
-    print("%d.%09d %6d: [entry] %s(%x) depth: %d" %
+    print("%d.%09d %7d: [entry] %s(%x) depth: %d" %
             (_time / unit, _time % unit, _tid, _name, _address, _depth))
 
     if "args" in ctx:
@@ -47,7 +47,7 @@ def uftrace_exit(ctx):
     _name       = ctx["name"]
 
     unit = 10 ** 9
-    print("%d.%09d %6d: [exit ] %s(%x) depth: %d" %
+    print("%d.%09d %7d: [exit ] %s(%x) depth: %d" %
             (_time / unit, _time % unit, _tid, _name, _address, _depth))
 
     if "retval" in ctx:
@@ -62,7 +62,7 @@ def uftrace_event(ctx):
     _name       = ctx["name"]
 
     unit = 10 ** 9
-    print("%d.%09d %6d: [event] %s(%x)" %
+    print("%d.%09d %7d: [event] %s(%x)" %
             (_time / unit, _time % unit, _tid, _name, _address))
 
 # uftrace_end is optional, so can be omitted.

diff --git a/scripts/replay.lua b/scripts/replay.lua
@@ -10,7 +10,7 @@ function uftrace_entry(ctx)
     local indent = _depth * 2
     local space = string.rep(' ', indent)
 
-    local buf = string.format(' %10s [%6d] | %s%s() {', '', _tid, space, _symname)
+    local buf = string.format(' %10s [%7d] | %s%s() {', '', _tid, space, _symname)
     print(buf)
 end
 
@@ -26,7 +26,7 @@ function uftrace_exit(ctx)
     local time_and_unit = get_time_and_unit(_duration)
     local time = time_and_unit[1]
     local unit = time_and_unit[2]
-    local buf = string.format(' %7.3f %s [%6d] | %s}', time, unit, _tid, space)
+    local buf = string.format(' %7.3f %s [%7d] | %s}', time, unit, _tid, space)
     local buf = string.format('%s /* %s */', buf, _symname)
     print(buf)
 end

diff --git a/scripts/replay.py b/scripts/replay.py
@@ -10,7 +10,7 @@ def uftrace_entry(ctx):
     indent = _depth * 2
     space = " " * indent
 
-    buf = " %10s [%6d] | %s%s() {" % ("", _tid, space, _symname)
+    buf = " %10s [%7d] | %s%s() {" % ("", _tid, space, _symname)
     print(buf)
 
 def uftrace_exit(ctx):
@@ -24,7 +24,7 @@ def uftrace_exit(ctx):
     space = " " * indent
 
     (time, unit) = get_time_and_unit(_duration)
-    buf = " %7.3f %s [%6d] | %s}" % (time, unit, _tid, space)
+    buf = " %7.3f %s [%7d] | %s}" % (time, unit, _tid, space)
     buf = "%s /* %s */" % (buf, _symname)
     print(buf)
 

diff --git a/uftrace.h b/uftrace.h
@@ -357,6 +357,7 @@ void put_libmcount_path(char *libpath);
 #define SESSION_ID_LEN 16
 #define TASK_COMM_LEN 16
 #define TASK_COMM_LAST (TASK_COMM_LEN - 1)
+#define TASK_ID_LEN 7
 
 struct uftrace_session {
 	struct rb_node node;

diff --git a/utils/fstack.c b/utils/fstack.c
@@ -610,8 +610,8 @@ int fstack_entry(struct uftrace_task_reader *task, struct uftrace_record *rstack
 	if (fstack == NULL)
 		return -1;
 
-	pr_dbg2("ENTRY: [%5d] stack: %d, depth: %d, disp: %d, I: %d, O: %d, D: %d, flags = %lx %s\n",
-		task->tid, task->stack_count - 1, rstack->depth, task->display_depth,
+	pr_dbg2("ENTRY: [%*d] stack: %d, depth: %d, disp: %d, I: %d, O: %d, D: %d, flags = %lx %s\n",
+		TASK_ID_LEN, task->tid, task->stack_count - 1, rstack->depth, task->display_depth,
 		task->filter.in_count, task->filter.out_count, task->filter.depth, fstack->flags,
 		rstack->more ? "more" : "");
 
@@ -740,8 +740,8 @@ void fstack_exit(struct uftrace_task_reader *task)
 	if (fstack == NULL)
 		return;
 
-	pr_dbg2("EXIT : [%5d] stack: %d, depth: %d, disp: %d, I: %d, O: %d, D: %d, flags = %lx\n",
-		task->tid, task->stack_count, task->rstack->depth, task->display_depth,
+	pr_dbg2("EXIT : [%*d] stack: %d, depth: %d, disp: %d, I: %d, O: %d, D: %d, flags = %lx\n",
+		TASK_ID_LEN, task->tid, task->stack_count, task->rstack->depth, task->display_depth,
 		task->filter.in_count, task->filter.out_count, task->filter.depth, fstack->flags);
 
 	if (fstack->flags & FSTACK_FL_FILTERED)
@@ -1021,10 +1021,10 @@ bool fstack_check_filter(struct uftrace_task_reader *task)
 			if (fstack == NULL)
 				return false;
 
-			pr_dbg2("SCHED: [%5d] stack: %d, depth: %d, disp: %d, I: %d, O: %d, D: %d, %s\n",
-				task->tid, idx, fstack->orig_depth, task->display_depth,
-				task->filter.in_count, task->filter.out_count, task->filter.depth,
-				sched);
+			pr_dbg2("SCHED: [%*d] stack: %d, depth: %d, disp: %d, I: %d, O: %d, D: %d, %s\n",
+				TASK_ID_LEN, task->tid, idx, fstack->orig_depth,
+				task->display_depth, task->filter.in_count, task->filter.out_count,
+				task->filter.depth, sched);
 		}
 	}
 
@@ -2237,7 +2237,7 @@ static void adjust_rstack_after_schedule(struct uftrace_data *handle,
 			task->timestamp_next -= prev_fstack->total_time;
 		}
 
-		pr_dbg3("task[%6d] delay next record after schedule\n", task->tid);
+		pr_dbg3("task[%*d] delay next record after schedule\n", TASK_ID_LEN, task->tid);
 		next_rec->time = ~0ULL;
 		return;
 	}
@@ -2253,7 +2253,7 @@ static void adjust_rstack_after_schedule(struct uftrace_data *handle,
 	/* save it in case it's overwritten by subsequent schedule */
 	task->timestamp_estimate = next_rec->time;
 
-	pr_dbg3("task[%6d] estimate next record after schedule\n", task->tid);
+	pr_dbg3("task[%*d] estimate next record after schedule\n", TASK_ID_LEN, task->tid);
 }
 
 static int __read_rstack(struct uftrace_data *handle, struct uftrace_task_reader **taskp,

diff --git a/utils/report.c b/utils/report.c
@@ -851,9 +851,9 @@ void report_sort_tasks(struct uftrace_data *handle, struct rb_root *name_root,
 	static void print_##_func(struct field_data *fd)                                           \
 	{                                                                                          \
 		struct uftrace_report_node *node = fd->arg;                                        \
-		pr_out("%6d", strtol(node->name, NULL, 10));                                       \
+		pr_out("%*d", TASK_ID_LEN, strtol(node->name, NULL, 10));                          \
 	}                                                                                          \
-	FIELD_STRUCT(_id, _name, _func, _header, 6)
+	FIELD_STRUCT(_id, _name, _func, _header, TASK_ID_LEN)
 
 #define NODATA "-"
 static void print_time_or_dash(uint64_t time_nsec)