Skip to contentSkip to conversation

tracing: updates

GIT PULL In review Steven Rostedt 2 participants 16 messages Feb 8, 2011 – Feb 17, 2011

Subsystems (7)
Documentation Tracing ABI/API ftrace +3 more subsystems
lore
Share & tools
lore

Steven Rostedt

author maintainer
#0 lore raw

Ingo,

Please pull the latest tip/perf/core tree, which can be found at:

git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/perf/core

Ian Munsie (5):
tracing/syscalls: Don't add events for unmapped syscalls tracing/syscalls: Convert redundant syscall_nr checks into WARN_ON tracing/syscalls: Make arch_syscall_addr weak tracing/syscalls: Allow arch specific syscall symbol matching tracing/syscalls: Early terminate search for sys_ni_syscall

Jiri Olsa (1):
tracing: Add unstable sched clock note to the warning

Lai Jiangshan (1):
tracing: Compile time initialization for event flags value

Steven Rostedt (2):
tracing: Remove obsolete sched_switch tracer
tracing: Deprecate tracing_enabled for tracing_on

Uwe Kleine-König (1):
trivial: Fix Steven's Copyright typos

----

 Documentation/trace/ftrace-design.txt |    7 ++
 Documentation/trace/ftrace.txt        |  148 ++++----------------------------
 include/linux/syscalls.h              |   10 ++-
 kernel/trace/ring_buffer.c            |    8 ++-
 kernel/trace/trace.c                  |    4 +
 kernel/trace/trace_sched_switch.c     |   48 -----------
 kernel/trace/trace_syscalls.c         |   42 +++++++---
 scripts/kconfig/streamline_config.pl  |    2 +-
 tools/testing/ktest/ktest.pl          |    2 +-
 9 files changed, 74 insertions(+), 197 deletions(-)
author maintainer
#1 lore raw

PATCH 1/10 tracing/syscalls: Dont add events for unmapped syscalls

From: Ian Munsie <[email protected]>

FTRACE_SYSCALLS would create events for each and every system call, even if it had failed to map the system call's name with it's number. This resulted in a number of events being created that would not behave as expected.

This could happen, for example, on architectures who's symbol names are unusual and will not match the system call name. It could also happen with system calls which were mapped to sys_ni_syscall.

This patch changes the default system call number in the metadata to -1. If the system call name from the metadata is not successfully mapped to a system call number during boot, than the event initialisation routine will now return an error, preventing the event from being created.

Signed-off-by Ian Munsie <[email protected]>

LKML-Reference: <[email protected]>

Signed-off-by Steven Rostedt <[email protected]>
---
 include/linux/syscalls.h      |    2 ++
 kernel/trace/trace_syscalls.c |    8 ++++++++
 2 files changed, 10 insertions(+), 0 deletions(-)
include/linux/syscalls.h +2 -0
index 98664db..8e8968e 100644
@@ -158,6 +158,7 @@ extern struct trace_event_functions exit_syscall_print_funcs;
 	static struct syscall_metadata __used			\
 	  __syscall_meta_##sname = {				\
 		.name 		= "sys"#sname,			\
+		.syscall_nr	= -1,	/* Filled in at boot */	\
 		.nb_args 	= nb,				\
 		.types		= types_##sname,		\
 		.args		= args_##sname,			\

@@ -175,6 +176,7 @@ extern struct trace_event_functions exit_syscall_print_funcs;
 	static struct syscall_metadata __used			\
 	  __syscall_meta__##sname = {				\
 		.name 		= "sys_"#sname,			\
+		.syscall_nr	= -1,	/* Filled in at boot */	\
 		.nb_args 	= 0,				\
 		.enter_event	= &event_enter__##sname,	\
 		.exit_event	= &event_exit__##sname,		\
