delta/linux.git/kernel/trace/trace.c, branch proc-cmdline

Revert: Unify CLOCK_MONOTONIC and CLOCK_BOOTTIME

2018-04-26T12:53:32+00:00

Revert commits

92af4dcb4e1c ("tracing: Unify the "boot" and "mono" tracing clocks")
127bfa5f4342 ("hrtimer: Unify MONOTONIC and BOOTTIME clock behavior")
7250a4047aa6 ("posix-timers: Unify MONOTONIC and BOOTTIME clock behavior")
d6c7270e913d ("timekeeping: Remove boot time specific code")
f2d6fdbfd238 ("Input: Evdev - unify MONOTONIC and BOOTTIME clock behavior")
d6ed449afdb3 ("timekeeping: Make the MONOTONIC clock behave like the BOOTTIME clock")
72199320d49d ("timekeeping: Add the new CLOCK_MONOTONIC_ACTIVE clock")

As stated in the pull request for the unification of CLOCK_MONOTONIC and
CLOCK_BOOTTIME, it was clear that we might have to revert the change.

As reported by several folks systemd and other applications rely on the
documented behaviour of CLOCK_MONOTONIC on Linux and break with the above
changes. After resume daemons time out and other timeout related issues are
observed. Rafael compiled this list:

* systemd kills daemons on resume, after >WatchdogSec seconds
  of suspending (Genki Sky).  [Verified that that's because systemd uses
  CLOCK_MONOTONIC and expects it to not include the suspend time.]

* systemd-journald misbehaves after resume:
  systemd-journald[7266]: File /var/log/journal/016627c3c4784cd4812d4b7e96a34226/system.journal
corrupted or uncleanly shut down, renaming and replacing.
  (Mike Galbraith).

* NetworkManager reports "networking disabled" and networking is broken
  after resume 50% of the time (Pavel).  [May be because of systemd.]

* MATE desktop dims the display and starts the screensaver right after
  system resume (Pavel).

* Full system hang during resume (me).  [May be due to systemd or NM or both.]

That happens on debian and open suse systems.

It's sad, that these problems were neither catched in -next nor by those
folks who expressed interest in this change.

Reported-by: Rafael J. Wysocki 
Reported-by: Genki Sky ,
Reported-by: Pavel Machek 
Signed-off-by: Thomas Gleixner 
Cc: Dmitry Torokhov 
Cc: John Stultz 
Cc: Jonathan Corbet 
Cc: Kevin Easton 
Cc: Linus Torvalds 
Cc: Mark Salyzyn 
Cc: Michael Kerrisk 
Cc: Peter Zijlstra 
Cc: Petr Mladek 
Cc: Prarit Bhargava 
Cc: Sergey Senozhatsky 
Cc: Steven Rostedt

Merge tag 'trace-v4.17' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace

2018-04-10T18:27:30+00:00

Pull tracing updates from Steven Rostedt:
 "New features:

   - Tom Zanussi's extended histogram work.

     This adds the synthetic events to have histograms from multiple
     event data Adds triggers "onmatch" and "onmax" to call the
     synthetic events Several updates to the histogram code from this

   - Allow way to nest ring buffer calls in the same context

   - Allow absolute time stamps in ring buffer

   - Rewrite of filter code parsing based on Al Viro's suggestions

   - Setting of trace_clock to global if TSC is unstable (on boot)

   - Better OOM handling when allocating large ring buffers

   - Added initcall tracepoints (consolidated initcall_debug code with
     them)

  And other various fixes and clean ups"

* tag 'trace-v4.17' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace: (68 commits)
  init: Have initcall_debug still work without CONFIG_TRACEPOINTS
  init, tracing: Have printk come through the trace events for initcall_debug
  init, tracing: instrument security and console initcall trace events
  init, tracing: Add initcall trace events
  tracing: Add rcu dereference annotation for test func that touches filter->prog
  tracing: Add rcu dereference annotation for filter->prog
  tracing: Fixup logic inversion on setting trace_global_clock defaults
  tracing: Hide global trace clock from lockdep
  ring-buffer: Add set/clear_current_oom_origin() during allocations
  ring-buffer: Check if memory is available before allocation
  lockdep: Add print_irqtrace_events() to __warn
  vsprintf: Do not preprocess non-dereferenced pointers for bprintf (%px and %pK)
  tracing: Uninitialized variable in create_tracing_map_fields()
  tracing: Make sure variable string fields are NULL-terminated
  tracing: Add action comparisons when testing matching hist triggers
  tracing: Don't add flag strings when displaying variable references
  tracing: Fix display of hist trigger expressions containing timestamps
  ftrace: Drop a VLA in module_exists()
  tracing: Mention trace_clock=global when warning about unstable clocks
  tracing: Default to using trace_global_clock if sched_clock is unstable
  ...

tracing: Fixup logic inversion on setting trace_global_clock defaults

2018-04-06T12:56:53+00:00

