[PATCH] tracing: don't macro-expand arguments before stringification in TP_printk

From: Rasmus Villemoes
Date: Tue Dec 15 2015 - 18:59:59 EST


TL;DR: For the .config I use for my laptop, the bloat-o-meter win is

$ scripts/bloat-o-meter /tmp/vmlinux.{old,new}
add/remove: 0/0 grow/shrink: 187/136 up/down: 3566/-38081 (-34515)

The __stringify macro ensures that its argument is completely
macro-expanded before it is stringified. That is, IMO, not very useful
for the print_fmt_* variables, since it often makes the resulting
string almost, but not quite, entirely unlike the source code. For
example, in ext4/ext4_mballoc_alloc/format one finds

((unsigned int) ((REC->dev) >> 20)), ((unsigned int) ((REC->dev) & ((1U << 20) - 1)))

which came from

MAJOR(__entry->dev), MINOR(__entry->dev),

The latter is much more readable. Moreover, the macro expansion ends
up making the print_fmt_* strings rather bloated:

# find . -name 'format' | xargs grep '^print fmt:' | perl -pe 's/:print fmt: (.*)/" ".length($1)/e' | sort -k2,2n | tail
./kmem/kmem_cache_alloc/format 2160
./kmem/kmalloc_node/format 2179
./kmem/kmem_cache_alloc_node/format 2179
./kmem/mm_page_alloc/format 2241
./vmscan/mm_shrink_slab_start/format 2296
./scsi/scsi_dispatch_cmd_start/format 3102
./scsi/scsi_dispatch_cmd_error/format 3119
./libata/ata_qc_issue/format 5072
./scsi/scsi_dispatch_cmd_done/format 5145
./scsi/scsi_dispatch_cmd_timeout/format 5145

This is mostly caused by the (flag value, symbolic string) arrays used
for __print_symbolic being included verbatim.

The increases in bloat-o-meter are partly due to the simple fact that
__entry is longer than REC, but also because symbolic constants such
as I2C_SMBUS_QUICK no longer gets replaced by small integer literals -
the latter can in many cases profitably be rectified by using a
#define for the __print_symbolic argument (for example, in the i2c
case the same array is repeated four times in
include/trace/events/i2c.h).

Signed-off-by: Rasmus Villemoes <linux@xxxxxxxxxxxxxxxxxx>
---
include/trace/trace_events.h | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/include/trace/trace_events.h b/include/trace/trace_events.h
index de996cf61053..62daa32527e0 100644
--- a/include/trace/trace_events.h
+++ b/include/trace/trace_events.h
@@ -715,7 +715,7 @@ static inline void ftrace_test_probe_##call(void) \
#undef __print_array

#undef TP_printk
-#define TP_printk(fmt, args...) "\"" fmt "\", " __stringify(args)
+#define TP_printk(fmt, args...) "\"" fmt "\", " #args

#undef DECLARE_EVENT_CLASS
#define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print) \
--
2.6.1

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/