kernel/trace/trace_syscalls.c +8 -0
index 5c9fe08..a9ceabd 100644
@@ -424,6 +424,14 @@ void unreg_event_syscall_exit(struct ftrace_event_call *call)
 int init_syscall_trace(struct ftrace_event_call *call)
 {
 	int id;
+	int num;
+
+	num = ((struct syscall_metadata *)call->data)->syscall_nr;
+	if (num < 0 || num >= NR_syscalls) {
+		pr_debug("syscall %s metadata not mapped, disabling ftrace event\n",
+				((struct syscall_metadata *)call->data)->name);
+		return -ENOSYS;
+	}
 
 	if (set_syscall_print_fmt(call) < 0)
 		return -ENOMEM;
Signature · 1 line
1.7.2.3
author maintainer
#2 lore raw

PATCH 2/10 tracing/syscalls: Convert redundant syscall_nr checks into WARN_ON

In reply to Steven Rostedt

From: Ian Munsie <[email protected]>

With the ftrace events now checking if the syscall_nr is valid upon initialisation it should no longer be possible to register or unregister a syscall event without a valid syscall_nr since they should not be created. This adds a WARN_ON_ONCE in the register and unregister functions to locate potential regressions in the future.

Signed-off-by Ian Munsie <[email protected]>

LKML-Reference: <[email protected]>

Signed-off-by Steven Rostedt <[email protected]>
---
 kernel/trace/trace_syscalls.c |    8 ++++----
 1 files changed, 4 insertions(+), 4 deletions(-)
kernel/trace/trace_syscalls.c +4 -4
index a9ceabd..4230942 100644
@@ -359,7 +359,7 @@ int reg_event_syscall_enter(struct ftrace_event_call *call)
 	int num;
 
 	num = ((struct syscall_metadata *)call->data)->syscall_nr;
-	if (num < 0 || num >= NR_syscalls)
+	if (WARN_ON_ONCE(num < 0 || num >= NR_syscalls))
 		return -ENOSYS;
 	mutex_lock(&syscall_trace_lock);
 	if (!sys_refcount_enter)

@@ -377,7 +377,7 @@ void unreg_event_syscall_enter(struct ftrace_event_call *call)
 	int num;
 
 	num = ((struct syscall_metadata *)call->data)->syscall_nr;
-	if (num < 0 || num >= NR_syscalls)
+	if (WARN_ON_ONCE(num < 0 || num >= NR_syscalls))
 		return;
 	mutex_lock(&syscall_trace_lock);
 	sys_refcount_enter--;

@@ -393,7 +393,7 @@ int reg_event_syscall_exit(struct ftrace_event_call *call)
 	int num;
 
 	num = ((struct syscall_metadata *)call->data)->syscall_nr;
-	if (num < 0 || num >= NR_syscalls)
+	if (WARN_ON_ONCE(num < 0 || num >= NR_syscalls))
 		return -ENOSYS;
 	mutex_lock(&syscall_trace_lock);
 	if (!sys_refcount_exit)

@@ -411,7 +411,7 @@ void unreg_event_syscall_exit(struct ftrace_event_call *call)
 	int num;
 
 	num = ((struct syscall_metadata *)call->data)->syscall_nr;
-	if (num < 0 || num >= NR_syscalls)
+	if (WARN_ON_ONCE(num < 0 || num >= NR_syscalls))
 		return;
 	mutex_lock(&syscall_trace_lock);
 	sys_refcount_exit--;
Signature · 1 line
1.7.2.3
author maintainer
#3 lore raw

PATCH 3/10 tracing/syscalls: Make arch_syscall_addr weak

In reply to Steven Rostedt

From: Ian Munsie <[email protected]>

Some architectures use non-trivial system call tables and will not work with the generic arch_syscall_addr code. For example, PowerPC64 uses a table of twin long longs.

This patch makes the generic arch_syscall_addr weak to allow architectures with non-trivial system call tables to override it.

Signed-off-by Ian Munsie <[email protected]>

LKML-Reference: <[email protected]>

Signed-off-by Steven Rostedt <[email protected]>
---
 Documentation/trace/ftrace-design.txt |    3 +++
 kernel/trace/trace_syscalls.c         |    2 +-
 2 files changed, 4 insertions(+), 1 deletions(-)
Documentation/trace/ftrace-design.txt +3 -0
index dc52bd4..6fca17b 100644
@@ -247,6 +247,9 @@ You need very few things to get the syscalls tracing in an arch.
 - Support the TIF_SYSCALL_TRACEPOINT thread flags.
 - Put the trace_sys_enter() and trace_sys_exit() tracepoints calls from ptrace
   in the ptrace syscalls tracing path.
+- If the system call table on this arch is more complicated than a simple array
+  of addresses of the system calls, implement an arch_syscall_addr to return
+  the address of a given system call.
 - Tag this arch as HAVE_SYSCALL_TRACEPOINTS.
kernel/trace/trace_syscalls.c +1 -1
index 4230942..af83154 100644
@@ -446,7 +446,7 @@ int init_syscall_trace(struct ftrace_event_call *call)
 	return id;
 }
 
-unsigned long __init arch_syscall_addr(int nr)
+unsigned long __init __weak arch_syscall_addr(int nr)
 {
 	return (unsigned long)sys_call_table[nr];
 }
Signature · 1 line
1.7.2.3
author maintainer
#4 lore raw

PATCH 4/10 tracing/syscalls: Allow arch specific syscall symbol matching

In reply to Steven Rostedt

From: Ian Munsie <[email protected]>

Some architectures have unusual symbol names and the generic code to match the symbol name with the function name for the syscall metadata will fail. For example, symbols on PPC64 start with a period and the generic code will fail to match them.

This patch moves the match logic out into a separate function which an arch can override by defining ARCH_HAS_SYSCALL_MATCH_SYM_NAME in asm/ftrace.h and implementing arch_syscall_match_sym_name.

Signed-off-by Ian Munsie <[email protected]>

LKML-Reference: <[email protected]>

Signed-off-by Steven Rostedt <[email protected]>
---
 Documentation/trace/ftrace-design.txt |    4 ++++
 kernel/trace/trace_syscalls.c         |   21 ++++++++++++++-------
 2 files changed, 18 insertions(+), 7 deletions(-)
Documentation/trace/ftrace-design.txt +4 -0
index 6fca17b..79fcafc 100644
@@ -250,6 +250,10 @@ You need very few things to get the syscalls tracing in an arch.
 - If the system call table on this arch is more complicated than a simple array
   of addresses of the system calls, implement an arch_syscall_addr to return
   the address of a given system call.
+- If the symbol names of the system calls do not match the function names on
+  this arch, define ARCH_HAS_SYSCALL_MATCH_SYM_NAME in asm/ftrace.h and
+  implement arch_syscall_match_sym_name with the appropriate logic to return
+  true if the function name corresponds with the symbol name.
 - Tag this arch as HAVE_SYSCALL_TRACEPOINTS.
kernel/trace/trace_syscalls.c +14 -7
index af83154..86a23e7 100644
@@ -60,6 +60,19 @@ extern struct syscall_metadata *__stop_syscalls_metadata[];
 
 static struct syscall_metadata **syscalls_metadata;
 
