85acbb21b9
Here is an example for this change. $ sudo perf record -e 'ftrace:function' --filter='ip==schedule' $ sudo perf report The output of perf before this patch: \# Samples: 100 of event 'ftrace:function' \# Event count (approx.): 100 \# \# Overhead Trace output \# ........ ...................................... \# 51.00% ffffffff81f6aaa0 <-- ffffffff81158e8d 29.00% ffffffff81f6aaa0 <-- ffffffff8116ccb2 8.00% ffffffff81f6aaa0 <-- ffffffff81f6f2ed 4.00% ffffffff81f6aaa0 <-- ffffffff811628db 4.00% ffffffff81f6aaa0 <-- ffffffff81f6ec5b 2.00% ffffffff81f6aaa0 <-- ffffffff81f6f21a 1.00% ffffffff81f6aaa0 <-- ffffffff811b04af 1.00% ffffffff81f6aaa0 <-- ffffffff8143ce17 After this patch: \# Samples: 36 of event 'ftrace:function' \# Event count (approx.): 36 \# \# Overhead Trace output \# ........ ............................................ \# 38.89% schedule <-- schedule_hrtimeout_range_clock 27.78% schedule <-- worker_thread 13.89% schedule <-- schedule_timeout 11.11% schedule <-- smpboot_thread_fn 5.56% schedule <-- rcu_gp_kthread 2.78% schedule <-- exit_to_usermode_loop Link: http://lkml.kernel.org/r/20190209161919.32350-1-changbin.du@gmail.com Signed-off-by: Changbin Du <changbin.du@gmail.com> Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
369 lines
8.3 KiB
C
369 lines
8.3 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( unsigned long, ip )
|
|
__field( unsigned long, parent_ip )
|
|
),
|
|
|
|
F_printk(" %ps <-- %ps",
|
|
(void *)__entry->ip, (void *)__entry->parent_ip),
|
|
|
|
FILTER_TRACE_FN,
|
|
|
|
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_desc( unsigned long, graph_ent, func )
|
|
__field_desc( int, graph_ent, depth )
|
|
),
|
|
|
|
F_printk("--> %ps (%d)", (void *)__entry->func, __entry->depth),
|
|
|
|
FILTER_OTHER
|
|
);
|
|
|
|
/* 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_desc( unsigned long, ret, func )
|
|
__field_desc( unsigned long long, ret, calltime)
|
|
__field_desc( unsigned long long, ret, rettime )
|
|
__field_desc( unsigned long, ret, overrun )
|
|
__field_desc( int, ret, depth )
|
|
),
|
|
|
|
F_printk("<-- %ps (%d) (start: %llx end: %llx) over: %d",
|
|
(void *)__entry->func, __entry->depth,
|
|
__entry->calltime, __entry->rettime,
|
|
__entry->depth),
|
|
|
|
FILTER_OTHER
|
|
);
|
|
|
|
/*
|
|
* 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),
|
|
|
|
FILTER_OTHER
|
|
);
|
|
|
|
/*
|
|
* 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),
|
|
|
|
FILTER_OTHER
|
|
);
|
|
|
|
/*
|
|
* Stack-trace entry:
|
|
*/
|
|
|
|
#define FTRACE_STACK_ENTRIES 8
|
|
|
|
FTRACE_ENTRY(kernel_stack, stack_entry,
|
|
|
|
TRACE_STACK,
|
|
|
|
F_STRUCT(
|
|
__field( int, size )
|
|
__dynamic_array(unsigned long, caller )
|
|
),
|
|
|
|
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]),
|
|
|
|
FILTER_OTHER
|
|
);
|
|
|
|
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]),
|
|
|
|
FILTER_OTHER
|
|
);
|
|
|
|
/*
|
|
* 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),
|
|
|
|
FILTER_OTHER
|
|
);
|
|
|
|
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),
|
|
|
|
FILTER_OTHER,
|
|
|
|
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]),
|
|
|
|
FILTER_OTHER
|
|
);
|
|
|
|
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),
|
|
|
|
FILTER_OTHER
|
|
);
|
|
|
|
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),
|
|
|
|
FILTER_OTHER
|
|
);
|
|
|
|
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),
|
|
|
|
FILTER_OTHER
|
|
);
|
|
|
|
|
|
#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" : ""),
|
|
|
|
FILTER_OTHER
|
|
);
|
|
|
|
|
|
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 )
|
|
),
|
|
|
|
F_printk("cnt:%u\tts:%010llu.%010lu\tinner:%llu\touter:%llu\tnmi-ts:%llu\tnmi-count:%u\n",
|
|
__entry->seqnum,
|
|
__entry->tv_sec,
|
|
__entry->tv_nsec,
|
|
__entry->duration,
|
|
__entry->outer_duration,
|
|
__entry->nmi_total_ts,
|
|
__entry->nmi_count),
|
|
|
|
FILTER_OTHER
|
|
);
|