Skip to content

Commit

Permalink
tracing: Make the space reserved for the pid wider
Browse files Browse the repository at this point in the history 
For 64bit CONFIG_BASE_SMALL=0 systems PID_MAX_LIMIT is set by default to
4194304. During boot the kernel sets a new value based on number of CPUs
but no lower than 32768. It is 1024 per CPU so with 128 CPUs the default
becomes 131072 which needs six digits.
This value can be increased during run time but must not exceed the
initial upper limit.

Systemd sometime after v241 sets it to the upper limit during boot. The
result is that when the pid exceeds five digits, the trace output is a
little hard to read because it is no longer properly padded (same like
on big iron with 98+ CPUs).

Increase the pid padding to seven digits.

Link: https://lkml.kernel.org/r/[email protected]

Signed-off-by: Sebastian Andrzej Siewior <[email protected]>
Signed-off-by: Steven Rostedt (VMware) <[email protected]>
  • Loading branch information
@rostedt
Sebastian Andrzej Siewior authored and rostedt committed Sep 18, 2020
1 parent 478ece9 commit 795d637
Show file tree
Hide file tree
Showing 2 changed files with 25 additions and 25 deletions.
38 changes: 19 additions & 19 deletions kernel/trace/trace.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3782,14 +3782,14 @@ unsigned long trace_total_entries(struct trace_array *tr)

static void print_lat_help_header(struct seq_file *m)
{
seq_puts(m, "# _------=> CPU# \n"
"# / _-----=> irqs-off \n"
"# | / _----=> need-resched \n"
"# || / _---=> hardirq/softirq \n"
"# ||| / _--=> preempt-depth \n"
"# |||| / delay \n"
"# cmd pid ||||| time | caller \n"
"# \\ / ||||| \\ | / \n");
seq_puts(m, "# _------=> CPU# \n"
"# / _-----=> irqs-off \n"
"# | / _----=> need-resched \n"
"# || / _---=> hardirq/softirq \n"
"# ||| / _--=> preempt-depth \n"
"# |||| / delay \n"
"# cmd pid ||||| time | caller \n"
"# \\ / ||||| \\ | / \n");
}

static void print_event_info(struct array_buffer *buf, struct seq_file *m)
Expand All @@ -3810,26 +3810,26 @@ static void print_func_help_header(struct array_buffer *buf, struct seq_file *m,

print_event_info(buf, m);

seq_printf(m, "# TASK-PID %s CPU# TIMESTAMP FUNCTION\n", tgid ? "TGID " : "");
seq_printf(m, "# | | %s | | |\n", tgid ? " | " : "");
seq_printf(m, "# TASK-PID %s CPU# TIMESTAMP FUNCTION\n", tgid ? " TGID " : "");
seq_printf(m, "# | | %s | | |\n", tgid ? " | " : "");
}

static void print_func_help_header_irq(struct array_buffer *buf, struct seq_file *m,
unsigned int flags)
{
bool tgid = flags & TRACE_ITER_RECORD_TGID;
const char *space = " ";
int prec = tgid ? 10 : 2;
const char *space = " ";
int prec = tgid ? 12 : 2;

print_event_info(buf, m);

seq_printf(m, "# %.*s _-----=> irqs-off\n", prec, space);
seq_printf(m, "# %.*s / _----=> need-resched\n", prec, space);
seq_printf(m, "# %.*s| / _---=> hardirq/softirq\n", prec, space);
seq_printf(m, "# %.*s|| / _--=> preempt-depth\n", prec, space);
seq_printf(m, "# %.*s||| / delay\n", prec, space);
seq_printf(m, "# TASK-PID %.*sCPU# |||| TIMESTAMP FUNCTION\n", prec, " TGID ");
seq_printf(m, "# | | %.*s | |||| | |\n", prec, " | ");
seq_printf(m, "# %.*s _-----=> irqs-off\n", prec, space);
seq_printf(m, "# %.*s / _----=> need-resched\n", prec, space);
seq_printf(m, "# %.*s| / _---=> hardirq/softirq\n", prec, space);
seq_printf(m, "# %.*s|| / _--=> preempt-depth\n", prec, space);
seq_printf(m, "# %.*s||| / delay\n", prec, space);
seq_printf(m, "# TASK-PID %.*s CPU# |||| TIMESTAMP FUNCTION\n", prec, " TGID ");
seq_printf(m, "# | | %.*s | |||| | |\n", prec, " | ");
}

void
Expand Down
12 changes: 6 additions & 6 deletions kernel/trace/trace_output.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -497,7 +497,7 @@ lat_print_generic(struct trace_seq *s, struct trace_entry *entry, int cpu)

trace_find_cmdline(entry->pid, comm);

trace_seq_printf(s, "%8.8s-%-5d %3d",
trace_seq_printf(s, "%8.8s-%-7d %3d",
comm, entry->pid, cpu);

return trace_print_lat_fmt(s, entry);
Expand Down Expand Up @@ -588,15 +588,15 @@ int trace_print_context(struct trace_iterator *iter)

trace_find_cmdline(entry->pid, comm);

trace_seq_printf(s, "%16s-%-5d ", comm, entry->pid);
trace_seq_printf(s, "%16s-%-7d ", comm, entry->pid);

if (tr->trace_flags & TRACE_ITER_RECORD_TGID) {
unsigned int tgid = trace_find_tgid(entry->pid);

if (!tgid)
trace_seq_printf(s, "(-----) ");
trace_seq_printf(s, "(-------) ");
else
trace_seq_printf(s, "(%5d) ", tgid);
trace_seq_printf(s, "(%7d) ", tgid);
}

trace_seq_printf(s, "[%03d] ", iter->cpu);
Expand Down Expand Up @@ -636,7 +636,7 @@ int trace_print_lat_context(struct trace_iterator *iter)
trace_find_cmdline(entry->pid, comm);

trace_seq_printf(
s, "%16s %5d %3d %d %08x %08lx ",
s, "%16s %7d %3d %d %08x %08lx ",
comm, entry->pid, iter->cpu, entry->flags,
entry->preempt_count, iter->idx);
} else {
Expand Down Expand Up @@ -917,7 +917,7 @@ static enum print_line_t trace_ctxwake_print(struct trace_iterator *iter,
S = task_index_to_char(field->prev_state);
trace_find_cmdline(field->next_pid, comm);
trace_seq_printf(&iter->seq,
" %5d:%3d:%c %s [%03d] %5d:%3d:%c %s\n",
" %7d:%3d:%c %s [%03d] %7d:%3d:%c %s\n",
field->prev_pid,
field->prev_prio,
S, delim,
Expand Down

0 comments on commit 795d637

Please sign in to comment.