+#ifndef ARCH_HAS_SYSCALL_MATCH_SYM_NAME
+static inline bool arch_syscall_match_sym_name(const char *sym, const char *name)
+{
+	/*
+	 * Only compare after the "sys" prefix. Archs that use
+	 * syscall wrappers may have syscalls symbols aliases prefixed
+	 * with "SyS" instead of "sys", leading to an unwanted
+	 * mismatch.
+	 */
+	return !strcmp(sym + 3, name + 3);
+}
+#endif
+
 static __init struct syscall_metadata *
 find_syscall_meta(unsigned long syscall)
 {

@@ -73,13 +86,7 @@ find_syscall_meta(unsigned long syscall)
 	kallsyms_lookup(syscall, NULL, NULL, NULL, str);
 
 	for ( ; start < stop; start++) {
-		/*
-		 * Only compare after the "sys" prefix. Archs that use
-		 * syscall wrappers may have syscalls symbols aliases prefixed
-		 * with "SyS" instead of "sys", leading to an unwanted
-		 * mismatch.
-		 */
-		if ((*start)->name && !strcmp((*start)->name + 3, str + 3))
+		if ((*start)->name && arch_syscall_match_sym_name(str, (*start)->name))
 			return *start;
 	}
 	return NULL;
Signature · 1 line
1.7.2.3
author maintainer
#5 lore raw

PATCH 5/10 tracing/syscalls: Early terminate search for sys_ni_syscall

In reply to Steven Rostedt

From: Ian Munsie <[email protected]>

Many system calls are unimplemented and mapped to sys_ni_syscall, but at boot ftrace would still search through every syscall metadata entry for a match which wouldn't be there.

This patch adds causes the search to terminate early if the system call is not mapped.

Signed-off-by Ian Munsie <[email protected]>

LKML-Reference: <[email protected]>

Signed-off-by Steven Rostedt <[email protected]>
---
 kernel/trace/trace_syscalls.c |    3 +++
 1 files changed, 3 insertions(+), 0 deletions(-)
kernel/trace/trace_syscalls.c +3 -0
index 86a23e7..ee7b5a0 100644
@@ -85,6 +85,9 @@ find_syscall_meta(unsigned long syscall)
 	stop = __stop_syscalls_metadata;
 	kallsyms_lookup(syscall, NULL, NULL, NULL, str);
 
+	if (arch_syscall_match_sym_name(str, "sys_ni_syscall"))
+		return NULL;
+
 	for ( ; start < stop; start++) {
 		if ((*start)->name && arch_syscall_match_sym_name(str, (*start)->name))
 			return *start;
Signature · 1 line
1.7.2.3
author maintainer
#6 lore raw

PATCH 6/10 tracing: Add unstable sched clock note to the warning

In reply to Steven Rostedt

From: Jiri Olsa <[email protected]>

The warning "Delta way too big" warning might appear on a system with unstable shed clock right after the system is resumed and tracing was enabled during the suspend.

Since it's not realy bug, and the unstable sched clock is working fast and reliable otherwise, Steven suggested to keep using the sched clock in any case and just to make note in the warning itself.

Signed-off-by Jiri Olsa <[email protected]>

LKML-Reference: <[email protected]>

Signed-off-by Steven Rostedt <[email protected]>
---
 kernel/trace/ring_buffer.c |    8 ++++++--
 1 files changed, 6 insertions(+), 2 deletions(-)
kernel/trace/ring_buffer.c +6 -2
index bd1c35a..7739893 100644
@@ -2163,10 +2163,14 @@ rb_reserve_next_event(struct ring_buffer *buffer,
 		delta = diff;
 		if (unlikely(test_time_stamp(delta))) {
 			WARN_ONCE(delta > (1ULL << 59),
-				  KERN_WARNING "Delta way too big! %llu ts=%llu write stamp = %llu\n",
+				  KERN_WARNING "Delta way too big! %llu ts=%llu write stamp = %llu\n%s",
 				  (unsigned long long)delta,
 				  (unsigned long long)ts,
-				  (unsigned long long)cpu_buffer->write_stamp);
+				  (unsigned long long)cpu_buffer->write_stamp,
+				  sched_clock_stable ? "" :
+				  "If you just came from a suspend/resume,\n"
+				  "please switch to the trace global clock:\n"
+				  "  echo global > /sys/kernel/debug/tracing/trace_clock\n");
 			add_timestamp = 1;
 		}
 	}
Signature · 1 line
1.7.2.3
author maintainer
#7 lore raw

PATCH 7/10 trivial: Fix Stevens Copyright typos

In reply to Steven Rostedt

From: =?UTF-8?q?Uwe=20Kleine-K=C3=B6nig?= <[email protected]>

OK, the copyright allows you to write a copy, still I think the lawyers prefer the correct spelling.

Signed-off-by Uwe Kleine-König <[email protected]>

LKML-Reference: <[email protected]>

Signed-off-by Steven Rostedt <[email protected]>
---
 scripts/kconfig/streamline_config.pl |    2 +-
 tools/testing/ktest/ktest.pl         |    2 +-
 2 files changed, 2 insertions(+), 2 deletions(-)
scripts/kconfig/streamline_config.pl +1 -1
index fd81fc3..a4fe923 100644
@@ -1,6 +1,6 @@
 #!/usr/bin/perl -w
 #
-# Copywrite 2005-2009 - Steven Rostedt
+# Copyright 2005-2009 - Steven Rostedt
 # Licensed under the terms of the GNU GPL License version 2
 #
 #  It's simple enough to figure out how this works.
tools/testing/ktest/ktest.pl +1 -1
index e1c62ee..ba7c63a 100755
@@ -1,6 +1,6 @@
 #!/usr/bin/perl -w
 #
-# Copywrite 2010 - Steven Rostedt <[email protected]>, Red Hat Inc.
+# Copyright 2010 - Steven Rostedt <[email protected]>, Red Hat Inc.
 # Licensed under the terms of the GNU GPL License version 2
 #
Signature · 1 line
1.7.2.3
author maintainer
#8 lore raw

PATCH 8/10 tracing: Compile time initialization for event flags value

In reply to Steven Rostedt

From: Lai Jiangshan <[email protected]>

Compile time initialization is better than runtime initialization.

Remove many early_initcall()s and many trace_init_flags_##name()s.

Acked-by Frederic Weisbecker <[email protected]>
Signed-off-by Lai Jiangshan <[email protected]>

LKML-Reference: <[email protected]>

Signed-off-by Steven Rostedt <[email protected]>
---
 include/linux/syscalls.h |    8 ++++----
 1 files changed, 4 insertions(+), 4 deletions(-)
include/linux/syscalls.h +4 -4
index 8e8968e..a17fcea 100644
@@ -132,11 +132,11 @@ extern struct trace_event_functions exit_syscall_print_funcs;
 		.class			= &event_class_syscall_enter,	\
 		.event.funcs            = &enter_syscall_print_funcs,	\
 		.data			= (void *)&__syscall_meta_##sname,\
+		.flags			= TRACE_EVENT_FL_CAP_ANY,	\
 	};								\
 	static struct ftrace_event_call __used				\
 	  __attribute__((section("_ftrace_events")))			\
