tracing: Add linear buckets to histogram logic

There's been several times I wished the histogram logic had a "grouping"
feature for the buckets. Currently, each bucket has a size of one. That
is, if you trace the amount of requested allocations, each allocation is
its own bucket, even if you are interested in what allocates 100 bytes or
less, 100 to 200, 200 to 300, etc.

Also, without grouping, it fills up the allocated histogram buckets
quickly. If you are tracking latency, and don't care if something is 200
microseconds off, or 201 microseconds off, but want to track them by say
10 microseconds each. This can not currently be done.

There is a log2 but that grouping get's too big too fast for a lot of
cases.

Introduce a "buckets=SIZE" command to each field where it will record in a
rounded number. For example:

># echo 'hist:keys=bytes_req.buckets=100:sort=bytes_req' > events/kmem/kmalloc/trigger
># cat events/kmem/kmalloc/hist
# event histogram
#
# trigger info:
hist:keys=bytes_req.buckets=100:vals=hitcount:sort=bytes_req.buckets=100:size=2048
[active]
#

{ bytes_req: ~ 0-99 } hitcount: 3149
{ bytes_req: ~ 100-199 } hitcount: 1468
{ bytes_req: ~ 200-299 } hitcount: 39
{ bytes_req: ~ 300-399 } hitcount: 306
{ bytes_req: ~ 400-499 } hitcount: 364
{ bytes_req: ~ 500-599 } hitcount: 32
{ bytes_req: ~ 600-699 } hitcount: 69
{ bytes_req: ~ 700-799 } hitcount: 37
{ bytes_req: ~ 1200-1299 } hitcount: 16
{ bytes_req: ~ 1400-1499 } hitcount: 30
{ bytes_req: ~ 2000-2099 } hitcount: 6
{ bytes_req: ~ 4000-4099 } hitcount: 2168
{ bytes_req: ~ 5000-5099 } hitcount: 6

Totals:
Hits: 7690
Entries: 13
Dropped: 0

Link: https://lkml.kernel.org/r/20210707213921.980359719@goodmis.org

Acked-by: Namhyung Kim <namhyung@kernel.org>
Reviewed-by: Tom Zanussi <zanussi@kernel.org>
Reviewed-by: Masami Hiramatsu <mhiramat@kernel.org>
Tested-by: Daniel Bristot de Oliveira <bristot@kernel.org>
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>

Steven Rostedt (VMware) 4 years ago de9a48a3 6fe7c745

+58 -7

1 changed file

expand all

kernel

trace

trace_events_hist.c

+58 -7

kernel/trace/trace_events_hist.c

