mirror of
https://github.com/torvalds/linux.git
synced 2024-11-24 05:02:12 +00:00
4649079b9d
When using trace-cmd on 5.6-rt for the function graph tracer, the output was
corrupted. It gave output like this:
funcgraph_entry: func=0xffffffff depth=38982
funcgraph_entry: func=0x1ffffffff depth=16044
funcgraph_exit: func=0xffffffff overrun=0x92539aaf00000000 calltime=0x92539c9900000072 rettime=0x100000072 depth=11084
funcgraph_exit: func=0xffffffff overrun=0x9253946e00000000 calltime=0x92539e2100000072 rettime=0x72 depth=26033702
funcgraph_entry: func=0xffffffff depth=85798
funcgraph_entry: func=0x1ffffffff depth=12044
The reason was because the tracefs/events/ftrace/funcgraph_entry/exit format
file was incorrect. The -rt kernel adds more common fields to the trace
events. Namely, common_migrate_disable and common_preempt_lazy_count. Each
is one byte in size. This changes the alignment of the normal payload. Most
events are aligned normally, but the function and function graph events are
defined with a "PACKED" macro, that packs their payload. As the offsets
displayed in the format files are now calculated by an aligned field, the
aligned field for function and function graph events should be 1, not their
normal alignment.
With aligning of the funcgraph_entry event, the format file has:
field:unsigned short common_type; offset:0; size:2; signed:0;
field:unsigned char common_flags; offset:2; size:1; signed:0;
field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
field:int common_pid; offset:4; size:4; signed:1;
field:unsigned char common_migrate_disable; offset:8; size:1; signed:0;
field:unsigned char common_preempt_lazy_count; offset:9; size:1; signed:0;
field:unsigned long func; offset:16; size:8; signed:0;
field:int depth; offset:24; size:4; signed:1;
But the actual alignment is:
field:unsigned short common_type; offset:0; size:2; signed:0;
field:unsigned char common_flags; offset:2; size:1; signed:0;
field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
field:int common_pid; offset:4; size:4; signed:1;
field:unsigned char common_migrate_disable; offset:8; size:1; signed:0;
field:unsigned char common_preempt_lazy_count; offset:9; size:1; signed:0;
field:unsigned long func; offset:12; size:8; signed:0;
field:int depth; offset:20; size:4; signed:1;
Link: https://lkml.kernel.org/r/20200609220041.2a3b527f@oasis.local.home
Cc: stable@vger.kernel.org
Fixes: 04ae87a520 ("ftrace: Rework event_create_dir()")
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
341 lines
8.2 KiB
C
341 lines
8.2 KiB
C
// SPDX-License-Identifier: GPL-2.0
|
|
/*
|
|
* This file defines the trace event structures that go into the ring
|
|
* buffer directly. They are created via macros so that changes for them
|
|
* appear in the format file. Using macros will automate this process.
|
|
*
|
|
* The macro used to create a ftrace data structure is:
|
|
*
|
|
* FTRACE_ENTRY( name, struct_name, id, structure, print )
|
|
*
|
|
* @name: the name used the event name, as well as the name of
|
|
* the directory that holds the format file.
|
|
*
|
|
* @struct_name: the name of the structure that is created.
|
|
*
|
|
* @id: The event identifier that is used to detect what event
|
|
* this is from the ring buffer.
|
|
*
|
|
* @structure: the structure layout
|
|
*
|
|
* - __field( type, item )
|
|
* This is equivalent to declaring
|
|
* type item;
|
|
* in the structure.
|
|
* - __array( type, item, size )
|
|
* This is equivalent to declaring
|
|
* type item[size];
|
|
* in the structure.
|
|
*
|
|
* * for structures within structures, the format of the internal
|
|
* structure is laid out. This allows the internal structure
|
|
* to be deciphered for the format file. Although these macros
|
|
* may become out of sync with the internal structure, they
|
|
* will create a compile error if it happens. Since the
|
|
* internel structures are just tracing helpers, this is not
|
|
* an issue.
|
|
*
|
|
* When an internal structure is used, it should use:
|
|
*
|
|
* __field_struct( type, item )
|
|
*
|
|
* instead of __field. This will prevent it from being shown in
|
|
* the output file. The fields in the structure should use.
|
|
*
|
|
* __field_desc( type, container, item )
|
|
* __array_desc( type, container, item, len )
|
|
*
|
|
* type, item and len are the same as __field and __array, but
|
|
* container is added. This is the name of the item in
|
|
* __field_struct that this is describing.
|
|
*
|
|
*
|
|
* @print: the print format shown to users in the format file.
|
|
*/
|
|
|
|
/*
|
|
* Function trace entry - function address and parent function address:
|
|
*/
|
|
FTRACE_ENTRY_REG(function, ftrace_entry,
|
|
|
|
TRACE_FN,
|
|
|
|
F_STRUCT(
|
|
__field_fn( unsigned long, ip )
|
|
__field_fn( unsigned long, parent_ip )
|
|
),
|
|
|
|
F_printk(" %ps <-- %ps",
|
|
(void *)__entry->ip, (void *)__entry->parent_ip),
|
|
|
|
perf_ftrace_event_register
|
|
);
|
|
|
|
/* Function call entry */
|
|
FTRACE_ENTRY_PACKED(funcgraph_entry, ftrace_graph_ent_entry,
|
|
|
|
TRACE_GRAPH_ENT,
|
|
|
|
F_STRUCT(
|
|
__field_struct( struct ftrace_graph_ent, graph_ent )
|
|
__field_packed( unsigned long, graph_ent, func )
|
|
__field_packed( int, graph_ent, depth )
|
|
),
|
|
|
|
F_printk("--> %ps (%d)", (void *)__entry->func, __entry->depth)
|
|
);
|
|
|
|
/* Function return entry */
|
|
FTRACE_ENTRY_PACKED(funcgraph_exit, ftrace_graph_ret_entry,
|
|
|
|
TRACE_GRAPH_RET,
|
|
|
|
F_STRUCT(
|
|
__field_struct( struct ftrace_graph_ret, ret )
|
|
__field_packed( unsigned long, ret, func )
|
|
__field_packed( unsigned long, ret, overrun )
|
|
__field_packed( unsigned long long, ret, calltime)
|
|
__field_packed( unsigned long long, ret, rettime )
|
|
__field_packed( int, ret, depth )
|
|
),
|
|
|
|
F_printk("<-- %ps (%d) (start: %llx end: %llx) over: %d",
|
|
(void *)__entry->func, __entry->depth,
|
|
__entry->calltime, __entry->rettime,
|
|
__entry->depth)
|
|
);
|
|
|
|
/*
|
|
* Context switch trace entry - which task (and prio) we switched from/to:
|
|
*
|
|
* This is used for both wakeup and context switches. We only want
|
|
* to create one structure, but we need two outputs for it.
|
|
*/
|
|
#define FTRACE_CTX_FIELDS \
|
|
__field( unsigned int, prev_pid ) \
|
|
__field( unsigned int, next_pid ) \
|
|
__field( unsigned int, next_cpu ) \
|
|
__field( unsigned char, prev_prio ) \
|
|
__field( unsigned char, prev_state ) \
|
|
__field( unsigned char, next_prio ) \
|
|
__field( unsigned char, next_state )
|
|
|
|
FTRACE_ENTRY(context_switch, ctx_switch_entry,
|
|
|
|
TRACE_CTX,
|
|
|
|
F_STRUCT(
|
|
FTRACE_CTX_FIELDS
|
|
),
|
|
|
|
F_printk("%u:%u:%u ==> %u:%u:%u [%03u]",
|
|
__entry->prev_pid, __entry->prev_prio, __entry->prev_state,
|
|
__entry->next_pid, __entry->next_prio, __entry->next_state,
|
|
__entry->next_cpu)
|
|
);
|
|
|
|
/*
|
|
* FTRACE_ENTRY_DUP only creates the format file, it will not
|
|
* create another structure.
|
|
*/
|
|
FTRACE_ENTRY_DUP(wakeup, ctx_switch_entry,
|
|
|
|
TRACE_WAKE,
|
|
|
|
F_STRUCT(
|
|
FTRACE_CTX_FIELDS
|
|
),
|
|
|
|
F_printk("%u:%u:%u ==+ %u:%u:%u [%03u]",
|
|
__entry->prev_pid, __entry->prev_prio, __entry->prev_state,
|
|
__entry->next_pid, __entry->next_prio, __entry->next_state,
|
|
__entry->next_cpu)
|
|
);
|
|
|
|
/*
|
|
* Stack-trace entry:
|
|
*/
|
|
|
|
#define FTRACE_STACK_ENTRIES 8
|
|
|
|
FTRACE_ENTRY(kernel_stack, stack_entry,
|
|
|
|
TRACE_STACK,
|
|
|
|
F_STRUCT(
|
|
__field( int, size )
|
|
__array( unsigned long, caller, FTRACE_STACK_ENTRIES )
|
|
),
|
|
|
|
F_printk("\t=> %ps\n\t=> %ps\n\t=> %ps\n"
|
|
"\t=> %ps\n\t=> %ps\n\t=> %ps\n"
|
|
"\t=> %ps\n\t=> %ps\n",
|
|
(void *)__entry->caller[0], (void *)__entry->caller[1],
|
|
(void *)__entry->caller[2], (void *)__entry->caller[3],
|
|
(void *)__entry->caller[4], (void *)__entry->caller[5],
|
|
(void *)__entry->caller[6], (void *)__entry->caller[7])
|
|
);
|
|
|
|
FTRACE_ENTRY(user_stack, userstack_entry,
|
|
|
|
TRACE_USER_STACK,
|
|
|
|
F_STRUCT(
|
|
__field( unsigned int, tgid )
|
|
__array( unsigned long, caller, FTRACE_STACK_ENTRIES )
|
|
),
|
|
|
|
F_printk("\t=> %ps\n\t=> %ps\n\t=> %ps\n"
|
|
"\t=> %ps\n\t=> %ps\n\t=> %ps\n"
|
|
"\t=> %ps\n\t=> %ps\n",
|
|
(void *)__entry->caller[0], (void *)__entry->caller[1],
|
|
(void *)__entry->caller[2], (void *)__entry->caller[3],
|
|
(void *)__entry->caller[4], (void *)__entry->caller[5],
|
|
(void *)__entry->caller[6], (void *)__entry->caller[7])
|
|
);
|
|
|
|
/*
|
|
* trace_printk entry:
|
|
*/
|
|
FTRACE_ENTRY(bprint, bprint_entry,
|
|
|
|
TRACE_BPRINT,
|
|
|
|
F_STRUCT(
|
|
__field( unsigned long, ip )
|
|
__field( const char *, fmt )
|
|
__dynamic_array( u32, buf )
|
|
),
|
|
|
|
F_printk("%ps: %s",
|
|
(void *)__entry->ip, __entry->fmt)
|
|
);
|
|
|
|
FTRACE_ENTRY_REG(print, print_entry,
|
|
|
|
TRACE_PRINT,
|
|
|
|
F_STRUCT(
|
|
__field( unsigned long, ip )
|
|
__dynamic_array( char, buf )
|
|
),
|
|
|
|
F_printk("%ps: %s",
|
|
(void *)__entry->ip, __entry->buf),
|
|
|
|
ftrace_event_register
|
|
);
|
|
|
|
FTRACE_ENTRY(raw_data, raw_data_entry,
|
|
|
|
TRACE_RAW_DATA,
|
|
|
|
F_STRUCT(
|
|
__field( unsigned int, id )
|
|
__dynamic_array( char, buf )
|
|
),
|
|
|
|
F_printk("id:%04x %08x",
|
|
__entry->id, (int)__entry->buf[0])
|
|
);
|
|
|
|
FTRACE_ENTRY(bputs, bputs_entry,
|
|
|
|
TRACE_BPUTS,
|
|
|
|
F_STRUCT(
|
|
__field( unsigned long, ip )
|
|
__field( const char *, str )
|
|
),
|
|
|
|
F_printk("%ps: %s",
|
|
(void *)__entry->ip, __entry->str)
|
|
);
|
|
|
|
FTRACE_ENTRY(mmiotrace_rw, trace_mmiotrace_rw,
|
|
|
|
TRACE_MMIO_RW,
|
|
|
|
F_STRUCT(
|
|
__field_struct( struct mmiotrace_rw, rw )
|
|
__field_desc( resource_size_t, rw, phys )
|
|
__field_desc( unsigned long, rw, value )
|
|
__field_desc( unsigned long, rw, pc )
|
|
__field_desc( int, rw, map_id )
|
|
__field_desc( unsigned char, rw, opcode )
|
|
__field_desc( unsigned char, rw, width )
|
|
),
|
|
|
|
F_printk("%lx %lx %lx %d %x %x",
|
|
(unsigned long)__entry->phys, __entry->value, __entry->pc,
|
|
__entry->map_id, __entry->opcode, __entry->width)
|
|
);
|
|
|
|
FTRACE_ENTRY(mmiotrace_map, trace_mmiotrace_map,
|
|
|
|
TRACE_MMIO_MAP,
|
|
|
|
F_STRUCT(
|
|
__field_struct( struct mmiotrace_map, map )
|
|
__field_desc( resource_size_t, map, phys )
|
|
__field_desc( unsigned long, map, virt )
|
|
__field_desc( unsigned long, map, len )
|
|
__field_desc( int, map, map_id )
|
|
__field_desc( unsigned char, map, opcode )
|
|
),
|
|
|
|
F_printk("%lx %lx %lx %d %x",
|
|
(unsigned long)__entry->phys, __entry->virt, __entry->len,
|
|
__entry->map_id, __entry->opcode)
|
|
);
|
|
|
|
|
|
#define TRACE_FUNC_SIZE 30
|
|
#define TRACE_FILE_SIZE 20
|
|
|
|
FTRACE_ENTRY(branch, trace_branch,
|
|
|
|
TRACE_BRANCH,
|
|
|
|
F_STRUCT(
|
|
__field( unsigned int, line )
|
|
__array( char, func, TRACE_FUNC_SIZE+1 )
|
|
__array( char, file, TRACE_FILE_SIZE+1 )
|
|
__field( char, correct )
|
|
__field( char, constant )
|
|
),
|
|
|
|
F_printk("%u:%s:%s (%u)%s",
|
|
__entry->line,
|
|
__entry->func, __entry->file, __entry->correct,
|
|
__entry->constant ? " CONSTANT" : "")
|
|
);
|
|
|
|
|
|
FTRACE_ENTRY(hwlat, hwlat_entry,
|
|
|
|
TRACE_HWLAT,
|
|
|
|
F_STRUCT(
|
|
__field( u64, duration )
|
|
__field( u64, outer_duration )
|
|
__field( u64, nmi_total_ts )
|
|
__field_struct( struct timespec64, timestamp )
|
|
__field_desc( s64, timestamp, tv_sec )
|
|
__field_desc( long, timestamp, tv_nsec )
|
|
__field( unsigned int, nmi_count )
|
|
__field( unsigned int, seqnum )
|
|
__field( unsigned int, count )
|
|
),
|
|
|
|
F_printk("cnt:%u\tts:%010llu.%010lu\tinner:%llu\touter:%llu\tcount:%d\tnmi-ts:%llu\tnmi-count:%u\n",
|
|
__entry->seqnum,
|
|
__entry->tv_sec,
|
|
__entry->tv_nsec,
|
|
__entry->duration,
|
|
__entry->outer_duration,
|
|
__entry->count,
|
|
__entry->nmi_total_ts,
|
|
__entry->nmi_count)
|
|
);
|