-	 *__event_enter_##sname = &event_enter_##sname;			\
-	__TRACE_EVENT_FLAGS(enter_##sname, TRACE_EVENT_FL_CAP_ANY)
+	 *__event_enter_##sname = &event_enter_##sname;
 
 #define SYSCALL_TRACE_EXIT_EVENT(sname)					\
 	static struct syscall_metadata __syscall_meta_##sname;		\

@@ -146,11 +146,11 @@ extern struct trace_event_functions exit_syscall_print_funcs;
 		.class			= &event_class_syscall_exit,	\
 		.event.funcs		= &exit_syscall_print_funcs,	\
 		.data			= (void *)&__syscall_meta_##sname,\
+		.flags			= TRACE_EVENT_FL_CAP_ANY,	\
 	};								\
 	static struct ftrace_event_call __used				\
 	  __attribute__((section("_ftrace_events")))			\
-	*__event_exit_##sname = &event_exit_##sname;			\
-	__TRACE_EVENT_FLAGS(exit_##sname, TRACE_EVENT_FL_CAP_ANY)
+	*__event_exit_##sname = &event_exit_##sname;
 
 #define SYSCALL_METADATA(sname, nb)				\
 	SYSCALL_TRACE_ENTER_EVENT(sname);			\
Signature · 1 line
1.7.2.3
author maintainer
#9 lore raw

PATCH 9/10 tracing: Remove obsolete sched_switch tracer

In reply to Steven Rostedt

From: Steven Rostedt <[email protected]>

The trace events sched_switch and sched_wakeup do the same thing as the stand alone sched_switch tracer does. It is no longer needed.

Signed-off-by Steven Rostedt <[email protected]>
---
 Documentation/trace/ftrace.txt    |  110 -------------------------------------
 kernel/trace/trace_sched_switch.c |   48 ----------------
 2 files changed, 0 insertions(+), 158 deletions(-)
Documentation/trace/ftrace.txt +0 -110
index 557c1ed..65eddb7 100644
@@ -202,10 +202,6 @@ Here is the list of current tracers that may be configured.
 	to draw a graph of function calls similar to C code
 	source.
 
-  "sched_switch"
-
-	Traces the context switches and wakeups between tasks.
-
   "irqsoff"
 
 	Traces the areas that disable interrupts and saves

@@ -273,39 +269,6 @@ format, the function name that was traced "path_put" and the
 parent function that called this function "path_walk". The
 timestamp is the time at which the function was entered.
 
-The sched_switch tracer also includes tracing of task wakeups
-and context switches.
-
-     ksoftirqd/1-7     [01]  1453.070013:      7:115:R   +  2916:115:S
-     ksoftirqd/1-7     [01]  1453.070013:      7:115:R   +    10:115:S
-     ksoftirqd/1-7     [01]  1453.070013:      7:115:R ==>    10:115:R
-        events/1-10    [01]  1453.070013:     10:115:S ==>  2916:115:R
-     kondemand/1-2916  [01]  1453.070013:   2916:115:S ==>     7:115:R
-     ksoftirqd/1-7     [01]  1453.070013:      7:115:S ==>     0:140:R
-
-Wake ups are represented by a "+" and the context switches are
-shown as "==>".  The format is:
-
- Context switches:
-
-       Previous task              Next Task
-
-  <pid>:<prio>:<state>  ==>  <pid>:<prio>:<state>
-
- Wake ups:
-
-       Current task               Task waking up
-
-  <pid>:<prio>:<state>    +  <pid>:<prio>:<state>
-
-The prio is the internal kernel priority, which is the inverse
-of the priority that is usually displayed by user-space tools.
-Zero represents the highest priority (99). Prio 100 starts the
-"nice" priorities with 100 being equal to nice -20 and 139 being
-nice 19. The prio "140" is reserved for the idle task which is
-the lowest priority thread (pid 0).
-
-
 Latency trace format
 --------------------
 

@@ -491,79 +454,6 @@ x494] <- /root/a.out[+0x4a8] <- /lib/libc-2.7.so[+0x1e1a6]
                    latencies, as described in "Latency
                    trace format".
 
