From 62aed044ea4bef36ac3f6885611b013b11c9be2d Mon Sep 17 00:00:00 2001 From: Chao Yu Date: Tue, 6 May 2014 16:46:04 +0800 Subject: f2fs: add a tracepoint for f2fs_write_begin This patch adds a tracepoint for f2fs_write_begin to trace write op of user. Signed-off-by: Chao Yu Signed-off-by: Jaegeuk Kim --- include/trace/events/f2fs.h | 30 ++++++++++++++++++++++++++++++ 1 file changed, 30 insertions(+) (limited to 'include/trace') diff --git a/include/trace/events/f2fs.h b/include/trace/events/f2fs.h index 67f38faac589..1e9375aa9340 100644 --- a/include/trace/events/f2fs.h +++ b/include/trace/events/f2fs.h @@ -659,6 +659,36 @@ DEFINE_EVENT_CONDITION(f2fs__submit_bio, f2fs_submit_read_bio, TP_CONDITION(bio) ); +TRACE_EVENT(f2fs_write_begin, + + TP_PROTO(struct inode *inode, loff_t pos, unsigned int len, + unsigned int flags), + + TP_ARGS(inode, pos, len, flags), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(ino_t, ino) + __field(loff_t, pos) + __field(unsigned int, len) + __field(unsigned int, flags) + ), + + TP_fast_assign( + __entry->dev = inode->i_sb->s_dev; + __entry->ino = inode->i_ino; + __entry->pos = pos; + __entry->len = len; + __entry->flags = flags; + ), + + TP_printk("dev = (%d,%d), ino = %lu, pos = %llu, len = %u, flags = %u", + show_dev_ino(__entry), + (unsigned long long)__entry->pos, + __entry->len, + __entry->flags) +); + DECLARE_EVENT_CLASS(f2fs__page, TP_PROTO(struct page *page, int type), -- cgit v1.2.3 From dfb2bf38bf89e15a65f9996566b2945921388a2f Mon Sep 17 00:00:00 2001 From: Chao Yu Date: Tue, 6 May 2014 16:47:23 +0800 Subject: f2fs: add a tracepoint for f2fs_write_end This patch adds a tracepoint for f2fs_write_end to trace write op of user. Signed-off-by: Chao Yu Signed-off-by: Jaegeuk Kim --- include/trace/events/f2fs.h | 30 ++++++++++++++++++++++++++++++ 1 file changed, 30 insertions(+) (limited to 'include/trace') diff --git a/include/trace/events/f2fs.h b/include/trace/events/f2fs.h index 1e9375aa9340..483804b55742 100644 --- a/include/trace/events/f2fs.h +++ b/include/trace/events/f2fs.h @@ -689,6 +689,36 @@ TRACE_EVENT(f2fs_write_begin, __entry->flags) ); +TRACE_EVENT(f2fs_write_end, + + TP_PROTO(struct inode *inode, loff_t pos, unsigned int len, + unsigned int copied), + + TP_ARGS(inode, pos, len, copied), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(ino_t, ino) + __field(loff_t, pos) + __field(unsigned int, len) + __field(unsigned int, copied) + ), + + TP_fast_assign( + __entry->dev = inode->i_sb->s_dev; + __entry->ino = inode->i_ino; + __entry->pos = pos; + __entry->len = len; + __entry->copied = copied; + ), + + TP_printk("dev = (%d,%d), ino = %lu, pos = %llu, len = %u, copied = %u", + show_dev_ino(__entry), + (unsigned long long)__entry->pos, + __entry->len, + __entry->copied) +); + DECLARE_EVENT_CLASS(f2fs__page, TP_PROTO(struct page *page, int type), -- cgit v1.2.3 From ecda0de3430455378f1c02523bf3ad71d91d613a Mon Sep 17 00:00:00 2001 From: Chao Yu Date: Tue, 6 May 2014 16:48:26 +0800 Subject: f2fs: add a tracepoint for f2fs_write_{meta,node,data}_page This patch adds a tracepoint for f2fs_write_{meta,node,data}_page to trace when page is writting out. Signed-off-by: Chao Yu Signed-off-by: Jaegeuk Kim --- include/trace/events/f2fs.h | 7 +++++++ 1 file changed, 7 insertions(+) (limited to 'include/trace') diff --git a/include/trace/events/f2fs.h b/include/trace/events/f2fs.h index 483804b55742..d70991e69e58 100644 --- a/include/trace/events/f2fs.h +++ b/include/trace/events/f2fs.h @@ -751,6 +751,13 @@ DECLARE_EVENT_CLASS(f2fs__page, __entry->dirty) ); +DEFINE_EVENT(f2fs__page, f2fs_writepage, + + TP_PROTO(struct page *page, int type), + + TP_ARGS(page, type) +); + DEFINE_EVENT(f2fs__page, f2fs_set_page_dirty, TP_PROTO(struct page *page, int type), -- cgit v1.2.3 From e57484343898094bb8f72a2aa1a50929d27aa027 Mon Sep 17 00:00:00 2001 From: Chao Yu Date: Tue, 6 May 2014 16:51:24 +0800 Subject: f2fs: add a tracepoint for f2fs_write_{meta,node,data}_pages This patch adds a tracepoint for f2fs_write_{meta,node,data}_pages to trace when pages are fsyncing/flushing. Signed-off-by: Chao Yu Signed-off-by: Jaegeuk Kim --- include/trace/events/f2fs.h | 64 +++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 64 insertions(+) (limited to 'include/trace') diff --git a/include/trace/events/f2fs.h b/include/trace/events/f2fs.h index d70991e69e58..91b1fcc5ec93 100644 --- a/include/trace/events/f2fs.h +++ b/include/trace/events/f2fs.h @@ -772,6 +772,70 @@ DEFINE_EVENT(f2fs__page, f2fs_vm_page_mkwrite, TP_ARGS(page, type) ); +TRACE_EVENT(f2fs_writepages, + + TP_PROTO(struct inode *inode, struct writeback_control *wbc, int type), + + TP_ARGS(inode, wbc, type), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(ino_t, ino) + __field(int, type) + __field(int, dir) + __field(long, nr_to_write) + __field(long, pages_skipped) + __field(loff_t, range_start) + __field(loff_t, range_end) + __field(pgoff_t, writeback_index) + __field(int, sync_mode) + __field(char, for_kupdate) + __field(char, for_background) + __field(char, tagged_writepages) + __field(char, for_reclaim) + __field(char, range_cyclic) + __field(char, for_sync) + ), + + TP_fast_assign( + __entry->dev = inode->i_sb->s_dev; + __entry->ino = inode->i_ino; + __entry->type = type; + __entry->dir = S_ISDIR(inode->i_mode); + __entry->nr_to_write = wbc->nr_to_write; + __entry->pages_skipped = wbc->pages_skipped; + __entry->range_start = wbc->range_start; + __entry->range_end = wbc->range_end; + __entry->writeback_index = inode->i_mapping->writeback_index; + __entry->sync_mode = wbc->sync_mode; + __entry->for_kupdate = wbc->for_kupdate; + __entry->for_background = wbc->for_background; + __entry->tagged_writepages = wbc->tagged_writepages; + __entry->for_reclaim = wbc->for_reclaim; + __entry->range_cyclic = wbc->range_cyclic; + __entry->for_sync = wbc->for_sync; + ), + + TP_printk("dev = (%d,%d), ino = %lu, %s, %s, nr_to_write %ld, " + "skipped %ld, start %lld, end %lld, wb_idx %lu, sync_mode %d, " + "kupdate %u background %u tagged %u reclaim %u cyclic %u sync %u", + show_dev_ino(__entry), + show_block_type(__entry->type), + show_file_type(__entry->dir), + __entry->nr_to_write, + __entry->pages_skipped, + __entry->range_start, + __entry->range_end, + (unsigned long)__entry->writeback_index, + __entry->sync_mode, + __entry->for_kupdate, + __entry->for_background, + __entry->tagged_writepages, + __entry->for_reclaim, + __entry->range_cyclic, + __entry->for_sync) +); + TRACE_EVENT(f2fs_submit_page_mbio, TP_PROTO(struct page *page, int rw, int type, block_t blk_addr), -- cgit v1.2.3 From c20e89cde669799eff62bf8c00ca9a4819c4e11f Mon Sep 17 00:00:00 2001 From: Chao Yu Date: Tue, 6 May 2014 16:53:08 +0800 Subject: f2fs: add a tracepoint for f2fs_read_data_page This patch adds a tracepoint for f2fs_read_data_page to trace when page is readed by user. Signed-off-by: Chao Yu Signed-off-by: Jaegeuk Kim --- include/trace/events/f2fs.h | 15 +++++++++++++-- 1 file changed, 13 insertions(+), 2 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/f2fs.h b/include/trace/events/f2fs.h index 91b1fcc5ec93..b983990b4a9f 100644 --- a/include/trace/events/f2fs.h +++ b/include/trace/events/f2fs.h @@ -732,6 +732,7 @@ DECLARE_EVENT_CLASS(f2fs__page, __field(int, dir) __field(pgoff_t, index) __field(int, dirty) + __field(int, uptodate) ), TP_fast_assign( @@ -741,14 +742,17 @@ DECLARE_EVENT_CLASS(f2fs__page, __entry->dir = S_ISDIR(page->mapping->host->i_mode); __entry->index = page->index; __entry->dirty = PageDirty(page); + __entry->uptodate = PageUptodate(page); ), - TP_printk("dev = (%d,%d), ino = %lu, %s, %s, index = %lu, dirty = %d", + TP_printk("dev = (%d,%d), ino = %lu, %s, %s, index = %lu, " + "dirty = %d, uptodate = %d", show_dev_ino(__entry), show_block_type(__entry->type), show_file_type(__entry->dir), (unsigned long)__entry->index, - __entry->dirty) + __entry->dirty, + __entry->uptodate) ); DEFINE_EVENT(f2fs__page, f2fs_writepage, @@ -758,6 +762,13 @@ DEFINE_EVENT(f2fs__page, f2fs_writepage, TP_ARGS(page, type) ); +DEFINE_EVENT(f2fs__page, f2fs_readpage, + + TP_PROTO(struct page *page, int type), + + TP_ARGS(page, type) +); + DEFINE_EVENT(f2fs__page, f2fs_set_page_dirty, TP_PROTO(struct page *page, int type), -- cgit v1.2.3 From 4449bf927b61bdb4389393c6fea6837214d1ace7 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Red Hat)" Date: Tue, 6 May 2014 13:10:24 -0400 Subject: tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks Being able to show a cpumask of events can be useful as some events may affect only some CPUs. There is no standard way to record the cpumask and converting it to a string is rather expensive during the trace as traces happen in hotpaths. It would be better to record the raw event mask and be able to parse it at print time. The following macros were added for use with the TRACE_EVENT() macro: __bitmask() __assign_bitmask() __get_bitmask() To test this, I added this to the sched_migrate_task event, which looked like this: TRACE_EVENT(sched_migrate_task, TP_PROTO(struct task_struct *p, int dest_cpu, const struct cpumask *cpus), TP_ARGS(p, dest_cpu, cpus), TP_STRUCT__entry( __array( char, comm, TASK_COMM_LEN ) __field( pid_t, pid ) __field( int, prio ) __field( int, orig_cpu ) __field( int, dest_cpu ) __bitmask( cpumask, num_possible_cpus() ) ), TP_fast_assign( memcpy(__entry->comm, p->comm, TASK_COMM_LEN); __entry->pid = p->pid; __entry->prio = p->prio; __entry->orig_cpu = task_cpu(p); __entry->dest_cpu = dest_cpu; __assign_bitmask(cpumask, cpumask_bits(cpus), num_possible_cpus()); ), TP_printk("comm=%s pid=%d prio=%d orig_cpu=%d dest_cpu=%d cpumask=%s", __entry->comm, __entry->pid, __entry->prio, __entry->orig_cpu, __entry->dest_cpu, __get_bitmask(cpumask)) ); With the output of: ksmtuned-3613 [003] d..2 485.220508: sched_migrate_task: comm=ksmtuned pid=3615 prio=120 orig_cpu=3 dest_cpu=2 cpumask=00000000,0000000f migration/1-13 [001] d..5 485.221202: sched_migrate_task: comm=ksmtuned pid=3614 prio=120 orig_cpu=1 dest_cpu=0 cpumask=00000000,0000000f awk-3615 [002] d.H5 485.221747: sched_migrate_task: comm=rcu_preempt pid=7 prio=120 orig_cpu=0 dest_cpu=1 cpumask=00000000,000000ff migration/2-18 [002] d..5 485.222062: sched_migrate_task: comm=ksmtuned pid=3615 prio=120 orig_cpu=2 dest_cpu=3 cpumask=00000000,0000000f Link: http://lkml.kernel.org/r/1399377998-14870-6-git-send-email-javi.merino@arm.com Link: http://lkml.kernel.org/r/20140506132238.22e136d1@gandalf.local.home Suggested-by: Javi Merino Tested-by: Javi Merino Signed-off-by: Steven Rostedt --- include/trace/ftrace.h | 57 +++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 56 insertions(+), 1 deletion(-) (limited to 'include/trace') diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h index 0a1a4f7caf09..9b7a989dcbcc 100644 --- a/include/trace/ftrace.h +++ b/include/trace/ftrace.h @@ -53,6 +53,9 @@ #undef __string #define __string(item, src) __dynamic_array(char, item, -1) +#undef __bitmask +#define __bitmask(item, nr_bits) __dynamic_array(char, item, -1) + #undef TP_STRUCT__entry #define TP_STRUCT__entry(args...) args @@ -128,6 +131,9 @@ #undef __string #define __string(item, src) __dynamic_array(char, item, -1) +#undef __bitmask +#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1) + #undef DECLARE_EVENT_CLASS #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print) \ struct ftrace_data_offsets_##call { \ @@ -200,6 +206,15 @@ #undef __get_str #define __get_str(field) (char *)__get_dynamic_array(field) +#undef __get_bitmask +#define __get_bitmask(field) \ + ({ \ + void *__bitmask = __get_dynamic_array(field); \ + unsigned int __bitmask_size; \ + __bitmask_size = (__entry->__data_loc_##field >> 16) & 0xffff; \ + ftrace_print_bitmask_seq(p, __bitmask, __bitmask_size); \ + }) + #undef __print_flags #define __print_flags(flag, delim, flag_array...) \ ({ \ @@ -322,6 +337,9 @@ static struct trace_event_functions ftrace_event_type_funcs_##call = { \ #undef __string #define __string(item, src) __dynamic_array(char, item, -1) +#undef __bitmask +#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1) + #undef DECLARE_EVENT_CLASS #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, func, print) \ static int notrace __init \ @@ -372,6 +390,29 @@ ftrace_define_fields_##call(struct ftrace_event_call *event_call) \ #define __string(item, src) __dynamic_array(char, item, \ strlen((src) ? (const char *)(src) : "(null)") + 1) +/* + * __bitmask_size_in_bytes_raw is the number of bytes needed to hold + * num_possible_cpus(). + */ +#define __bitmask_size_in_bytes_raw(nr_bits) \ + (((nr_bits) + 7) / 8) + +#define __bitmask_size_in_longs(nr_bits) \ + ((__bitmask_size_in_bytes_raw(nr_bits) + \ + ((BITS_PER_LONG / 8) - 1)) / (BITS_PER_LONG / 8)) + +/* + * __bitmask_size_in_bytes is the number of bytes needed to hold + * num_possible_cpus() padded out to the nearest long. This is what + * is saved in the buffer, just to be consistent. + */ +#define __bitmask_size_in_bytes(nr_bits) \ + (__bitmask_size_in_longs(nr_bits) * (BITS_PER_LONG / 8)) + +#undef __bitmask +#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, \ + __bitmask_size_in_longs(nr_bits)) + #undef DECLARE_EVENT_CLASS #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print) \ static inline notrace int ftrace_get_offsets_##call( \ @@ -513,12 +554,22 @@ static inline notrace int ftrace_get_offsets_##call( \ __entry->__data_loc_##item = __data_offsets.item; #undef __string -#define __string(item, src) __dynamic_array(char, item, -1) \ +#define __string(item, src) __dynamic_array(char, item, -1) #undef __assign_str #define __assign_str(dst, src) \ strcpy(__get_str(dst), (src) ? (const char *)(src) : "(null)"); +#undef __bitmask +#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1) + +#undef __get_bitmask +#define __get_bitmask(field) (char *)__get_dynamic_array(field) + +#undef __assign_bitmask +#define __assign_bitmask(dst, src, nr_bits) \ + memcpy(__get_bitmask(dst), (src), __bitmask_size_in_bytes(nr_bits)) + #undef TP_fast_assign #define TP_fast_assign(args...) args @@ -586,6 +637,7 @@ static inline void ftrace_test_probe_##call(void) \ #undef __print_hex #undef __get_dynamic_array #undef __get_str +#undef __get_bitmask #undef TP_printk #define TP_printk(fmt, args...) "\"" fmt "\", " __stringify(args) @@ -651,6 +703,9 @@ __attribute__((section("_ftrace_events"))) *__event_##call = &event_##call #undef __get_str #define __get_str(field) (char *)__get_dynamic_array(field) +#undef __get_bitmask +#define __get_bitmask(field) (char *)__get_dynamic_array(field) + #undef __perf_addr #define __perf_addr(a) (__addr = (a)) -- cgit v1.2.3 From beba4bb096201ceec0e8cfb7ce3172a53015bdaf Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Red Hat)" Date: Wed, 4 Jun 2014 14:29:33 -0400 Subject: tracing: Add __get_dynamic_array_len() macro for trace events If a trace event uses a dynamic array for something other than a string then there's currently no way the TP_printk() can figure out what size it is. A __get_dynamic_array_len() is required to know the length. This also simplifies the __get_bitmask() macro which required it as well, but instead just hardcoded it. Signed-off-by: Steven Rostedt --- include/trace/ftrace.h | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) (limited to 'include/trace') diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h index 9b7a989dcbcc..0fd06fef9fac 100644 --- a/include/trace/ftrace.h +++ b/include/trace/ftrace.h @@ -203,6 +203,10 @@ #define __get_dynamic_array(field) \ ((void *)__entry + (__entry->__data_loc_##field & 0xffff)) +#undef __get_dynamic_array_len +#define __get_dynamic_array_len(field) \ + ((__entry->__data_loc_##field >> 16) & 0xffff) + #undef __get_str #define __get_str(field) (char *)__get_dynamic_array(field) @@ -211,7 +215,7 @@ ({ \ void *__bitmask = __get_dynamic_array(field); \ unsigned int __bitmask_size; \ - __bitmask_size = (__entry->__data_loc_##field >> 16) & 0xffff; \ + __bitmask_size = __get_dynamic_array_len(field); \ ftrace_print_bitmask_seq(p, __bitmask, __bitmask_size); \ }) @@ -636,6 +640,7 @@ static inline void ftrace_test_probe_##call(void) \ #undef __print_symbolic #undef __print_hex #undef __get_dynamic_array +#undef __get_dynamic_array_len #undef __get_str #undef __get_bitmask @@ -700,6 +705,10 @@ __attribute__((section("_ftrace_events"))) *__event_##call = &event_##call #define __get_dynamic_array(field) \ ((void *)__entry + (__entry->__data_loc_##field & 0xffff)) +#undef __get_dynamic_array_len +#define __get_dynamic_array_len(field) \ + ((__entry->__data_loc_##field >> 16) & 0xffff) + #undef __get_str #define __get_str(field) (char *)__get_dynamic_array(field) -- cgit v1.2.3 From dfc68f29ae67f2a6e799b44e6a4eb3417dffbfcd Mon Sep 17 00:00:00 2001 From: Andy Lutomirski Date: Wed, 4 Jun 2014 10:31:15 -0700 Subject: sched, trace: Add a tracepoint for IPI-less remote wakeups Remote wakeups of polling CPUs are a valuable performance improvement; add a tracepoint to make it much easier to verify that they're working. Signed-off-by: Andy Lutomirski Signed-off-by: Peter Zijlstra Cc: nicolas.pitre@linaro.org Cc: daniel.lezcano@linaro.org Cc: umgwanakikbuti@gmail.com Cc: David Ahern Cc: Frederic Weisbecker Cc: Linus Torvalds Cc: Mel Gorman Cc: Oleg Nesterov Cc: Steven Rostedt Cc: linux-kernel@vger.kernel.org Link: http://lkml.kernel.org/r/16205aee116772aa686814f9b13bccb562108047.1401902905.git.luto@amacapital.net Signed-off-by: Ingo Molnar --- include/trace/events/sched.h | 20 ++++++++++++++++++++ 1 file changed, 20 insertions(+) (limited to 'include/trace') diff --git a/include/trace/events/sched.h b/include/trace/events/sched.h index 67e1bbf83695..0a68d5ae584e 100644 --- a/include/trace/events/sched.h +++ b/include/trace/events/sched.h @@ -530,6 +530,26 @@ TRACE_EVENT(sched_swap_numa, __entry->dst_pid, __entry->dst_tgid, __entry->dst_ngid, __entry->dst_cpu, __entry->dst_nid) ); + +/* + * Tracepoint for waking a polling cpu without an IPI. + */ +TRACE_EVENT(sched_wake_idle_without_ipi, + + TP_PROTO(int cpu), + + TP_ARGS(cpu), + + TP_STRUCT__entry( + __field( int, cpu ) + ), + + TP_fast_assign( + __entry->cpu = cpu; + ), + + TP_printk("cpu=%d", __entry->cpu) +); #endif /* _TRACE_SCHED_H */ /* This part must be outside protection */ -- cgit v1.2.3 From bb3632c6101b2fad07e6246721466b984b1e0e9d Mon Sep 17 00:00:00 2001 From: Todd E Brandt Date: Fri, 6 Jun 2014 05:40:17 -0700 Subject: PM / sleep: trace events for suspend/resume Adds trace events that give finer resolution into suspend/resume. These events are graphed in the timelines generated by the analyze_suspend.py script. They represent large areas of time consumed that are typical to suspend and resume. The event is triggered by calling the function "trace_suspend_resume" with three arguments: a string (the name of the event to be displayed in the timeline), an integer (case specific number, such as the power state or cpu number), and a boolean (where true is used to denote the start of the timeline event, and false to denote the end). The suspend_resume trace event reproduces the data that the machine_suspend trace event did, so the latter has been removed. Signed-off-by: Todd Brandt Acked-by: Steven Rostedt Signed-off-by: Rafael J. Wysocki --- include/trace/events/power.h | 42 +++++++++++++++++++++++++----------------- 1 file changed, 25 insertions(+), 17 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/power.h b/include/trace/events/power.h index 9a7e08d61258..f88c8573e66c 100644 --- a/include/trace/events/power.h +++ b/include/trace/events/power.h @@ -7,6 +7,9 @@ #include #include #include +#include + +#define TPS(x) tracepoint_string(x) DECLARE_EVENT_CLASS(cpu, @@ -97,23 +100,6 @@ DEFINE_EVENT(cpu, cpu_frequency, TP_ARGS(frequency, cpu_id) ); -TRACE_EVENT(machine_suspend, - - TP_PROTO(unsigned int state), - - TP_ARGS(state), - - TP_STRUCT__entry( - __field( u32, state ) - ), - - TP_fast_assign( - __entry->state = state; - ), - - TP_printk("state=%lu", (unsigned long)__entry->state) -); - TRACE_EVENT(device_pm_report_time, TP_PROTO(struct device *dev, const char *pm_ops, s64 ops_time, @@ -151,6 +137,28 @@ TRACE_EVENT(device_pm_report_time, __entry->ops_time, __entry->error) ); +TRACE_EVENT(suspend_resume, + + TP_PROTO(const char *action, int val, bool start), + + TP_ARGS(action, val, start), + + TP_STRUCT__entry( + __field(const char *, action) + __field(int, val) + __field(bool, start) + ), + + TP_fast_assign( + __entry->action = action; + __entry->val = val; + __entry->start = start; + ), + + TP_printk("%s[%u] %s", __entry->action, (unsigned int)__entry->val, + (__entry->start)?"begin":"end") +); + DECLARE_EVENT_CLASS(wakeup_source, TP_PROTO(const char *name, unsigned int state), -- cgit v1.2.3 From e8bca479c3f269ebb3a3acea5ef63314bb677060 Mon Sep 17 00:00:00 2001 From: Todd E Brandt Date: Tue, 10 Jun 2014 07:31:22 -0700 Subject: PM / sleep: trace events for device PM callbacks Adds two trace events which supply the same info that initcall_debug provides, but via ftrace instead of dmesg. The existing initcall_debug calls require the pm_print_times_enabled var to be set (either via sysfs or via the kernel cmd line). The new trace events provide all the same info as the initcall_debug prints but with less overhead, and also with coverage of device prepare and complete device callbacks. These events replace the device_pm_report_time event (which has been removed). device_pm_callback_start is called first and provides the device and callback info. device_pm_callback_end is called after with the device name and error info. The time and pid are gathered from the trace data headers. Signed-off-by: Todd Brandt Signed-off-by: Rafael J. Wysocki --- include/trace/events/power.h | 60 +++++++++++++++++++++++++++++++------------- 1 file changed, 42 insertions(+), 18 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/power.h b/include/trace/events/power.h index f88c8573e66c..d19840b0cac8 100644 --- a/include/trace/events/power.h +++ b/include/trace/events/power.h @@ -93,6 +93,17 @@ TRACE_EVENT(pstate_sample, #define PWR_EVENT_EXIT -1 #endif +#define pm_verb_symbolic(event) \ + __print_symbolic(event, \ + { PM_EVENT_SUSPEND, "suspend" }, \ + { PM_EVENT_RESUME, "resume" }, \ + { PM_EVENT_FREEZE, "freeze" }, \ + { PM_EVENT_QUIESCE, "quiesce" }, \ + { PM_EVENT_HIBERNATE, "hibernate" }, \ + { PM_EVENT_THAW, "thaw" }, \ + { PM_EVENT_RESTORE, "restore" }, \ + { PM_EVENT_RECOVER, "recover" }) + DEFINE_EVENT(cpu, cpu_frequency, TP_PROTO(unsigned int frequency, unsigned int cpu_id), @@ -100,41 +111,54 @@ DEFINE_EVENT(cpu, cpu_frequency, TP_ARGS(frequency, cpu_id) ); -TRACE_EVENT(device_pm_report_time, +TRACE_EVENT(device_pm_callback_start, - TP_PROTO(struct device *dev, const char *pm_ops, s64 ops_time, - char *pm_event_str, int error), + TP_PROTO(struct device *dev, const char *pm_ops, int event), - TP_ARGS(dev, pm_ops, ops_time, pm_event_str, error), + TP_ARGS(dev, pm_ops, event), TP_STRUCT__entry( __string(device, dev_name(dev)) __string(driver, dev_driver_string(dev)) __string(parent, dev->parent ? dev_name(dev->parent) : "none") __string(pm_ops, pm_ops ? pm_ops : "none ") - __string(pm_event_str, pm_event_str) - __field(s64, ops_time) - __field(int, error) + __field(int, event) ), TP_fast_assign( - const char *tmp = dev->parent ? dev_name(dev->parent) : "none"; - const char *tmp_i = pm_ops ? pm_ops : "none "; + __assign_str(device, dev_name(dev)); + __assign_str(driver, dev_driver_string(dev)); + __assign_str(parent, + dev->parent ? dev_name(dev->parent) : "none"); + __assign_str(pm_ops, pm_ops ? pm_ops : "none "); + __entry->event = event; + ), + + TP_printk("%s %s, parent: %s, %s[%s]", __get_str(driver), + __get_str(device), __get_str(parent), __get_str(pm_ops), + pm_verb_symbolic(__entry->event)) +); + +TRACE_EVENT(device_pm_callback_end, + + TP_PROTO(struct device *dev, int error), + TP_ARGS(dev, error), + + TP_STRUCT__entry( + __string(device, dev_name(dev)) + __string(driver, dev_driver_string(dev)) + __field(int, error) + ), + + TP_fast_assign( __assign_str(device, dev_name(dev)); __assign_str(driver, dev_driver_string(dev)); - __assign_str(parent, tmp); - __assign_str(pm_ops, tmp_i); - __assign_str(pm_event_str, pm_event_str); - __entry->ops_time = ops_time; __entry->error = error; ), - /* ops_str has an extra space at the end */ - TP_printk("%s %s parent=%s state=%s ops=%snsecs=%lld err=%d", - __get_str(driver), __get_str(device), __get_str(parent), - __get_str(pm_event_str), __get_str(pm_ops), - __entry->ops_time, __entry->error) + TP_printk("%s %s, err=%d", + __get_str(driver), __get_str(device), __entry->error) ); TRACE_EVENT(suspend_resume, -- cgit v1.2.3 From 4af4206be2bd1933cae20c2b6fb2058dbc887f7c Mon Sep 17 00:00:00 2001 From: Oleg Nesterov Date: Sun, 13 Apr 2014 20:58:54 +0200 Subject: tracing: Fix syscall_*regfunc() vs copy_process() race syscall_regfunc() and syscall_unregfunc() should set/clear TIF_SYSCALL_TRACEPOINT system-wide, but do_each_thread() can race with copy_process() and miss the new child which was not added to the process/thread lists yet. Change copy_process() to update the child's TIF_SYSCALL_TRACEPOINT under tasklist. Link: http://lkml.kernel.org/p/20140413185854.GB20668@redhat.com Cc: stable@vger.kernel.org # 2.6.33 Fixes: a871bd33a6c0 "tracing: Add syscall tracepoints" Acked-by: Frederic Weisbecker Acked-by: Paul E. McKenney Signed-off-by: Oleg Nesterov Signed-off-by: Steven Rostedt --- include/trace/syscall.h | 15 +++++++++++++++ 1 file changed, 15 insertions(+) (limited to 'include/trace') diff --git a/include/trace/syscall.h b/include/trace/syscall.h index fed853f3d7aa..9674145e2f6a 100644 --- a/include/trace/syscall.h +++ b/include/trace/syscall.h @@ -4,6 +4,7 @@ #include #include #include +#include #include @@ -32,4 +33,18 @@ struct syscall_metadata { struct ftrace_event_call *exit_event; }; +#if defined(CONFIG_TRACEPOINTS) && defined(CONFIG_HAVE_SYSCALL_TRACEPOINTS) +static inline void syscall_tracepoint_update(struct task_struct *p) +{ + if (test_thread_flag(TIF_SYSCALL_TRACEPOINT)) + set_tsk_thread_flag(p, TIF_SYSCALL_TRACEPOINT); + else + clear_tsk_thread_flag(p, TIF_SYSCALL_TRACEPOINT); +} +#else +static inline void syscall_tracepoint_update(struct task_struct *p) +{ +} +#endif + #endif /* _TRACE_SYSCALL_H */ -- cgit v1.2.3 From 4d4c9cc839a308be3289a361ccba4447ee140552 Mon Sep 17 00:00:00 2001 From: Steven Rostedt Date: Tue, 17 Jun 2014 08:59:16 -0400 Subject: tracing: Add __field_struct macro for TRACE_EVENT() Currently the __field() macro in TRACE_EVENT is only good for primitive values, such as integers and pointers, but it fails on complex data types such as structures or unions. This is because the __field() macro determines if the variable is signed or not with the test of: (((type)(-1)) < (type)1) Unfortunately, that fails when type is a structure. Since trace events should support structures as fields a new macro is created for such a case called __field_struct() which acts exactly the same as __field() does but it does not do the signed type check and just uses a constant false for that answer. Cc: Tony Luck Signed-off-by: Steven Rostedt --- include/trace/ftrace.h | 33 +++++++++++++++++++++++++++++++++ 1 file changed, 33 insertions(+) (limited to 'include/trace') diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h index 0fd06fef9fac..26b4f2e13275 100644 --- a/include/trace/ftrace.h +++ b/include/trace/ftrace.h @@ -44,6 +44,12 @@ #undef __field_ext #define __field_ext(type, item, filter_type) type item; +#undef __field_struct +#define __field_struct(type, item) type item; + +#undef __field_struct_ext +#define __field_struct_ext(type, item, filter_type) type item; + #undef __array #define __array(type, item, len) type item[len]; @@ -122,6 +128,12 @@ #undef __field_ext #define __field_ext(type, item, filter_type) +#undef __field_struct +#define __field_struct(type, item) + +#undef __field_struct_ext +#define __field_struct_ext(type, item, filter_type) + #undef __array #define __array(type, item, len) @@ -315,9 +327,21 @@ static struct trace_event_functions ftrace_event_type_funcs_##call = { \ if (ret) \ return ret; +#undef __field_struct_ext +#define __field_struct_ext(type, item, filter_type) \ + ret = trace_define_field(event_call, #type, #item, \ + offsetof(typeof(field), item), \ + sizeof(field.item), \ + 0, filter_type); \ + if (ret) \ + return ret; + #undef __field #define __field(type, item) __field_ext(type, item, FILTER_OTHER) +#undef __field_struct +#define __field_struct(type, item) __field_struct_ext(type, item, FILTER_OTHER) + #undef __array #define __array(type, item, len) \ do { \ @@ -379,6 +403,12 @@ ftrace_define_fields_##call(struct ftrace_event_call *event_call) \ #undef __field_ext #define __field_ext(type, item, filter_type) +#undef __field_struct +#define __field_struct(type, item) + +#undef __field_struct_ext +#define __field_struct_ext(type, item, filter_type) + #undef __array #define __array(type, item, len) @@ -550,6 +580,9 @@ static inline notrace int ftrace_get_offsets_##call( \ #undef __field #define __field(type, item) +#undef __field_struct +#define __field_struct(type, item) + #undef __array #define __array(type, item, len) -- cgit v1.2.3