Other messages are occasionally printed between these two, for example:
[203104.106534] Restarting tasks ...
[203104.106559] mei_hdcp 0000:00:16.0-b638ab7e-94e2-4ea2-a552-d1c54b627f04: bound 0000:00:02.0 (ops i915_hdcp_ops [i915])
[203104.112354] done.
This seems to be a timing issue, seen in two of the eleven
hibernation exits in my current `dmesg` output.
When printed on its own, the "done" message has the default log level.
This makes the output of `dmesg --level=warn` quite misleading.
Add enough context for the "done" messages to make sense on their own,
and use the same log level for all messages.
Change the messages to "<event>..." / "Done <event>.", unlike a449dfbfc0
which uses "<event>..." / "<event> completed.". Front-loading the unique
part of the message makes it easier to scan the log, and reduces ambiguity
for users who aren't confident in their English comprehension.
Reviewed-by: Lucas De Marchi <lucas.demarchi@intel.com>
Signed-off-by: Andrew Sayers <kernel.org@pileofstuff.org>
Link: https://patch.msgid.link/20250411152632.2806038-1-kernel.org@pileofstuff.org
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
- fix link to pm-graph homepage and in comments
- add usleep_range() kprobe to -dev mode
- add SIGUSR1 and SIGUSR2 to list of captured signals
- kill -s USR1 causes sleepgraph to print out stack trace
- kill -s USR2 prints stack trace and exits
- stack trace is also printed to -result file
- add legacy support for /sys/kernel/debug/tracing/
- allow multiple instances of trace funcs in the same phase
- update javascript to draw device detail for multiple trace func instances
- add -debugtiming option to print out timestamps on all outputs
Signed-off-by: Todd Brandt <todd.e.brandt@intel.com>
Link: https://patch.msgid.link/20240912055956.30108-1-todd.e.brandt@intel.com
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
- Standardize directory variables to support more flexible installations.
- Add copyright and licensing information to the Makefile.
- Introduce ".PHONY" declarations to ensure that specific targets are always
executed, regardless of the presence of files with matching names.
- Add a help target to provide usage instructions.
Signed-off-by: Amit Vadhavana <av2082000@gmail.com>
Acked-by: Todd Brandt <todd.e.brandt@linux.intel.com>
Link: https://patch.msgid.link/Update directory handling and installation process in Makefile
[ rjw: Changelog edits ]
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
sleepgraph/bootgraph function correctly in python3.12 but include a slew
of deprecation warnings for unsupported regexes. This patch fixes up all
the strings in the code so that it comforms with python3.12 standards.
Signed-off-by: Todd Brandt <todd.e.brandt@intel.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
- fix S3 suspend fail double run by using fp.flush to /sys/power/state
- when running turbostat print the return value
- handle case where html files have binary data
- max issues in summary-issues is now 100 (in case there are thousands)
- add backup to dmidecode, use /sys/class/dmi/id/ in case /dev/mem fails
- update summary page to use full mode (disk-platform instead of disk)
Signed-off-by: Todd Brandt <todd.e.brandt@intel.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
The sleepgraph tool currently fails:
File "/usr/bin/sleepgraph", line 4155
or re.match('psci: CPU(?P<cpu>[0-9]*) killed.*', msg)):
^
SyntaxError: unmatched ')'
Fixes: 34ea427e01 ("PM: tools: sleepgraph: Recognize "CPU killed" messages")
Signed-off-by: David Woodhouse <dwmw@amazon.co.uk>
Reviewed-by: Wolfram Sang <wsa@kernel.org>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
On the arm64 platform with PSCI, the core log of CPU offline is as
follows:
[ 100.431501] CPU1: shutdown
[ 100.454820] psci: CPU1 killed (polled 20 ms)
[ 100.459266] CPU2: shutdown
[ 100.482575] psci: CPU2 killed (polled 20 ms)
[ 100.486057] CPU3: shutdown
[ 100.513974] psci: CPU3 killed (polled 28 ms)
[ 100.518068] CPU4: shutdown
[ 100.541481] psci: CPU4 killed (polled 24 ms)
Prevent sleepgraph from mistakenly treating the "CPU up" message as part
of the suspend flow (because it should be regarded as part of the resume
flow) by making it recognize the "CPU* killed" messages above.
Signed-off-by: Xueqin Luo <luoxueqin@kylinos.cn>
[ rjw: Subject and changelog edits ]
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
install_latest_from_github.sh:
- Added a new script which allows users to install the latest pm-graph
from the upstream github repo. This is useful if the kernel source
version has issues that have already been fixed in github.
sleepgraph.py:
- Updated all the dmesg suspend/resume PM print formats to be able to
process recent timelines using dmesg only.
- Added ethtool output to the log for the system's ethernet device id the
ethtool exists. This helps in debugging network issues.
- Made the tool more robustly handle events where mangled dmesg or ftrace
outputs do not include all the requisite data. The tool fails gracefully
instead of creating a garbled timeline.
Signed-off-by: Todd Brandt <todd.e.brandt@intel.com>
[ rjw: Changelog edits ]
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
A regression has occurred in the hid-sensor code where a device
name string has not been initialized to 0, and ends up without
a NULL char and is printed with %s. This includes random binary
data in the device name, which makes its way into the ftrace output
and ends up crashing sleepgraph because it expects the ftrace output
to be ASCII only.
For example: "HID-SENSOR-INT-020b?.39.auto" ends up in ftrace instead
of "HID-SENSOR-INT-020b.39.auto". It causes this crash in sleepgraph:
File "/usr/bin/sleepgraph", line 5579, in executeSuspend
for line in fp:
File "/usr/lib/python3.10/codecs.py", line 322, in decode
(result, consumed) = self._buffer_decode(data, self.errors, final)
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xff in position
1568: invalid start byte
The issue is present in 6.3-rc1 and is described in full here:
https://bugzilla.kernel.org/show_bug.cgi?id=217169
A separate fix has been submitted to have this issue repaired, but
it has also exposed a larger bug in sleepgraph, since nothing should
make sleepgraph crash. Sleepgraph needs to be able to handle binary
data showing up in ftrace gracefully.
Modify the ftrace processing code to treat it as potentially binary
and to filter out binary data and leave just the ASCII.
Link: https://bugzilla.kernel.org/show_bug.cgi?id=217169
Fixes: 98c062e824 ("HID: hid-sensor-custom: Allow more custom iio sensors")
Signed-off-by: Todd Brandt <todd.e.brandt@linux.intel.com>
[ rjw: Subject and changelog edits ]
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
The canonical location for the tracefs filesystem is at /sys/kernel/tracing.
But, from Documentation/trace/ftrace.rst:
Before 4.1, all ftrace tracing control files were within the debugfs
file system, which is typically located at /sys/kernel/debug/tracing.
For backward compatibility, when mounting the debugfs file system,
the tracefs file system will be automatically mounted at:
/sys/kernel/debug/tracing
A few scripts in tools/power still refer to this older debugfs path, so
let's update them to avoid confusion.
Signed-off-by: Ross Zwisler <zwisler@google.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
A previous change amended try_to_freeze_tasks() with the "what"
variable pointing to a string describing the group of tasks subject to
the freezing which may be used in the error message in there too, so
make that happen.
Accordingly, update sleepgraph.py to catch the modified error message
as appropriate.
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
Reviewed-by: Petr Mladek <pmladek@suse.com>
sleepgraph:
- add -wifitrace argument for tracing all the way to wifi reconnect
- include more data in ftrace to mark the end of kernel resume
- add async_synchronize_full to the list of funcs to chart
- add thermal zone info to the log data
- include a check for s0ix support (s2idle is the default mem_sleep)
- if s2idle does not support s0ix, remove the SYS%LPI turbostat var
- fix -dev crash when kprobe caller is just an address (not a symbol)
- fix the cpuexec data in -proc to display in resume
sleepgraph.8:
- add -wifitrace documentation
README:
- change links from 01.org to developer.intel.com
Signed-off-by: Todd Brandt <todd.e.brandt@intel.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
bootgraph:
- fix parsing of /proc/version to be much more flexible
- check kernel version to disallow ftrace on anything older than 4.10
sleepgraph:
- include fix to bugzilla 212761 in case it regresses
- fix for -proc bug: https://github.com/intel/pm-graph/pull/20
- add -debugtiming arg to get timestamps on prints
- allow use of the netfix tool hosted in the github repo
- read s0ix data from pmc_core for better debug
- include more system data in the output log
- Do a better job testing input files useability
- flag more error data from dmesg in the timeline
- pre-parse the trace log to fix any ordering issues
- add new parser to process dmesg only timelines
- remove superflous sleep(5) in multitest mode
config/custom-timeline-functions.cfg:
- change some names to keep up to date
README:
- new version, small wording changes
Signed-off-by: Todd Brandt <todd.e.brandt@intel.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
- if wakeups occur in s2idle: "freeze time: N (-x ms waking y times) ms"
- change FREEZELOOP and FREEZEWAKE to S2LOOP and S2WAKE for brevity
- returns all sysfs vals to their initial state after testing
- use the dmesg log for debugging until the test is completed,
instrument the executeSuspend process to have a full trace,
if test completes, formal dmesg log overwrites the debug log
- fix CPU_ON and CPU_OFF devices in the timeline, should include [n]
Signed-off-by: Todd Brandt <todd.e.brandt@linux.intel.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
The current notifiers have the following error handling pattern all
over the place:
int err, nr;
err = __foo_notifier_call_chain(&chain, val_up, v, -1, &nr);
if (err & NOTIFIER_STOP_MASK)
__foo_notifier_call_chain(&chain, val_down, v, nr-1, NULL)
And aside from the endless repetition thereof, it is broken. Consider
blocking notifiers; both calls take and drop the rwsem, this means
that the notifier list can change in between the two calls, making @nr
meaningless.
Fix this by replacing all the __foo_notifier_call_chain() functions
with foo_notifier_call_chain_robust() that embeds the above pattern,
but ensures it is inside a single lock region.
Note: I switched atomic_notifier_call_chain_robust() to use
the spinlock, since RCU cannot provide the guarantee
required for the recovery.
Note: software_resume() error handling was broken afaict.
Signed-off-by: Peter Zijlstra (Intel) <peterz@infradead.org>
Signed-off-by: Ingo Molnar <mingo@kernel.org>
Acked-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
Link: https://lore.kernel.org/r/20200818135804.325626653@infradead.org
Important fixes:
- in s2idle, use timekeeping_freeze trace mark instead of
machine_suspend to denote entry into s2idle mode.
- in s2idle, use machine_suspend trace mark to create a new virtual
device called "s2idle_enter_<n>x". It denotes an s2idle_enter call
loop of <n> iterations where s2idle was never actually achieved.
It isn't counted as "freeze time" in the header.
- in s2idle, only show multiple freeze times if s2idle went in and
out of resume_noirq. Otherwise multiple freezes are shown with
"waking" time subtracted (waking time is time spent outside s2idle
dealing with wakeups).
- in s2idle summaries, include "FREEZEWAKE" as an issue when at
least 1ms is spent waking from s2idle. A clean run should only
wake for the rtc timer.
- add support for device callbacks with matching names in the same
phase. In rare cases some devices register multiple callbacks from
separate drivers using the same name. Without this fix only one is
shown.
- add kparamsfmt string back to fix bootgraph
General updates:
- when suspend_machine is missing, error says "failed in
suspend_machine"
- extract target count/time and add to summary title if -multi
used
- include any instances of "timeout" in dmesg as issues to be
logged.
- fix ftrace parse to handle any number of flags (instead of
just 4).
- remove sync/async_device string from device detail, remains in
hover.
- when using callgraph (-f) add driver name to callgraph titles.
Signed-off-by: Todd Brandt <todd.e.brandt@linux.intel.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
Pull SMP updates from Ingo Molnar:
"Misc cleanups in the SMP hotplug and cross-call code"
* tag 'smp-core-2020-06-01' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip:
cpu/hotplug: Remove __freeze_secondary_cpus()
cpu/hotplug: Remove disable_nonboot_cpus()
cpu/hotplug: Fix a typo in comment "broadacasted"->"broadcasted"
smp: Use smp_call_func_t in on_each_cpu()
The single user could have called freeze_secondary_cpus() directly.
Since this function was a source of confusion, remove it as it's
just a pointless wrapper.
While at it, rename enable_nonboot_cpus() to thaw_secondary_cpus() to
preserve the naming symmetry.
Done automatically via:
git grep -l enable_nonboot_cpus | xargs sed -i 's/enable_nonboot_cpus/thaw_secondary_cpus/g'
Signed-off-by: Qais Yousef <qais.yousef@arm.com>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Cc: "Rafael J. Wysocki" <rjw@rjwysocki.net>
Link: https://lkml.kernel.org/r/20200430114004.17477-1-qais.yousef@arm.com
sleepgraph:
- force usage of python3 instead of using system default
- fix bugzilla 204773 (https://bugzilla.kernel.org/show_bug.cgi?id=204773)
- fix issue of platform info not being reset in -multi (logs fill up)
- change -ftop call to "pm_suspend", this is one level below state_store
- add -wificheck command to read out the current wifi device details
- change -wifi behavior to poll /proc/net/wireless for wifi connect
- add wifi reconnect time to timeline, include time in summary column
- add "fail on wifi_resume" to timeline and summary when wifi fails
- add a set of commands to collect data before/after suspend in the log
- add "-cmdinfo" command which prints out all the data collected
- check for cmd info tools at start, print found/missing in green/red
- fix kernel suspend time calculation: tool used to look for start of
pm_suspend_console, but the order has changed. latest kernel starts
with ksys_sync, use this instead
- include time spent in mem/disk in the header (same as freeze/standby)
- ignore turbostat 32-bit capability warnings
- print to result.txt when -skiphtml is used, just say result: pass
- don't exit on SIGTSTP, it's a ctrl-Z and the tool may come back
- -multi argument supports duration as well as count: hours, minutes, seconds
- update the -multi status output to be more informative
- -maxfail sets maximum consecutive fails before a -multi run is aborted
- in -summary, ignore dmesg/ftrace/html files that are 0 size
bootgraph:
- force usage of python3 instead of using system default
README:
- add endurance testing instructions
Makefile:
- remove pycache on uninstall
Signed-off-by: Todd Brandt <todd.e.brandt@linux.intel.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
Upgrade bootgraph/sleepgraph to be able to run on python2 and python3.
Both now simply require python, the system can choose which to use.
bootgraph python3 update:
- add floor function to handle integer arithmetic
- change argument loop to use next() instead of args.next()
- open dmesg log and popen in binary, use decode(ascii, ignore)
- sort all html data to allow diff between python versions
- change exception handler to use python3 as instead of comma
sleepgraph python3 update:
- import configparser not ConfigParser (p2 needs python-configparser)
- add floor function to handle integer arithmetic
- change argument loop to use next() instead of args.next()
- handle popen output in binary, use decode(ascii, ignore)
- sort all html/output data to allow diff between python versions
- force gzip open to use text mode, same for file open
- ensure no binary data is written to logs (ascii convert devprops info)
- use codecs library to handle zlib encoding for mcelog data
- remove all uses of python3.7 keyword "async" as members or vars
- assume all FPDT and DMI data is in binary string form
sleepgraph:
- turbostat will be used by default if it's found & the mode is freeze
- a new option "-noturbostat" will disable its use
- fix bug where two callgraphs with the same start time overwrite.
- fix s2idle processing where two suspend/resume_machines occur back2back
- update getexec function to use which first (assuming PATH exists)
- new platforminfo data in log with: lspci, gpe counts, /proc/interrupts
- new data is zipped, b64 encoded, and tacked on the end of ftrace
Signed-off-by: Todd Brandt <todd.e.brandt@linux.intel.com>
Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