-sched_switch
-------------
-
-This tracer simply records schedule switches. Here is an example
-of how to use it.
-
- # echo sched_switch > current_tracer
- # echo 1 > tracing_enabled
- # sleep 1
- # echo 0 > tracing_enabled
- # cat trace
-
-# tracer: sched_switch
-#
-#           TASK-PID   CPU#    TIMESTAMP  FUNCTION
-#              | |      |          |         |
-            bash-3997  [01]   240.132281:   3997:120:R   +  4055:120:R
-            bash-3997  [01]   240.132284:   3997:120:R ==>  4055:120:R
-           sleep-4055  [01]   240.132371:   4055:120:S ==>  3997:120:R
-            bash-3997  [01]   240.132454:   3997:120:R   +  4055:120:S
-            bash-3997  [01]   240.132457:   3997:120:R ==>  4055:120:R
-           sleep-4055  [01]   240.132460:   4055:120:D ==>  3997:120:R
-            bash-3997  [01]   240.132463:   3997:120:R   +  4055:120:D
-            bash-3997  [01]   240.132465:   3997:120:R ==>  4055:120:R
-          <idle>-0     [00]   240.132589:      0:140:R   +     4:115:S
-          <idle>-0     [00]   240.132591:      0:140:R ==>     4:115:R
-     ksoftirqd/0-4     [00]   240.132595:      4:115:S ==>     0:140:R
-          <idle>-0     [00]   240.132598:      0:140:R   +     4:115:S
-          <idle>-0     [00]   240.132599:      0:140:R ==>     4:115:R
-     ksoftirqd/0-4     [00]   240.132603:      4:115:S ==>     0:140:R
-           sleep-4055  [01]   240.133058:   4055:120:S ==>  3997:120:R
- [...]
-
-
-As we have discussed previously about this format, the header
-shows the name of the trace and points to the options. The
-"FUNCTION" is a misnomer since here it represents the wake ups
-and context switches.
-
-The sched_switch file only lists the wake ups (represented with
-'+') and context switches ('==>') with the previous task or
-current task first followed by the next task or task waking up.
-The format for both of these is PID:KERNEL-PRIO:TASK-STATE.
-Remember that the KERNEL-PRIO is the inverse of the actual
-priority with zero (0) being the highest priority and the nice
-values starting at 100 (nice -20). Below is a quick chart to map
-the kernel priority to user land priorities.
-
-   Kernel Space                     User Space
- ===============================================================
-   0(high) to  98(low)     user RT priority 99(high) to 1(low)
-                           with SCHED_RR or SCHED_FIFO
- ---------------------------------------------------------------
-  99                       sched_priority is not used in scheduling
-                           decisions(it must be specified as 0)
- ---------------------------------------------------------------
- 100(high) to 139(low)     user nice -20(high) to 19(low)
- ---------------------------------------------------------------
- 140                       idle task priority
- ---------------------------------------------------------------
-
-The task states are:
-
- R - running : wants to run, may not actually be running
- S - sleep   : process is waiting to be woken up (handles signals)
- D - disk sleep (uninterruptible sleep) : process must be woken up
-					(ignores signals)
- T - stopped : process suspended
- t - traced  : process is being traced (with something like gdb)
- Z - zombie  : process waiting to be cleaned up
- X - unknown
-
-
 ftrace_enabled
 --------------
kernel/trace/trace_sched_switch.c +0 -48

51 lines not on this page · raw message

Signature · 1 line
1.7.2.3
author maintainer
#10 lore raw

Re: [PATCH 09/10] tracing: Remove obsolete sched_switch tracer

Quoted 6 lines · Steven Rostedt

plain text document attachment (0009-tracing-Remove-obsolete-sched_switch-tracer.patch)
From: Steven Rostedt <[email protected]>

The trace events sched_switch and sched_wakeup do the same thing as the stand alone sched_switch tracer does. It is no longer needed.

Hmm, is this the right thing to do, or should we do the "WARN_ONCE()" when it is used, and give it a year to remove it?

-- Steve

Quoted 198 lines
Signed-off-by Steven Rostedt <[email protected]>
---
 Documentation/trace/ftrace.txt    |  110 -------------------------------------
 kernel/trace/trace_sched_switch.c |   48 ----------------
 2 files changed, 0 insertions(+), 158 deletions(-)
Documentation/trace/ftrace.txt +0 -110
index 557c1ed..65eddb7 100644
@@ -202,10 +202,6 @@ Here is the list of current tracers that may be configured.
 	to draw a graph of function calls similar to C code
 	source.
 
-  "sched_switch"
-
-	Traces the context switches and wakeups between tasks.
-
   "irqsoff"
 
 	Traces the areas that disable interrupts and saves

@@ -273,39 +269,6 @@ format, the function name that was traced "path_put" and the
 parent function that called this function "path_walk". The
 timestamp is the time at which the function was entered.
 