··· 121 121 unsigned int size; 122 122 unsigned int offset; 123 123 unsigned int is_signed; 124 + unsigned long buckets; 124 125 const char *type; 125 126 struct hist_field *operands[HIST_FIELD_OPERANDS_MAX]; 126 127 struct hist_trigger_data *hist_data; ··· 218 217 u64 val = operand->fn(operand, elt, buffer, rbe, event); 219 218 220 219 return (u64) ilog2(roundup_pow_of_two(val)); 220 + } 221 + 222 + static u64 hist_field_bucket(struct hist_field *hist_field, 223 + struct tracing_map_elt *elt, 224 + struct trace_buffer *buffer, 225 + struct ring_buffer_event *rbe, 226 + void *event) 227 + { 228 + struct hist_field *operand = hist_field->operands[0]; 229 + unsigned long buckets = hist_field->buckets; 230 + 231 + u64 val = operand->fn(operand, elt, buffer, rbe, event); 232 + 233 + if (WARN_ON_ONCE(!buckets)) 234 + return val; 235 + 236 + if (val >= LONG_MAX) 237 + val = div64_ul(val, buckets); 238 + else 239 + val = (u64)((unsigned long)val / buckets); 240 + return val * buckets; 221 241 } 222 242 223 243 static u64 hist_field_plus(struct hist_field *hist_field, ··· 340 318 HIST_FIELD_FL_VAR_REF = 1 << 14, 341 319 HIST_FIELD_FL_CPU = 1 << 15, 342 320 HIST_FIELD_FL_ALIAS = 1 << 16, 321 + HIST_FIELD_FL_BUCKET = 1 << 17, 343 322 }; 344 323 345 324 struct var_defs { ··· 1132 1109 if (field->field) 1133 1110 field_name = field->field->name; 1134 1111 else if (field->flags & HIST_FIELD_FL_LOG2 || 1135 - field->flags & HIST_FIELD_FL_ALIAS) 1112 + field->flags & HIST_FIELD_FL_ALIAS || 1113 + field->flags & HIST_FIELD_FL_BUCKET) 1136 1114 field_name = hist_field_name(field->operands[0], ++level); 1137 1115 else if (field->flags & HIST_FIELD_FL_CPU) 1138 1116 field_name = "common_cpu"; ··· 1494 1470 flags_str = "syscall"; 1495 1471 else if (hist_field->flags & HIST_FIELD_FL_LOG2) 1496 1472 flags_str = "log2"; 1473 + else if (hist_field->flags & HIST_FIELD_FL_BUCKET) 1474 + flags_str = "buckets"; 1497 1475 else if (hist_field->flags & HIST_FIELD_FL_TIMESTAMP_USECS) 1498 1476 flags_str = "usecs"; 1499 1477 ··· 1684 1658 goto out; 1685 1659 } 1686 1660 1687 - if (flags & HIST_FIELD_FL_LOG2) { 1688 - unsigned long fl = flags & ~HIST_FIELD_FL_LOG2; 1689 - hist_field->fn = hist_field_log2; 1661 + if (flags & (HIST_FIELD_FL_LOG2 | HIST_FIELD_FL_BUCKET)) { 1662 + unsigned long fl = flags & ~(HIST_FIELD_FL_LOG2 | HIST_FIELD_FL_BUCKET); 1663 + hist_field->fn = flags & HIST_FIELD_FL_LOG2 ? hist_field_log2 : 1664 + hist_field_bucket; 1690 1665 hist_field->operands[0] = create_hist_field(hist_data, field, fl, NULL); 1691 1666 hist_field->size = hist_field->operands[0]->size; 1692 1667 hist_field->type = kstrdup(hist_field->operands[0]->type, GFP_KERNEL); ··· 1980 1953 1981 1954 static struct ftrace_event_field * 1982 1955 parse_field(struct hist_trigger_data *hist_data, struct trace_event_file *file, 1983 - char *field_str, unsigned long *flags) 1956 + char *field_str, unsigned long *flags, unsigned long *buckets) 1984 1957 { 1985 1958 struct ftrace_event_field *field = NULL; 1986 1959 char *field_name, *modifier, *str; ··· 2007 1980 *flags |= HIST_FIELD_FL_LOG2; 2008 1981 else if (strcmp(modifier, "usecs") == 0) 2009 1982 *flags |= HIST_FIELD_FL_TIMESTAMP_USECS; 2010 - else { 1983 + else if (strncmp(modifier, "bucket", 6) == 0) { 1984 + int ret; 1985 + 1986 + modifier += 6; 1987 + 1988 + if (*modifier == 's') 1989 + modifier++; 1990 + if (*modifier != '=') 1991 + goto error; 1992 + modifier++; 1993 + ret = kstrtoul(modifier, 0, buckets); 1994 + if (ret || !(*buckets)) 1995 + goto error; 1996 + *flags |= HIST_FIELD_FL_BUCKET; 1997 + } else { 1998 + error: 2011 1999 hist_err(tr, HIST_ERR_BAD_FIELD_MODIFIER, errpos(modifier)); 2012 2000 field = ERR_PTR(-EINVAL); 2013 2001 goto out; ··· 2091 2049 char *s, *ref_system = NULL, *ref_event = NULL, *ref_var = str; 2092 2050 struct ftrace_event_field *field = NULL; 2093 2051 struct hist_field *hist_field = NULL; 2052 + unsigned long buckets = 0; 2094 2053 int ret = 0; 2095 2054 2096 2055 s = strchr(str, '.'); ··· 2129 2086 } else 2130 2087 str = s; 2131 2088 2132 - field = parse_field(hist_data, file, str, flags); 2089 + field = parse_field(hist_data, file, str, flags, &buckets); 2133 2090 if (IS_ERR(field)) { 2134 2091 ret = PTR_ERR(field); 2135 2092 goto out; ··· 2140 2097 ret = -ENOMEM; 2141 2098 goto out; 2142 2099 } 2100 + hist_field->buckets = buckets; 2143 2101 2144 2102 return hist_field; 2145 2103 out: ··· 4742 4698 } else if (key_field->flags & HIST_FIELD_FL_LOG2) { 4743 4699 seq_printf(m, "%s: ~ 2^%-2llu", field_name, 4744 4700 *(u64 *)(key + key_field->offset)); 4701 + } else if (key_field->flags & HIST_FIELD_FL_BUCKET) { 4702 + unsigned long buckets = key_field->buckets; 4703 + uval = *(u64 *)(key + key_field->offset); 4704 + seq_printf(m, "%s: ~ %llu-%llu", field_name, 4705 + uval, uval + buckets -1); 4745 4706 } else if (key_field->flags & HIST_FIELD_FL_STRING) { 4746 4707 seq_printf(m, "%s: %-50s", field_name, 4747 4708 (char *)(key + key_field->offset)); ··· 5186 5137 seq_printf(m, ".%s", flags); 5187 5138 } 5188 5139 } 5140 + if (hist_field->buckets) 5141 + seq_printf(m, "=%ld", hist_field->buckets); 5189 5142 } 5190 5143 5191 5144 static int event_hist_trigger_print(struct seq_file *m,

Configure Feed

Configure Feed