LKML Archive on lore.kernel.org
 help / color / Atom feed
From: Steven Rostedt <rostedt@goodmis.org>
To: Petr Mladek <pmladek@suse.cz>
Cc: Tom Zanussi <tom.zanussi@linux.intel.com>,
	Jiri Kosina <jkosina@suse.cz>,
	linux-kernel@vger.kernel.org
Subject: Re: [BUG] ftrace: support for SOFT_DISABLE to syscall events caused huge slowdown of ftrace startup test
Date: Tue, 3 Dec 2013 12:41:20 -0500
Message-ID: <20131203124120.427b9661@gandalf.local.home> (raw)
In-Reply-To: <1386090969.1603.72.camel@pathway.suse.cz>

On Tue, 03 Dec 2013 18:16:09 +0100
Petr Mladek <pmladek@suse.cz> wrote:

> Hi,
> 
> I tested my ftrace-related patches and enabled also the startup test:
> 
>   CONFIG_FTRACE_SELFTEST=y
>   CONFIG_FTRACE_STARTUP_TEST=y
> 
> On today's kernel/git/tip/tip.git, the boot "freezed" for 1 minute when
> doing "Testing event system syscalls".
> 
> A bisect pointed finger to the commit d562aff93bfb530b099 (tracing: Add
> support for SOFT_DISABLE to syscall events).
> 
> It seems that the culprit are the "synchronize_sched" calls added to
> "unreg_event_syscall_enter" and "unreg_event_syscall_exit" functions.
> They are called 2312 times during the boot here and are responsible for
> the delay.
> 
> I wonder if it might cause slowdown also at runtime.
> 
> I am going to look deeper into the code and eventually come up with a
> solution. But it might take some time. I am still newbie in the kernel
> development. Any hints or tips are welcome ;-)
> 

Yeah, the synchronize_sched() at all disabling of syscall events seems
rather extreme. Perhaps this is good enough.

Dose this work for you?

Tom, do you see anything wrong with this. I'm assuming that the
synchronize_sched() within the event unregistering, was there for
deleting of trace instances. By placing the synchronize_sched() only
within the deletion code, this should be good enough.

-- Steve

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>

diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index f919a2e..a11800a 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -2314,6 +2314,9 @@ int event_trace_del_tracer(struct trace_array *tr)
 	/* Disable any running events */
 	__ftrace_set_clr_event_nolock(tr, NULL, NULL, NULL, 0);
 
+	/* Access to events are within rcu_read_lock_sched() */
+	synchronize_sched();
+
 	down_write(&trace_event_sem);
 	__trace_remove_event_dirs(tr);
 	debugfs_remove_recursive(tr->event_dir);
diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
index e4b6d11..ea90eb5 100644
--- a/kernel/trace/trace_syscalls.c
+++ b/kernel/trace/trace_syscalls.c
@@ -431,11 +431,6 @@ static void unreg_event_syscall_enter(struct ftrace_event_file *file,
 	if (!tr->sys_refcount_enter)
 		unregister_trace_sys_enter(ftrace_syscall_enter, tr);
 	mutex_unlock(&syscall_trace_lock);
-	/*
-	 * Callers expect the event to be completely disabled on
-	 * return, so wait for current handlers to finish.
-	 */
-	synchronize_sched();
 }
 
 static int reg_event_syscall_exit(struct ftrace_event_file *file,
@@ -474,11 +469,6 @@ static void unreg_event_syscall_exit(struct ftrace_event_file *file,
 	if (!tr->sys_refcount_exit)
 		unregister_trace_sys_exit(ftrace_syscall_exit, tr);
 	mutex_unlock(&syscall_trace_lock);
-	/*
-	 * Callers expect the event to be completely disabled on
-	 * return, so wait for current handlers to finish.
-	 */
-	synchronize_sched();
 }
 
 static int __init init_syscall_trace(struct ftrace_event_call *call)

  reply index

Thread overview: 5+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2013-12-03 17:16 Petr Mladek
2013-12-03 17:41 ` Steven Rostedt [this message]
2013-12-03 20:46   ` Tom Zanussi
2013-12-03 22:32     ` Tom Zanussi
2013-12-04 12:47   ` Petr Mladek

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20131203124120.427b9661@gandalf.local.home \
    --to=rostedt@goodmis.org \
    --cc=jkosina@suse.cz \
    --cc=linux-kernel@vger.kernel.org \
    --cc=pmladek@suse.cz \
    --cc=tom.zanussi@linux.intel.com \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link

LKML Archive on lore.kernel.org

Archives are clonable:
	git clone --mirror https://lore.kernel.org/lkml/0 lkml/git/0.git
	git clone --mirror https://lore.kernel.org/lkml/1 lkml/git/1.git
	git clone --mirror https://lore.kernel.org/lkml/2 lkml/git/2.git
	git clone --mirror https://lore.kernel.org/lkml/3 lkml/git/3.git
	git clone --mirror https://lore.kernel.org/lkml/4 lkml/git/4.git
	git clone --mirror https://lore.kernel.org/lkml/5 lkml/git/5.git
	git clone --mirror https://lore.kernel.org/lkml/6 lkml/git/6.git
	git clone --mirror https://lore.kernel.org/lkml/7 lkml/git/7.git
	git clone --mirror https://lore.kernel.org/lkml/8 lkml/git/8.git

	# If you have public-inbox 1.1+ installed, you may
	# initialize and index your mirror using the following commands:
	public-inbox-init -V2 lkml lkml/ https://lore.kernel.org/lkml \
		linux-kernel@vger.kernel.org
	public-inbox-index lkml

Example config snippet for mirrors

Newsgroup available over NNTP:
	nntp://nntp.lore.kernel.org/org.kernel.vger.linux-kernel


AGPL code for this site: git clone https://public-inbox.org/public-inbox.git