1. 30 May, 2014 2 commits
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add tracepoint benchmark tracepoint · 81dc9f0e
      Steven Rostedt (Red Hat) authored
      In order to help benchmark the time tracepoints take, a new config
      option is added called CONFIG_TRACEPOINT_BENCHMARK. When this option
      is set a tracepoint is created called "benchmark:benchmark_event".
      When the tracepoint is enabled, it kicks off a kernel thread that
      goes into an infinite loop (calling cond_sched() to let other tasks
      run), and calls the tracepoint. Each iteration will record the time
      it took to write to the tracepoint and the next iteration that
      data will be passed to the tracepoint itself. That is, the tracepoint
      will report the time it took to do the previous tracepoint.
      The string written to the tracepoint is a static string of 128 bytes
      to keep the time the same. The initial string is simply a write of
      "START". The second string records the cold cache time of the first
      write which is not added to the rest of the calculations.
      
      As it is a tight loop, it benchmarks as hot cache. That's fine because
      we care most about hot paths that are probably in cache already.
      
      An example of the output:
      
           START
           first=3672 [COLD CACHED]
           last=632 first=3672 max=632 min=632 avg=316 std=446 std^2=199712
           last=278 first=3672 max=632 min=278 avg=303 std=316 std^2=100337
           last=277 first=3672 max=632 min=277 avg=296 std=258 std^2=67064
           last=273 first=3672 max=632 min=273 avg=292 std=224 std^2=50411
           last=273 first=3672 max=632 min=273 avg=288 std=200 std^2=40389
           last=281 first=3672 max=632 min=273 avg=287 std=183 std^2=33666
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      81dc9f0e
    • Steven Rostedt's avatar
      tracing: Print nasty banner when trace_printk() is in use · 2184db46
      Steven Rostedt authored
      trace_printk() is used to debug fast paths within the kernel. Places
      that gets called in any context (interrupt or NMI) or thousands of
      times a second. Something you do not want to do with a printk().
      
      In order to make it completely lockless as it needs a temporary buffer
      to handle some of the string formatting, a page is created per cpu for
      every context (four per cpu; normal, softirq, irq, NMI).
      
      Since trace_printk() should only be used for debugging purposes,
      there's no reason to waste memory on these buffers on a production
      system. That means, trace_printk() should never be used unless a
      developer is debugging their kernel. There's macro magic to allocate
      the buffers if trace_printk() is used anywhere in the kernel.
      
      To help enforce that trace_printk() isn't used outside of development,
      when it is used, a nasty banner is displayed on bootup (or when a module
      is loaded that uses trace_printk() and the kernel core does not).
      
      Here's the banner:
      
       **********************************************************
       **   NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE   **
       **                                                      **
       ** trace_printk() being used. Allocating extra memory.  **
       **                                                      **
       ** This means that this is a DEBUG kernel and it is     **
       ** unsafe for produciton use.                           **
       **                                                      **
       ** If you see this message and you are not debugging    **
       ** the kernel, report this immediately to your vendor!  **
       **                                                      **
       **   NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE   **
       **********************************************************
      
      That should hopefully keep developers from trying to sneak in a
      trace_printk() or two.
      
      Link: http://lkml.kernel.org/p/20140528131440.2283213c@gandalf.local.homeSigned-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      2184db46
  2. 21 May, 2014 2 commits
  3. 15 May, 2014 1 commit
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks · 4449bf92
      Steven Rostedt (Red Hat) authored
      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.homeSuggested-by: default avatarJavi Merino <javi.merino@arm.com>
      Tested-by: default avatarJavi Merino <javi.merino@arm.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      4449bf92
  4. 14 May, 2014 8 commits
  5. 07 May, 2014 1 commit
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Add trace_<tracepoint>_enabled() function · 7c65bbc7
      Steven Rostedt (Red Hat) authored
      There are some code paths in the kernel that need to do some preparations
      before it calls a tracepoint. As that code is worthless overhead when
      the tracepoint is not enabled, it would be prudent to have that code
      only run when the tracepoint is active. To accomplish this, all tracepoints
      now get a static inline function called "trace_<tracepoint-name>_enabled()"
      which returns true when the tracepoint is enabled and false otherwise.
      
      As an added bonus, that function uses the static_key of the tracepoint
      such that no branch is needed.
      
        if (trace_mytracepoint_enabled()) {
      	arg = process_tp_arg();
      	trace_mytracepoint(arg);
        }
      
      Will keep the "process_tp_arg()" (which may be expensive to run) from
      being executed when the tracepoint isn't enabled.
      
      It's best to encapsulate the tracepoint itself in the if statement
      just to keep races. For example, if you had:
      
        if (trace_mytracepoint_enabled())
      	arg = process_tp_arg();
        trace_mytracepoint(arg);
      
      There's a chance that the tracepoint could be enabled just after the
      if statement, and arg will be undefined when calling the tracepoint.
      
      Link: http://lkml.kernel.org/r/20140506094407.507b6435@gandalf.local.homeAcked-by: default avatarMathieu Desnoyers <mathieu.desnoyers@efficios.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      7c65bbc7
  6. 06 May, 2014 1 commit
  7. 05 May, 2014 1 commit
    • Frederic Weisbecker's avatar
      tracing: Remove myself as a tracing maintainer · 3415c28c
      Frederic Weisbecker authored
      It has been a while since I last sent a tracing patch. I always keep an
      eye on tracing evolutions and contributions in general but given
      how busy I am with nohz, isolation and more generally core cleanups stuff,
      I seldom have time left to provide deep reviews of tracing patches nor
      simply for reviews to begin with.
      
      I've been very lucky to start kernel development on a very young subsystem
      with tons of low hanging fruits back in 2008. Given that it deals with
      a lot of tricky stuffs all around (sched, timers, irq, preemption, NMIs,
      SMP, RCU, ....) I basically learned everything there.
      
      Steve has been doing most of the incredible work these last years.
      Thanks a lot!
      
      Of course consider me always available to help on tracing if any hard
      days happen.
      
      Link: http://lkml.kernel.org/p/1399131991-13216-1-git-send-email-fweisbec@gmail.com
      
      Cc: Arnaldo Carvalho de Melo <acme@ghostprotocols.net>
      Cc: Ingo Molnar <mingo@kernel.org>
      Cc: Jiri Olsa <jolsa@redhat.com>
      Cc: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Cc: Thomas Gleixner <tglx@linutronix.de>
      Signed-off-by: default avatarFrederic Weisbecker <fweisbec@gmail.com>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      3415c28c
  8. 02 May, 2014 1 commit
  9. 30 Apr, 2014 1 commit
    • Steven Rostedt (Red Hat)'s avatar
      tracing: Remove mock up poll wait function · b1169cc6
      Steven Rostedt (Red Hat) authored
      Now that the ring buffer has a built in way to wake up readers
      when there's data, using irq_work such that it is safe to do it
      in any context. But it was still using the old "poor man's"
      wait polling that checks every 1/10 of a second to see if it
      should wake up a waiter. This makes the latency for a wake up
      excruciatingly long. No need to do that anymore.
      
      Completely remove the different wait_poll types from the tracers
      and have them all use the default one now.
      Reported-by: default avatarJohannes Berg <johannes@sipsolutions.net>
      Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
      b1169cc6
  10. 29 Apr, 2014 1 commit
  11. 24 Apr, 2014 2 commits
  12. 21 Apr, 2014 8 commits
  13. 20 Apr, 2014 5 commits
  14. 19 Apr, 2014 6 commits