-The sched_switch tracer also includes tracing of task wakeups
-and context switches.
-
-     ksoftirqd/1-7     [01]  1453.070013:      7:115:R   +  2916:115:S
-     ksoftirqd/1-7     [01]  1453.070013:      7:115:R   +    10:115:S
-     ksoftirqd/1-7     [01]  1453.070013:      7:115:R ==>    10:115:R
-        events/1-10    [01]  1453.070013:     10:115:S ==>  2916:115:R
-     kondemand/1-2916  [01]  1453.070013:   2916:115:S ==>     7:115:R
-     ksoftirqd/1-7     [01]  1453.070013:      7:115:S ==>     0:140:R
-
-Wake ups are represented by a "+" and the context switches are
-shown as "==>".  The format is:
-
- Context switches:
-
-       Previous task              Next Task
-
-  <pid>:<prio>:<state>  ==>  <pid>:<prio>:<state>
-
- Wake ups:
-
-       Current task               Task waking up
-
-  <pid>:<prio>:<state>    +  <pid>:<prio>:<state>
-
-The prio is the internal kernel priority, which is the inverse
-of the priority that is usually displayed by user-space tools.
-Zero represents the highest priority (99). Prio 100 starts the
-"nice" priorities with 100 being equal to nice -20 and 139 being
-nice 19. The prio "140" is reserved for the idle task which is
-the lowest priority thread (pid 0).
-
-
 Latency trace format
 --------------------
 

@@ -491,79 +454,6 @@ x494] <- /root/a.out[+0x4a8] <- /lib/libc-2.7.so[+0x1e1a6]
                    latencies, as described in "Latency
                    trace format".
 
-sched_switch
-------------
-
-This tracer simply records schedule switches. Here is an example
-of how to use it.
-
- # echo sched_switch > current_tracer
- # echo 1 > tracing_enabled
- # sleep 1
- # echo 0 > tracing_enabled
- # cat trace
-
-# tracer: sched_switch
-#
-#           TASK-PID   CPU#    TIMESTAMP  FUNCTION
-#              | |      |          |         |
-            bash-3997  [01]   240.132281:   3997:120:R   +  4055:120:R
-            bash-3997  [01]   240.132284:   3997:120:R ==>  4055:120:R
-           sleep-4055  [01]   240.132371:   4055:120:S ==>  3997:120:R
-            bash-3997  [01]   240.132454:   3997:120:R   +  4055:120:S
-            bash-3997  [01]   240.132457:   3997:120:R ==>  4055:120:R
-           sleep-4055  [01]   240.132460:   4055:120:D ==>  3997:120:R
-            bash-3997  [01]   240.132463:   3997:120:R   +  4055:120:D
-            bash-3997  [01]   240.132465:   3997:120:R ==>  4055:120:R
-          <idle>-0     [00]   240.132589:      0:140:R   +     4:115:S
-          <idle>-0     [00]   240.132591:      0:140:R ==>     4:115:R
-     ksoftirqd/0-4     [00]   240.132595:      4:115:S ==>     0:140:R
-          <idle>-0     [00]   240.132598:      0:140:R   +     4:115:S
-          <idle>-0     [00]   240.132599:      0:140:R ==>     4:115:R
-     ksoftirqd/0-4     [00]   240.132603:      4:115:S ==>     0:140:R
-           sleep-4055  [01]   240.133058:   4055:120:S ==>  3997:120:R
- [...]
-
-
-As we have discussed previously about this format, the header
-shows the name of the trace and points to the options. The
-"FUNCTION" is a misnomer since here it represents the wake ups
-and context switches.
-
-The sched_switch file only lists the wake ups (represented with
-'+') and context switches ('==>') with the previous task or
-current task first followed by the next task or task waking up.
-The format for both of these is PID:KERNEL-PRIO:TASK-STATE.
-Remember that the KERNEL-PRIO is the inverse of the actual
-priority with zero (0) being the highest priority and the nice
-values starting at 100 (nice -20). Below is a quick chart to map
-the kernel priority to user land priorities.
-
-   Kernel Space                     User Space
- ===============================================================
-   0(high) to  98(low)     user RT priority 99(high) to 1(low)
-                           with SCHED_RR or SCHED_FIFO
- ---------------------------------------------------------------
-  99                       sched_priority is not used in scheduling
-                           decisions(it must be specified as 0)
- ---------------------------------------------------------------
- 100(high) to 139(low)     user nice -20(high) to 19(low)
- ---------------------------------------------------------------
- 140                       idle task priority
- ---------------------------------------------------------------
-
-The task states are:
-
- R - running : wants to run, may not actually be running
- S - sleep   : process is waiting to be woken up (handles signals)
- D - disk sleep (uninterruptible sleep) : process must be woken up
-					(ignores signals)
- T - stopped : process suspended
- t - traced  : process is being traced (with something like gdb)
- Z - zombie  : process waiting to be cleaned up
- X - unknown
-
-
 ftrace_enabled
 --------------
kernel/trace/trace_sched_switch.c +0 -48
index 8f758d0..7e62c0a 100644
@@ -247,51 +247,3 @@ void tracing_sched_switch_assign_trace(struct trace_array *tr)
 	ctx_trace = tr;
 }
 