In commit 932066a15335 ("tracing: Default to using trace_global_clock if
sched_clock is unstable"), the logic for deciding to override the
default clock if unstable was reversed from the earlier posting. I was
trying to reduce the width of the message by using an early return
rather than a if-block, but reverted back to using the if-block and
accidentally left the predicate inverted.

Link: http://lkml.kernel.org/r/20180404212450.26646-1-chris@chris-wilson.co.uk

Fixes: 932066a15335 ("tracing: Default to using trace_global_clock if sched_clock is unstable")
Signed-off-by: Chris Wilson 
Signed-off-by: Steven Rostedt (VMware)

tracing: Default to using trace_global_clock if sched_clock is unstable

2018-04-06T12:56:47+00:00

Across suspend, we may see a very large drift in timestamps if the sched
clock is unstable, prompting the global trace's ringbuffer code to warn
and suggest switching to the global clock. Preempt this request by
detecting when the sched clock is unstable (determined during
late_initcall) and automatically switching the default clock over to
trace_global_clock.

This should prevent requiring user interaction to resolve warnings such
as:

    Delta way too big! 18446743856563626466 ts=18446744054496180323 write stamp = 197932553857
    If you just came from a suspend/resume,
    please switch to the trace global clock:
    echo global > /sys/kernel/debug/tracing/trace_clock

Link: http://lkml.kernel.org/r/20180330150132.16903-1-chris@chris-wilson.co.uk

Signed-off-by: Chris Wilson 
Signed-off-by: Steven Rostedt (VMware)

Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/jikos/trivial

2018-04-05T18:56:35+00:00

Pull trivial tree updates from Jiri Kosina.

* 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/jikos/trivial:
  kfifo: fix inaccurate comment
  tools/thermal: tmon: fix for segfault
  net: Spelling s/stucture/structure/
  edd: don't spam log if no EDD information is present
  Documentation: Fix early-microcode.txt references after file rename
  tracing: Block comments should align the * on each line
  treewide: Fix typos in printk
  GenWQE: Fix a typo in two comments
  treewide: Align function definition open/close braces

tracing: Block comments should align the * on each line

2018-03-27T07:51:23+00:00

Resolved Block comments use * on subsequent lines checkpatch warning.
Issue found by checkpatch.

Signed-off-by: Rohit Visavalia 
Signed-off-by: Jiri Kosina

tracing: Unify the "boot" and "mono" tracing clocks

2018-03-13T06:34:23+00:00

Unify the "boot" and "mono" tracing clocks and document the new behaviour.

Signed-off-by: Thomas Gleixner 
Cc: Dmitry Torokhov 
Cc: John Stultz 
Cc: Jonathan Corbet 
Cc: Kevin Easton 
Cc: Linus Torvalds 
Cc: Mark Salyzyn 
Cc: Michael Kerrisk 
Cc: Peter Zijlstra 
Cc: Petr Mladek 
Cc: Prarit Bhargava 
Cc: Sergey Senozhatsky 
Cc: Steven Rostedt 
Link: http://lkml.kernel.org/r/20180301165150.489635255@linutronix.de
Signed-off-by: Ingo Molnar

tracing: Make tracing_set_clock() non-static

2018-03-10T21:06:03+00:00

Allow tracing code outside of trace.c to access tracing_set_clock().

Some applications may require a particular clock in order to function
properly, such as latency calculations.

Also, add an accessor returning the current clock string.

Link: http://lkml.kernel.org/r/6d1c53e9ee2163f54e1849f5376573f54f0e6009.1516069914.git.tom.zanussi@linux.intel.com

Signed-off-by: Tom Zanussi 
Signed-off-by: Steven Rostedt (VMware)

tracing: Add variable reference handling to hist triggers

2018-03-10T21:05:58+00:00

Add the necessary infrastructure to allow the variables defined on one
event to be referenced in another.  This allows variables set by a
previous event to be referenced and used in expressions combining the
variable values saved by that previous event and the event fields of
the current event.  For example, here's how a latency can be
calculated and saved into yet another variable named 'wakeup_lat':

    # echo 'hist:keys=pid,prio:ts0=common_timestamp ...
    # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp-$ts0 ...

In the first event, the event's timetamp is saved into the variable
ts0.  In the next line, ts0 is subtracted from the second event's
timestamp to produce the latency.

Further users of variable references will be described in subsequent
patches, such as for instance how the 'wakeup_lat' variable above can
be displayed in a latency histogram.

Link: http://lkml.kernel.org/r/b1d3e6975374e34d501ff417c20189c3f9b2c7b8.1516069914.git.tom.zanussi@linux.intel.com

Signed-off-by: Tom Zanussi 
Signed-off-by: Steven Rostedt (VMware)

tracing: Add usecs modifier for hist trigger timestamps

2018-03-10T21:05:54+00:00

Appending .usecs onto a common_timestamp field will cause the
timestamp value to be in microseconds instead of the default
nanoseconds.  A typical latency histogram using usecs would look like
this:

   # echo 'hist:keys=pid,prio:ts0=common_timestamp.usecs ...
   # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0 ...

This also adds an external trace_clock_in_ns() to trace.c for the
timestamp conversion.

Link: http://lkml.kernel.org/r/4e813705a170b3e13e97dc3135047362fb1a39f3.1516069914.git.tom.zanussi@linux.intel.com

Signed-off-by: Tom Zanussi 
Signed-off-by: Steven Rostedt (VMware)