tracing: Avoid soft lockup in trace_pipe
authorJiri Olsa <jolsa@redhat.com>
Fri, 25 Mar 2011 11:05:18 +0000 (12:05 +0100)
committerSteven Rostedt <rostedt@goodmis.org>
Mon, 4 Apr 2011 16:18:24 +0000 (12:18 -0400)
commitee5e51f51be755830f57445e268ba50e88ccbdbb
tree059d6c5843275a5ab94ae01408c1dc6dbe00b2ea
parent1813dc3776c22ad4b0294a6df8434b9a02c98109
tracing: Avoid soft lockup in trace_pipe

running following commands:

  # enable the binary option
  echo 1 > ./options/bin
  # disable context info option
  echo 0 > ./options/context-info
  # tracing only events
  echo 1 > ./events/enable
  cat trace_pipe

plus forcing system to generate many tracing events,
is causing lockup (in NON preemptive kernels) inside
tracing_read_pipe function.

The issue is also easily reproduced by running ltp stress test.
(ftrace_stress_test.sh)

The reasons are:
 - bin/hex/raw output functions for events are set to
   trace_nop_print function, which prints nothing and
   returns TRACE_TYPE_HANDLED value
 - LOST EVENT trace do not handle trace_seq overflow

These reasons force the while loop in tracing_read_pipe
function never to break.

The attached patch fixies handling of lost event trace, and
changes trace_nop_print to print minimal info, which is needed
for the correct tracing_read_pipe processing.

v2 changes:
 - omit the cond_resched changes by trace_nop_print changes
 - WARN changed to WARN_ONCE and added info to be able
   to find out the culprit

v3 changes:
 - make more accurate patch comment

Signed-off-by: Jiri Olsa <jolsa@redhat.com>
LKML-Reference: <20110325110518.GC1922@jolsa.brq.redhat.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
kernel/trace/trace.c
kernel/trace/trace_output.c