-static void stop_sched_trace(struct trace_array *tr)
-{
-	tracing_stop_sched_switch_record();
-}
-
-static int sched_switch_trace_init(struct trace_array *tr)
-{
-	ctx_trace = tr;
-	tracing_reset_online_cpus(tr);
-	tracing_start_sched_switch_record();
-	return 0;
-}
-
-static void sched_switch_trace_reset(struct trace_array *tr)
-{
-	if (sched_ref)
-		stop_sched_trace(tr);
-}
-
-static void sched_switch_trace_start(struct trace_array *tr)
-{
-	sched_stopped = 0;
-}
-
-static void sched_switch_trace_stop(struct trace_array *tr)
-{
-	sched_stopped = 1;
-}
-
-static struct tracer sched_switch_trace __read_mostly =
-{
-	.name		= "sched_switch",
-	.init		= sched_switch_trace_init,
-	.reset		= sched_switch_trace_reset,
-	.start		= sched_switch_trace_start,
-	.stop		= sched_switch_trace_stop,
-	.wait_pipe	= poll_wait_pipe,
-#ifdef CONFIG_FTRACE_SELFTEST
-	.selftest    = trace_selftest_startup_sched_switch,
-#endif
-};
-
-__init static int init_sched_switch_trace(void)
-{
-	return register_tracer(&sched_switch_trace);
-}
-device_initcall(init_sched_switch_trace);
-
author maintainer
#11 lore raw

PATCH 10/10 tracing: Deprecate tracing_enabled for tracing_on

In reply to Steven Rostedt

From: Steven Rostedt <[email protected]>

tracing_enabled should not be used, it is heavy weight and does not do much in helping lower the overhead.

tracing_on should be used instead. Warn users to use tracing_on when tracing_enabled is used as it will soon be removed from the tracing directory.

Signed-off-by Steven Rostedt <[email protected]>
---
 Documentation/trace/ftrace.txt |   38 +++++++++++++++++++-------------------
 kernel/trace/trace.c           |    4 ++++
 2 files changed, 23 insertions(+), 19 deletions(-)
Documentation/trace/ftrace.txt +19 -19
index 65eddb7..67f1cc4 100644
@@ -80,11 +80,11 @@ of ftrace. Here is a list of some of the key files:
 	tracers listed here can be configured by
 	echoing their name into current_tracer.
 
-  tracing_enabled:
+  tracing_on:
 
-	This sets or displays whether the current_tracer
-	is activated and tracing or not. Echo 0 into this
-	file to disable the tracer or 1 to enable it.
+	This sets or displays whether writing to the trace
+	ring buffer is enabled. Echo 0 into this file to disable
+	the tracer or 1 to enable it.
 
   trace:
 

@@ -497,10 +497,10 @@ an example:
  # echo irqsoff > current_tracer
  # echo latency-format > trace_options
  # echo 0 > tracing_max_latency
- # echo 1 > tracing_enabled
+ # echo 1 > tracing_on
  # ls -ltr
  [...]
- # echo 0 > tracing_enabled
+ # echo 0 > tracing_on
  # cat trace
 # tracer: irqsoff
 #

@@ -605,10 +605,10 @@ is much like the irqsoff tracer.
  # echo preemptoff > current_tracer
  # echo latency-format > trace_options
  # echo 0 > tracing_max_latency
- # echo 1 > tracing_enabled
+ # echo 1 > tracing_on
  # ls -ltr
  [...]
- # echo 0 > tracing_enabled
+ # echo 0 > tracing_on
  # cat trace
 # tracer: preemptoff
 #

@@ -753,10 +753,10 @@ tracers.
  # echo preemptirqsoff > current_tracer
  # echo latency-format > trace_options
  # echo 0 > tracing_max_latency
- # echo 1 > tracing_enabled
+ # echo 1 > tracing_on
  # ls -ltr
  [...]
- # echo 0 > tracing_enabled
+ # echo 0 > tracing_on
  # cat trace
 # tracer: preemptirqsoff
 #

@@ -916,9 +916,9 @@ Instead of performing an 'ls', we will run 'sleep 1' under
  # echo wakeup > current_tracer
  # echo latency-format > trace_options
  # echo 0 > tracing_max_latency
- # echo 1 > tracing_enabled
+ # echo 1 > tracing_on
  # chrt -f 5 sleep 1
- # echo 0 > tracing_enabled
+ # echo 0 > tracing_on
  # cat trace
 # tracer: wakeup
 #

@@ -1030,9 +1030,9 @@ ftrace_enabled is set; otherwise this tracer is a nop.
 
  # sysctl kernel.ftrace_enabled=1
  # echo function > current_tracer
- # echo 1 > tracing_enabled
+ # echo 1 > tracing_on
  # usleep 1
- # echo 0 > tracing_enabled
+ # echo 0 > tracing_on
  # cat trace
 # tracer: function
 #

@@ -1070,7 +1070,7 @@ int trace_fd;
 [...]
 int main(int argc, char *argv[]) {
 	[...]
-	trace_fd = open(tracing_file("tracing_enabled"), O_WRONLY);
+	trace_fd = open(tracing_file("tracing_on"), O_WRONLY);
 	[...]
 	if (condition_hit()) {
 		write(trace_fd, "0", 1);

@@ -1521,9 +1521,9 @@ If I am only interested in sys_nanosleep and hrtimer_interrupt:
  # echo sys_nanosleep hrtimer_interrupt \
 		> set_ftrace_filter
  # echo function > current_tracer
- # echo 1 > tracing_enabled
+ # echo 1 > tracing_on
  # usleep 1
- # echo 0 > tracing_enabled
+ # echo 0 > tracing_on
  # cat trace
 # tracer: ftrace
 #

@@ -1769,9 +1769,9 @@ different. The trace is live.
  # echo function > current_tracer
  # cat trace_pipe > /tmp/trace.out &
 [1] 4153
- # echo 1 > tracing_enabled
+ # echo 1 > tracing_on
  # usleep 1
- # echo 0 > tracing_enabled
+ # echo 0 > tracing_on
  # cat trace
 # tracer: function
 #
kernel/trace/trace.c +4 -0
index dc53ecb..8dc8da6 100644
@@ -2710,6 +2710,10 @@ tracing_ctrl_write(struct file *filp, const char __user *ubuf,
 
 	mutex_lock(&trace_types_lock);
 	if (tracer_enabled ^ val) {
+
+		/* Only need to warn if this is used to change the state */
+		WARN_ONCE(1, "tracing_enabled is deprecated. Use tracing_on");
+
 		if (val) {
 			tracer_enabled = 1;
 			if (current_trace->start)
Signature · 1 line
1.7.2.3
#12 lore raw
In reply to Steven Rostedt
Quoted 30 lines · Steven Rostedt

Ingo,

Please pull the latest tip/perf/core tree, which can be found at:

git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/perf/core

Ian Munsie (5):
tracing/syscalls: Don't add events for unmapped syscalls tracing/syscalls: Convert redundant syscall_nr checks into WARN_ON tracing/syscalls: Make arch_syscall_addr weak tracing/syscalls: Allow arch specific syscall symbol matching tracing/syscalls: Early terminate search for sys_ni_syscall

Jiri Olsa (1):
tracing: Add unstable sched clock note to the warning

Lai Jiangshan (1):
tracing: Compile time initialization for event flags value

Steven Rostedt (2):
tracing: Remove obsolete sched_switch tracer
tracing: Deprecate tracing_enabled for tracing_on

Uwe Kleine-König (1):
trivial: Fix Steven's Copyright typos

----

Quoted 10 lines
 Documentation/trace/ftrace-design.txt |    7 ++
 Documentation/trace/ftrace.txt        |  148 ++++----------------------------
 include/linux/syscalls.h              |   10 ++-
 kernel/trace/ring_buffer.c            |    8 ++-
 kernel/trace/trace.c                  |    4 +
 kernel/trace/trace_sched_switch.c     |   48 -----------
 kernel/trace/trace_syscalls.c         |   42 +++++++---
 scripts/kconfig/streamline_config.pl  |    2 +-
 tools/testing/ktest/ktest.pl          |    2 +-
 9 files changed, 74 insertions(+), 197 deletions(-)

Pulled, thanks a lot Steve!

Ingo

#13 lore raw
Quoted 5 lines
Quoted 5 lines

Please pull the latest tip/perf/core tree, which can be found at:

git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/perf/core

Note that these changes caused a new build failure on arch/m32r:

/home/mingo/tip/drivers/net/smc91x.h:199:1: warning: this is the location of the previous definition /home/mingo/tip/kernel/trace/ring_buffer.c: In function 'rb_reserve_next_event':
/home/mingo/tip/kernel/trace/ring_buffer.c:2165: error: 'sched_clock_stable' undeclared (first use in this function) /home/mingo/tip/kernel/trace/ring_buffer.c:2165: error: (Each undeclared identifier is reported only once /home/mingo/tip/kernel/trace/ring_buffer.c:2165: error: for each function it appears in.) make[3]: *** [kernel/trace/ring_buffer.o] Error 1
make[2]: *** [kernel/trace] Error 2

Thanks,

Ingo

#14 lore raw
Quoted 7 lines · Ingo Molnar
Quoted 5 lines
Quoted 5 lines

Please pull the latest tip/perf/core tree, which can be found at:

git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/perf/core

Note that these changes caused a new build failure on arch/m32r:

powerpc and parisc is showing similar build failures. The other architectures are fine.

So i suspect it relates to !CONFIG_HAVE_UNSTABLE_SCHED_CLOCK architectures and the fact that sched_clock_stable is not uniformly available. The right fix would be to provide that flag in a Kconfig-invariant fashion.

Thanks,

Ingo

author maintainer
#15 lore raw
In reply to Ingo Molnar
Quoted 7 lines · Ingo Molnar
Quoted 4 lines
Quoted 4 lines

Please pull the latest tip/perf/core tree, which can be found at:

git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git
tip/perf/core

Note that these changes caused a new build failure on arch/m32r:

Quoted 7 lines

/home/mingo/tip/drivers/net/smc91x.h:199:1: warning: this is the location of the previous definition /home/mingo/tip/kernel/trace/ring_buffer.c: In function 'rb_reserve_next_event':
/home/mingo/tip/kernel/trace/ring_buffer.c:2165: error: 'sched_clock_stable' undeclared (first use in this function) /home/mingo/tip/kernel/trace/ring_buffer.c:2165: error: (Each undeclared identifier is reported only once /home/mingo/tip/kernel/trace/ring_buffer.c:2165: error: for each function it appears in.) make[3]: *** [kernel/trace/ring_buffer.o] Error 1
make[2]: *** [kernel/trace] Error 2

Ah, patch "tracing: Add unstable sched clock note to the warning" referenced sched_clock_stable without encompassing it with:

#ifdef CONFIG_HAVE_UNSTABLE_SCHED_CLOCK

I wonder if we could instead in linux/sched.h add in the ifndef part:

#define sched_clock_stable 1

That way generic code can still reference this variable without having to litter the code with #ifdef's.

Thoughts?

-- Steve