diff options
Diffstat (limited to 'tools')
49 files changed, 1876 insertions, 360 deletions
diff --git a/tools/gpio/.gitignore b/tools/gpio/.gitignore index 9e9dd4b681b2..a94c0e83b209 100644 --- a/tools/gpio/.gitignore +++ b/tools/gpio/.gitignore @@ -1,4 +1,4 @@ gpio-event-mon gpio-hammer lsgpio - +include/linux/gpio.h diff --git a/tools/include/linux/rcu.h b/tools/include/linux/rcu.h index 7d02527e5bce..9554d3fa54f3 100644 --- a/tools/include/linux/rcu.h +++ b/tools/include/linux/rcu.h @@ -19,7 +19,7 @@ static inline bool rcu_is_watching(void) return false; } -#define rcu_assign_pointer(p, v) ((p) = (v)) -#define RCU_INIT_POINTER(p, v) p=(v) +#define rcu_assign_pointer(p, v) do { (p) = (v); } while (0) +#define RCU_INIT_POINTER(p, v) do { (p) = (v); } while (0) #endif diff --git a/tools/include/uapi/linux/bpf.h b/tools/include/uapi/linux/bpf.h index a8b823c30b43..489e118b69d2 100644 --- a/tools/include/uapi/linux/bpf.h +++ b/tools/include/uapi/linux/bpf.h @@ -785,7 +785,7 @@ union bpf_attr { * based on a user-provided identifier for all traffic coming from * the tasks belonging to the related cgroup. See also the related * kernel documentation, available from the Linux sources in file - * *Documentation/cgroup-v1/net_cls.txt*. + * *Documentation/cgroup-v1/net_cls.rst*. * * The Linux kernel has two versions for cgroups: there are * cgroups v1 and cgroups v2. Both are available to users, who can diff --git a/tools/memory-model/linux-kernel.bell b/tools/memory-model/linux-kernel.bell index def9131d3d8e..5be86b1025e8 100644 --- a/tools/memory-model/linux-kernel.bell +++ b/tools/memory-model/linux-kernel.bell @@ -24,6 +24,7 @@ instructions RMW[{'once,'acquire,'release}] enum Barriers = 'wmb (*smp_wmb*) || 'rmb (*smp_rmb*) || 'mb (*smp_mb*) || + 'barrier (*barrier*) || 'rcu-lock (*rcu_read_lock*) || 'rcu-unlock (*rcu_read_unlock*) || 'sync-rcu (*synchronize_rcu*) || @@ -76,3 +77,8 @@ flag ~empty rcu-rscs & (po ; [Sync-srcu] ; po) as invalid-sleep (* Validate SRCU dynamic match *) flag ~empty different-values(srcu-rscs) as srcu-bad-nesting + +(* Compute marked and plain memory accesses *) +let Marked = (~M) | IW | Once | Release | Acquire | domain(rmw) | range(rmw) | + LKR | LKW | UL | LF | RL | RU +let Plain = M \ Marked diff --git a/tools/memory-model/linux-kernel.cat b/tools/memory-model/linux-kernel.cat index 8dcb37835b61..ea2ff4b94074 100644 --- a/tools/memory-model/linux-kernel.cat +++ b/tools/memory-model/linux-kernel.cat @@ -24,8 +24,14 @@ include "lock.cat" (* Basic relations *) (*******************) +(* Release Acquire *) +let acq-po = [Acquire] ; po ; [M] +let po-rel = [M] ; po ; [Release] +let po-unlock-rf-lock-po = po ; [UL] ; rf ; [LKR] ; po + (* Fences *) -let rmb = [R \ Noreturn] ; fencerel(Rmb) ; [R \ Noreturn] +let R4rmb = R \ Noreturn (* Reads for which rmb works *) +let rmb = [R4rmb] ; fencerel(Rmb) ; [R4rmb] let wmb = [W] ; fencerel(Wmb) ; [W] let mb = ([M] ; fencerel(Mb) ; [M]) | ([M] ; fencerel(Before-atomic) ; [RMW] ; po? ; [M]) | @@ -34,13 +40,14 @@ let mb = ([M] ; fencerel(Mb) ; [M]) | ([M] ; po ; [UL] ; (co | po) ; [LKW] ; fencerel(After-unlock-lock) ; [M]) let gp = po ; [Sync-rcu | Sync-srcu] ; po? - let strong-fence = mb | gp -(* Release Acquire *) -let acq-po = [Acquire] ; po ; [M] -let po-rel = [M] ; po ; [Release] -let po-unlock-rf-lock-po = po ; [UL] ; rf ; [LKR] ; po +let nonrw-fence = strong-fence | po-rel | acq-po +let fence = nonrw-fence | wmb | rmb +let barrier = fencerel(Barrier | Rmb | Wmb | Mb | Sync-rcu | Sync-srcu | + Before-atomic | After-atomic | Acquire | Release | + Rcu-lock | Rcu-unlock | Srcu-lock | Srcu-unlock) | + (po ; [Release]) | ([Acquire] ; po) (**********************************) (* Fundamental coherence ordering *) @@ -61,21 +68,22 @@ empty rmw & (fre ; coe) as atomic let dep = addr | data let rwdep = (dep | ctrl) ; [W] let overwrite = co | fr -let to-w = rwdep | (overwrite & int) -let to-r = addr | (dep ; rfi) -let fence = strong-fence | wmb | po-rel | rmb | acq-po +let to-w = rwdep | (overwrite & int) | (addr ; [Plain] ; wmb) +let to-r = addr | (dep ; [Marked] ; rfi) let ppo = to-r | to-w | fence | (po-unlock-rf-lock-po & int) (* Propagation: Ordering from release operations and strong fences. *) -let A-cumul(r) = rfe? ; r -let cumul-fence = A-cumul(strong-fence | po-rel) | wmb | po-unlock-rf-lock-po -let prop = (overwrite & ext)? ; cumul-fence* ; rfe? +let A-cumul(r) = (rfe ; [Marked])? ; r +let cumul-fence = [Marked] ; (A-cumul(strong-fence | po-rel) | wmb | + po-unlock-rf-lock-po) ; [Marked] +let prop = [Marked] ; (overwrite & ext)? ; cumul-fence* ; + [Marked] ; rfe? ; [Marked] (* * Happens Before: Ordering from the passage of time. * No fences needed here for prop because relation confined to one process. *) -let hb = ppo | rfe | ((prop \ id) & int) +let hb = [Marked] ; (ppo | rfe | ((prop \ id) & int)) ; [Marked] acyclic hb as happens-before (****************************************) @@ -83,7 +91,7 @@ acyclic hb as happens-before (****************************************) (* Propagation: Each non-rf link needs a strong fence. *) -let pb = prop ; strong-fence ; hb* +let pb = prop ; strong-fence ; hb* ; [Marked] acyclic pb as propagation (*******) @@ -114,24 +122,28 @@ let rcu-link = po? ; hb* ; pb* ; prop ; po (* * Any sequence containing at least as many grace periods as RCU read-side - * critical sections (joined by rcu-link) acts as a generalized strong fence. + * critical sections (joined by rcu-link) induces order like a generalized + * inter-CPU strong fence. * Likewise for SRCU grace periods and read-side critical sections, provided * the synchronize_srcu() and srcu_read_[un]lock() calls refer to the same * struct srcu_struct location. *) -let rec rcu-fence = rcu-gp | srcu-gp | +let rec rcu-order = rcu-gp | srcu-gp | (rcu-gp ; rcu-link ; rcu-rscsi) | ((srcu-gp ; rcu-link ; srcu-rscsi) & loc) | (rcu-rscsi ; rcu-link ; rcu-gp) | ((srcu-rscsi ; rcu-link ; srcu-gp) & loc) | - (rcu-gp ; rcu-link ; rcu-fence ; rcu-link ; rcu-rscsi) | - ((srcu-gp ; rcu-link ; rcu-fence ; rcu-link ; srcu-rscsi) & loc) | - (rcu-rscsi ; rcu-link ; rcu-fence ; rcu-link ; rcu-gp) | - ((srcu-rscsi ; rcu-link ; rcu-fence ; rcu-link ; srcu-gp) & loc) | - (rcu-fence ; rcu-link ; rcu-fence) + (rcu-gp ; rcu-link ; rcu-order ; rcu-link ; rcu-rscsi) | + ((srcu-gp ; rcu-link ; rcu-order ; rcu-link ; srcu-rscsi) & loc) | + (rcu-rscsi ; rcu-link ; rcu-order ; rcu-link ; rcu-gp) | + ((srcu-rscsi ; rcu-link ; rcu-order ; rcu-link ; srcu-gp) & loc) | + (rcu-order ; rcu-link ; rcu-order) +let rcu-fence = po ; rcu-order ; po? +let fence = fence | rcu-fence +let strong-fence = strong-fence | rcu-fence (* rb orders instructions just as pb does *) -let rb = prop ; po ; rcu-fence ; po? ; hb* ; pb* +let rb = prop ; rcu-fence ; hb* ; pb* ; [Marked] irreflexive rb as rcu @@ -143,3 +155,49 @@ irreflexive rb as rcu * let xb = hb | pb | rb * acyclic xb as executes-before *) + +(*********************************) +(* Plain accesses and data races *) +(*********************************) + +(* Warn about plain writes and marked accesses in the same region *) +let mixed-accesses = ([Plain & W] ; (po-loc \ barrier) ; [Marked]) | + ([Marked] ; (po-loc \ barrier) ; [Plain & W]) +flag ~empty mixed-accesses as mixed-accesses + +(* Executes-before and visibility *) +let xbstar = (hb | pb | rb)* +let vis = cumul-fence* ; rfe? ; [Marked] ; + ((strong-fence ; [Marked] ; xbstar) | (xbstar & int)) + +(* Boundaries for lifetimes of plain accesses *) +let w-pre-bounded = [Marked] ; (addr | fence)? +let r-pre-bounded = [Marked] ; (addr | nonrw-fence | + ([R4rmb] ; fencerel(Rmb) ; [~Noreturn]))? +let w-post-bounded = fence? ; [Marked] +let r-post-bounded = (nonrw-fence | ([~Noreturn] ; fencerel(Rmb) ; [R4rmb]))? ; + [Marked] + +(* Visibility and executes-before for plain accesses *) +let ww-vis = fence | (strong-fence ; xbstar ; w-pre-bounded) | + (w-post-bounded ; vis ; w-pre-bounded) +let wr-vis = fence | (strong-fence ; xbstar ; r-pre-bounded) | + (w-post-bounded ; vis ; r-pre-bounded) +let rw-xbstar = fence | (r-post-bounded ; xbstar ; w-pre-bounded) + +(* Potential races *) +let pre-race = ext & ((Plain * M) | ((M \ IW) * Plain)) + +(* Coherence requirements for plain accesses *) +let wr-incoh = pre-race & rf & rw-xbstar^-1 +let rw-incoh = pre-race & fr & wr-vis^-1 +let ww-incoh = pre-race & co & ww-vis^-1 +empty (wr-incoh | rw-incoh | ww-incoh) as plain-coherence + +(* Actual races *) +let ww-nonrace = ww-vis & ((Marked * W) | rw-xbstar) & ((W * Marked) | wr-vis) +let ww-race = (pre-race & co) \ ww-nonrace +let wr-race = (pre-race & (co? ; rf)) \ wr-vis +let rw-race = (pre-race & fr) \ rw-xbstar + +flag ~empty (ww-race | wr-race | rw-race) as data-race diff --git a/tools/memory-model/linux-kernel.def b/tools/memory-model/linux-kernel.def index 551eeaa389d4..ef0f3c1850de 100644 --- a/tools/memory-model/linux-kernel.def +++ b/tools/memory-model/linux-kernel.def @@ -24,6 +24,7 @@ smp_mb__before_atomic() { __fence{before-atomic}; } smp_mb__after_atomic() { __fence{after-atomic}; } smp_mb__after_spinlock() { __fence{after-spinlock}; } smp_mb__after_unlock_lock() { __fence{after-unlock-lock}; } +barrier() { __fence{barrier}; } // Exchange xchg(X,V) __xchg{mb}(X,V) diff --git a/tools/memory-model/litmus-tests/MP+poonceonces.litmus b/tools/memory-model/litmus-tests/MP+poonceonces.litmus index b2b60b84fb9d..172f0145301c 100644 --- a/tools/memory-model/litmus-tests/MP+poonceonces.litmus +++ b/tools/memory-model/litmus-tests/MP+poonceonces.litmus @@ -1,7 +1,7 @@ C MP+poonceonces (* - * Result: Maybe + * Result: Sometimes * * Can the counter-intuitive message-passing outcome be prevented with * no ordering at all? diff --git a/tools/memory-model/litmus-tests/README b/tools/memory-model/litmus-tests/README index 5ee08f129094..681f9067fa9e 100644 --- a/tools/memory-model/litmus-tests/README +++ b/tools/memory-model/litmus-tests/README @@ -244,7 +244,7 @@ produce the name: Adding the ".litmus" suffix: SB+rfionceonce-poonceonces.litmus The descriptors that describe connections between consecutive accesses -within the cycle through a given litmus test can be provided by the herd +within the cycle through a given litmus test can be provided by the herd7 tool (Rfi, Po, Fre, and so on) or by the linux-kernel.bell file (Once, Release, Acquire, and so on). diff --git a/tools/memory-model/lock.cat b/tools/memory-model/lock.cat index a059d1a6d8a2..6b52f365d73a 100644 --- a/tools/memory-model/lock.cat +++ b/tools/memory-model/lock.cat @@ -11,7 +11,7 @@ include "cross.cat" (* - * The lock-related events generated by herd are as follows: + * The lock-related events generated by herd7 are as follows: * * LKR Lock-Read: the read part of a spin_lock() or successful * spin_trylock() read-modify-write event pair diff --git a/tools/memory-model/scripts/README b/tools/memory-model/scripts/README index 29375a1fbbfa..095c7eb36f9f 100644 --- a/tools/memory-model/scripts/README +++ b/tools/memory-model/scripts/README @@ -22,7 +22,7 @@ checklitmushist.sh Run all litmus tests having .litmus.out files from previous initlitmushist.sh or newlitmushist.sh runs, comparing the - herd output to that of the original runs. + herd7 output to that of the original runs. checklitmus.sh @@ -43,7 +43,7 @@ initlitmushist.sh judgelitmus.sh - Given a .litmus file and its .litmus.out herd output, check the + Given a .litmus file and its .litmus.out herd7 output, check the .litmus.out file against the .litmus file's "Result:" comment to judge whether the test ran correctly. Not normally run manually, provided instead for use by other scripts. diff --git a/tools/memory-model/scripts/checkalllitmus.sh b/tools/memory-model/scripts/checkalllitmus.sh index b35fcd61ecf6..3c0c7fbbd223 100755 --- a/tools/memory-model/scripts/checkalllitmus.sh +++ b/tools/memory-model/scripts/checkalllitmus.sh @@ -1,7 +1,7 @@ #!/bin/sh # SPDX-License-Identifier: GPL-2.0+ # -# Run herd tests on all .litmus files in the litmus-tests directory +# Run herd7 tests on all .litmus files in the litmus-tests directory # and check each file's result against a "Result:" comment within that # litmus test. If the verification result does not match that specified # in the litmus test, this script prints an error message prefixed with diff --git a/tools/memory-model/scripts/checklitmus.sh b/tools/memory-model/scripts/checklitmus.sh index dd08801a30b0..11461ed40b5e 100755 --- a/tools/memory-model/scripts/checklitmus.sh +++ b/tools/memory-model/scripts/checklitmus.sh @@ -1,7 +1,7 @@ #!/bin/sh # SPDX-License-Identifier: GPL-2.0+ # -# Run a herd test and invokes judgelitmus.sh to check the result against +# Run a herd7 test and invokes judgelitmus.sh to check the result against # a "Result:" comment within the litmus test. It also outputs verification # results to a file whose name is that of the specified litmus test, but # with ".out" appended. diff --git a/tools/memory-model/scripts/parseargs.sh b/tools/memory-model/scripts/parseargs.sh index 859e1d581e05..40f52080fdbd 100644 --- a/tools/memory-model/scripts/parseargs.sh +++ b/tools/memory-model/scripts/parseargs.sh @@ -91,7 +91,7 @@ do shift ;; --herdopts|--herdopt) - checkarg --destdir "(herd options)" "$#" "$2" '.*' '^--' + checkarg --destdir "(herd7 options)" "$#" "$2" '.*' '^--' LKMM_HERD_OPTIONS="$2" shift ;; diff --git a/tools/memory-model/scripts/runlitmushist.sh b/tools/memory-model/scripts/runlitmushist.sh index e507f5f933d5..6ed376f495bb 100644 --- a/tools/memory-model/scripts/runlitmushist.sh +++ b/tools/memory-model/scripts/runlitmushist.sh @@ -79,7 +79,7 @@ then echo ' ---' Summary: 1>&2 grep '!!!' $T/*.sh.out 1>&2 nfail="`grep '!!!' $T/*.sh.out | wc -l`" - echo 'Number of failed herd runs (e.g., timeout): ' $nfail 1>&2 + echo 'Number of failed herd7 runs (e.g., timeout): ' $nfail 1>&2 exit 1 else echo All runs completed successfully. 1>&2 diff --git a/tools/power/cpupower/man/cpupower-monitor.1 b/tools/power/cpupower/man/cpupower-monitor.1 index 914cbb9d9cd0..70a56476f4b0 100644 --- a/tools/power/cpupower/man/cpupower-monitor.1 +++ b/tools/power/cpupower/man/cpupower-monitor.1 @@ -61,7 +61,7 @@ Only display specific monitors. Use the monitor string(s) provided by \-l option .PP \-i seconds .RS 4 -Measure intervall. +Measure interval. .RE .PP \-c diff --git a/tools/power/cpupower/po/cs.po b/tools/power/cpupower/po/cs.po index cb22c45c5069..bfc7e1702ec9 100644 --- a/tools/power/cpupower/po/cs.po +++ b/tools/power/cpupower/po/cs.po @@ -98,7 +98,7 @@ msgstr "" #: utils/idle_monitor/cpupower-monitor.c:74 #, c-format -msgid "\t -i: time intervall to measure for in seconds (default 1)\n" +msgid "\t -i: time interval to measure for in seconds (default 1)\n" msgstr "" #: utils/idle_monitor/cpupower-monitor.c:75 diff --git a/tools/power/cpupower/po/de.po b/tools/power/cpupower/po/de.po index 840c17cc450a..70887bb8ba95 100644 --- a/tools/power/cpupower/po/de.po +++ b/tools/power/cpupower/po/de.po @@ -95,7 +95,7 @@ msgstr "" #: utils/idle_monitor/cpupower-monitor.c:74 #, c-format -msgid "\t -i: time intervall to measure for in seconds (default 1)\n" +msgid "\t -i: time interval to measure for in seconds (default 1)\n" msgstr "" #: utils/idle_monitor/cpupower-monitor.c:75 diff --git a/tools/power/cpupower/po/fr.po b/tools/power/cpupower/po/fr.po index b46ca2548f86..b6e505b34e4a 100644 --- a/tools/power/cpupower/po/fr.po +++ b/tools/power/cpupower/po/fr.po @@ -95,7 +95,7 @@ msgstr "" #: utils/idle_monitor/cpupower-monitor.c:74 #, c-format -msgid "\t -i: time intervall to measure for in seconds (default 1)\n" +msgid "\t -i: time interval to measure for in seconds (default 1)\n" msgstr "" #: utils/idle_monitor/cpupower-monitor.c:75 diff --git a/tools/power/cpupower/po/it.po b/tools/power/cpupower/po/it.po index f80c4ddb9bda..a1deeb52c9e0 100644 --- a/tools/power/cpupower/po/it.po +++ b/tools/power/cpupower/po/it.po @@ -95,7 +95,7 @@ msgstr "" #: utils/idle_monitor/cpupower-monitor.c:74 #, c-format -msgid "\t -i: time intervall to measure for in seconds (default 1)\n" +msgid "\t -i: time interval to measure for in seconds (default 1)\n" msgstr "" #: utils/idle_monitor/cpupower-monitor.c:75 diff --git a/tools/power/cpupower/po/pt.po b/tools/power/cpupower/po/pt.po index 990f5267ffe8..902186585bb9 100644 --- a/tools/power/cpupower/po/pt.po +++ b/tools/power/cpupower/po/pt.po @@ -93,7 +93,7 @@ msgstr "" #: utils/idle_monitor/cpupower-monitor.c:74 #, c-format -msgid "\t -i: time intervall to measure for in seconds (default 1)\n" +msgid "\t -i: time interval to measure for in seconds (default 1)\n" msgstr "" #: utils/idle_monitor/cpupower-monitor.c:75 diff --git a/tools/power/cpupower/utils/cpufreq-set.c b/tools/power/cpupower/utils/cpufreq-set.c index f49bc4aa2a08..6ed82fba5aaa 100644 --- a/tools/power/cpupower/utils/cpufreq-set.c +++ b/tools/power/cpupower/utils/cpufreq-set.c @@ -305,6 +305,8 @@ int cmd_freq_set(int argc, char **argv) bitmask_setbit(cpus_chosen, cpus->cpu); cpus = cpus->next; } + /* Set the last cpu in related cpus list */ + bitmask_setbit(cpus_chosen, cpus->cpu); cpufreq_put_related_cpus(cpus); } } diff --git a/tools/power/pm-graph/README b/tools/power/pm-graph/README new file mode 100644 index 000000000000..58a5591e3951 --- /dev/null +++ b/tools/power/pm-graph/README @@ -0,0 +1,552 @@ + p m - g r a p h + + pm-graph: suspend/resume/boot timing analysis tools + Version: 5.4 + Author: Todd Brandt <todd.e.brandt@intel.com> + Home Page: https://01.org/pm-graph + + Report bugs/issues at bugzilla.kernel.org Tools/pm-graph + - https://bugzilla.kernel.org/buglist.cgi?component=pm-graph&product=Tools + + Full documentation available online & in man pages + - Getting Started: + https://01.org/pm-graph/documentation/getting-started + + - Config File Format: + https://01.org/pm-graph/documentation/3-config-file-format + + - upstream version in git: + https://github.com/intel/pm-graph/ + + Table of Contents + - Overview + - Setup + - Usage + - Basic Usage + - Dev Mode Usage + - Proc Mode Usage + - Configuration Files + - Usage Examples + - Config File Options + - Custom Timeline Entries + - Adding/Editing Timeline Functions + - Adding/Editing Dev Timeline Source Functions + - Verifying your Custom Functions + - Testing on consumer linux Operating Systems + - Android + +------------------------------------------------------------------ +| OVERVIEW | +------------------------------------------------------------------ + + This tool suite is designed to assist kernel and OS developers in optimizing + their linux stack's suspend/resume & boot time. Using a kernel image built + with a few extra options enabled, the tools will execute a suspend or boot, + and will capture dmesg and ftrace data. This data is transformed into a set of + timelines and a callgraph to give a quick and detailed view of which devices + and kernel processes are taking the most time in suspend/resume & boot. + +------------------------------------------------------------------ +| SETUP | +------------------------------------------------------------------ + + These packages are required to execute the scripts + - python + - python-requests + + Ubuntu: + sudo apt-get install python python-requests + + Fedora: + sudo dnf install python python-requests + + The tools can most easily be installed via git clone and make install + + $> git clone http://github.com/intel/pm-graph.git + $> cd pm-graph + $> sudo make install + $> man sleepgraph ; man bootgraph + + Setup involves some minor kernel configuration + + The following kernel build options are required for all kernels: + CONFIG_DEVMEM=y + CONFIG_PM_DEBUG=y + CONFIG_PM_SLEEP_DEBUG=y + CONFIG_FTRACE=y + CONFIG_FUNCTION_TRACER=y + CONFIG_FUNCTION_GRAPH_TRACER=y + CONFIG_KPROBES=y + CONFIG_KPROBES_ON_FTRACE=y + + In kernel 3.15.0, two patches were upstreamed which enable the + v3.0 behavior. These patches allow the tool to read all the + data from trace events instead of from dmesg. You can enable + this behavior on earlier kernels with these patches: + + (kernel/pre-3.15/enable_trace_events_suspend_resume.patch) + (kernel/pre-3.15/enable_trace_events_device_pm_callback.patch) + + If you're using a kernel older than 3.15.0, the following + additional kernel parameters are required: + (e.g. in file /etc/default/grub) + GRUB_CMDLINE_LINUX_DEFAULT="... initcall_debug log_buf_len=32M ..." + + If you're using a kernel older than 3.11-rc2, the following simple + patch must be applied to enable ftrace data: + in file: kernel/power/suspend.c + in function: int suspend_devices_and_enter(suspend_state_t state) + remove call to "ftrace_stop();" + remove call to "ftrace_start();" + + There is a patch which does this for kernel v3.8.0: + (kernel/pre-3.11-rc2/enable_ftrace_in_suspendresume.patch) + + + +------------------------------------------------------------------ +| USAGE | +------------------------------------------------------------------ + +Basic Usage +___________ + + 1) First configure a kernel using the instructions from the previous sections. + Then build, install, and boot with it. + 2) Open up a terminal window and execute the mode list command: + + %> sudo ./sleepgraph.py -modes + ['freeze', 'mem', 'disk'] + + Execute a test using one of the available power modes, e.g. mem (S3): + + %> sudo ./sleepgraph.py -m mem -rtcwake 15 + + or with a config file + + %> sudo ./sleepgraph.py -config config/suspend.cfg + + When the system comes back you'll see the script finishing up and + creating the output files in the test subdir. It generates output + files in subdirectory: suspend-mmddyy-HHMMSS. The ftrace file can + be used to regenerate the html timeline with different options + + HTML output: <hostname>_<mode>.html + raw dmesg output: <hostname>_<mode>_dmesg.txt + raw ftrace output: <hostname>_<mode>_ftrace.txt + + View the html in firefox or chrome. + + +Dev Mode Usage +______________ + + Developer mode adds information on low level source calls to the timeline. + The tool sets kprobes on all delay and mutex calls to see which devices + are waiting for something and when. It also sets a suite of kprobes on + subsystem dependent calls to better fill out the timeline. + + The tool will also expose kernel threads that don't normally show up in the + timeline. This is useful in discovering dependent threads to get a better + idea of what each device is waiting for. For instance, the scsi_eh thread, + a.k.a. scsi resume error handler, is what each SATA disk device waits for + before it can continue resume. + + The timeline will be much larger if run with dev mode, so it can be useful + to set the -mindev option to clip out any device blocks that are too small + to see easily. The following command will give a nice dev mode run: + + %> sudo ./sleepgraph.py -m mem -rtcwake 15 -mindev 1 -dev + + or with a config file + + %> sudo ./sleepgraph.py -config config/suspend-dev.cfg + + +Proc Mode Usage +_______________ + + Proc mode adds user process info to the timeline. This is done in a manner + similar to the bootchart utility, which graphs init processes and their + execution as the system boots. This tool option does the same thing but for + the period before and after suspend/resume. + + In order to see any process info, there needs to be some delay before or + after resume since processes are frozen in suspend_prepare and thawed in + resume_complete. The predelay and postdelay args allow you to do this. It + can also be useful to run in x2 mode with an x2 delay, this way you can + see process activity before and after resume, and in between two + successive suspend/resumes. + + The command can be run like this: + + %> sudo ./sleepgraph.py -m mem -rtcwake 15 -x2 -x2delay 1000 -predelay 1000 -postdelay 1000 -proc + + or with a config file + + %> sudo ./sleepgraph.py -config config/suspend-proc.cfg + + +------------------------------------------------------------------ +| CONFIGURATION FILES | +------------------------------------------------------------------ + + Since 4.0 we've moved to using config files in lieu of command line options. + The config folder contains a collection of typical use cases. + There are corresponding configs for other power modes: + + Simple suspend/resume with basic timeline (mem/freeze/standby) + config/suspend.cfg + config/freeze.cfg + config/standby.cfg + + Dev mode suspend/resume with dev timeline (mem/freeze/standby) + config/suspend-dev.cfg + config/freeze-dev.cfg + config/standby-dev.cfg + + Simple suspend/resume with timeline and callgraph (mem/freeze/standby) + config/suspend-callgraph.cfg + config/freeze-callgraph.cfg + config/standby-callgraph.cfg + + Sample proc mode x2 run using mem suspend + config/suspend-x2-proc.cfg + + Sample for editing timeline funcs (moves internal functions into config) + config/custom-timeline-functions.cfg + + Sample debug config for serio subsystem + config/debug-serio-suspend.cfg + + +Usage Examples +______________ + + Run a simple mem suspend: + %> sudo ./sleepgraph.py -config config/suspend.cfg + + Run a mem suspend with callgraph data: + %> sudo ./sleepgraph.py -config config/suspend-callgraph.cfg + + Run a mem suspend with dev mode detail: + %> sudo ./sleepgraph.py -config config/suspend-dev.cfg + + +Config File Options +___________________ + + [Settings] + + # Verbosity: print verbose messages (def: false) + verbose: false + + # Suspend Mode: e.g. standby, mem, freeze, disk (def: mem) + mode: mem + + # Output Directory Format: {hostname}, {date}, {time} give current values + output-dir: suspend-{hostname}-{date}-{time} + + # Automatic Wakeup: use rtcwake to wakeup after X seconds (def: infinity) + rtcwake: 15 + + # Add Logs: add the dmesg and ftrace log to the html output (def: false) + addlogs: false + + # Sus/Res Gap: insert a gap between sus & res in the timeline (def: false) + srgap: false + + # Custom Command: Command to execute in lieu of suspend (def: "") + command: echo mem > /sys/power/state + + # Proc mode: graph user processes and cpu usage in the timeline (def: false) + proc: false + + # Dev mode: graph source functions in the timeline (def: false) + dev: false + + # Suspend/Resume x2: run 2 suspend/resumes back to back (def: false) + x2: false + + # x2 Suspend Delay: time delay between the two test runs in ms (def: 0 ms) + x2delay: 0 + + # Pre Suspend Delay: nclude an N ms delay before (1st) suspend (def: 0 ms) + predelay: 0 + + # Post Resume Delay: include an N ms delay after (last) resume (def: 0 ms) + postdelay: 0 + + # Min Device Length: graph only dev callbacks longer than min (def: 0.001 ms) + mindev: 0.001 + + # Callgraph: gather ftrace callgraph data on all timeline events (def: false) + callgraph: false + + # Expand Callgraph: pre-expand the callgraph treeviews in html (def: false) + expandcg: false + + # Min Callgraph Length: show callgraphs only if longer than min (def: 1 ms) + mincg: 1 + + # Timestamp Precision: number of sig digits in timestamps (0:S, [3:ms], 6:us) + timeprec: 3 + + # Device Filter: show only devs whose name/driver includes one of these strings + devicefilter: _cpu_up,_cpu_down,i915,usb + + # Override default timeline entries: + # Do not use the internal default functions for timeline entries (def: false) + # Set this to true if you intend to only use the ones defined in the config + override-timeline-functions: true + + # Override default dev timeline entries: + # Do not use the internal default functions for dev timeline entries (def: false) + # Set this to true if you intend to only use the ones defined in the config + override-dev-timeline-functions: true + + # Call Loop Max Gap (dev mode only) + # merge loops of the same call if each is less than maxgap apart (def: 100us) + callloop-maxgap: 0.0001 + + # Call Loop Max Length (dev mode only) + # merge loops of the same call if each is less than maxlen in length (def: 5ms) + callloop-maxlen: 0.005 + +------------------------------------------------------------------ +| CUSTOM TIMELINE ENTRIES | +------------------------------------------------------------------ + +Adding or Editing Timeline Functions +____________________________________ + + The tool uses an array of function names to fill out empty spaces in the + timeline where device callbacks don't appear. For instance, in suspend_prepare + the tool adds the sys_sync and freeze_processes calls as virtual device blocks + in the timeline to show you where the time is going. These calls should fill + the timeline with contiguous data so that most kernel execution is covered. + + It is possible to add new function calls to the timeline by adding them to + the config. It's also possible to copy the internal timeline functions into + the config so that you can override and edit them. Place them in the + timeline_functions_ARCH section with the name of your architecture appended. + i.e. for x86_64: [timeline_functions_x86_64] + + Use the override-timeline-functions option if you only want to use your + custom calls, or leave it false to append them to the internal ones. + + This section includes a list of functions (set using kprobes) which use both + symbol data and function arg data. The args are pulled directly from the + stack using this architecture's registers and stack formatting. Each entry + can include up to four pieces of info: The function name, a format string, + an argument list, and a color. But only a function name is required. + + For a full example config, see config/custom-timeline-functions.cfg. It pulls + all the internal timeline functions into the config and allows you to edit + them. + + Entry format: + + function: format{fn_arg1}_{fn_arg2} fn_arg1 fn_arg2 ... [color=purple] + + Required Arguments: + + function: The symbol name for the function you want probed, this is the + minimum required for an entry, it will show up as the function + name with no arguments. + + example: _cpu_up: + + Optional Arguments: + + format: The format to display the data on the timeline in. Use braces to + enclose the arg names. + + example: CPU_ON[{cpu}] + + color: The color of the entry block in the timeline. The default color is + transparent, so the entry shares the phase color. The color is an + html color string, either a word, or an RGB. + + example: [color=#CC00CC] + + arglist: A list of arguments from registers/stack addresses. See URL: + https://www.kernel.org/doc/Documentation/trace/kprobetrace.txt + + example: cpu=%di:s32 + + Here is a full example entry. It displays cpu resume calls in the timeline + in orange. They will appear as CPU_ON[0], CPU_ON[1], etc. + + [timeline_functions_x86_64] + _cpu_up: CPU_ON[{cpu}] cpu=%di:s32 [color=orange] + + +Adding or Editing Dev Mode Timeline Source Functions +____________________________________________________ + + In dev mode, the tool uses an array of function names to monitor source + execution within the timeline entries. + + The function calls are displayed inside the main device/call blocks in the + timeline. However, if a function call is not within a main timeline event, + it will spawn an entirely new event named after the caller's kernel thread. + These asynchronous kernel threads will populate in a separate section + beneath the main device/call section. + + The tool has a set of hard coded calls which focus on the most common use + cases: msleep, udelay, schedule_timeout, mutex_lock_slowpath, etc. These are + the functions that add a hardcoded time delay to the suspend/resume path. + The tool also includes some common functions native to important + subsystems: ata, i915, and ACPI, etc. + + It is possible to add new function calls to the dev timeline by adding them + to the config. It's also possible to copy the internal dev timeline + functions into the config so that you can override and edit them. Place them + in the dev_timeline_functions_ARCH section with the name of your architecture + appended. i.e. for x86_64: [dev_timeline_functions_x86_64] + + Use the override-dev-timeline-functions option if you only want to use your + custom calls, or leave it false to append them to the internal ones. + + The format is the same as the timeline_functions_x86_64 section. It's a + list of functions (set using kprobes) which use both symbol data and function + arg data. The args are pulled directly from the stack using this + architecture's registers and stack formatting. Each entry can include up + to four pieces of info: The function name, a format string, an argument list, + and a color. But only the function name is required. + + For a full example config, see config/custom-timeline-functions.cfg. It pulls + all the internal dev timeline functions into the config and allows you to edit + them. + + Here is a full example entry. It displays the ATA port reset calls as + ataN_port_reset in the timeline. This is where most of the SATA disk resume + time goes, so it can be helpful to see the low level call. + + [dev_timeline_functions_x86_64] + ata_eh_recover: ata{port}_port_reset port=+36(%di):s32 [color=#CC00CC] + + +Verifying your custom functions +_______________________________ + + Once you have a set of functions (kprobes) defined, it can be useful to + perform a quick check to see if you formatted them correctly and if the system + actually supports them. To do this, run the tool with your config file + and the -status option. The tool will go through all the kprobes (both + custom and internal if you haven't overridden them) and actually attempts + to set them in ftrace. It will then print out success or fail for you. + + Note that kprobes which don't actually exist in the kernel won't stop the + tool, they just wont show up. + + For example: + + sudo ./sleepgraph.py -config config/custom-timeline-functions.cfg -status + Checking this system (myhostname)... + have root access: YES + is sysfs mounted: YES + is "mem" a valid power mode: YES + is ftrace supported: YES + are kprobes supported: YES + timeline data source: FTRACE (all trace events found) + is rtcwake supported: YES + verifying timeline kprobes work: + _cpu_down: YES + _cpu_up: YES + acpi_pm_finish: YES + acpi_pm_prepare: YES + freeze_kernel_threads: YES + freeze_processes: YES + sys_sync: YES + thaw_processes: YES + verifying dev kprobes work: + __const_udelay: YES + __mutex_lock_slowpath: YES + acpi_os_stall: YES + acpi_ps_parse_aml: YES + intel_opregion_init: NO + intel_opregion_register: NO + intel_opregion_setup: NO + msleep: YES + schedule_timeout: YES + schedule_timeout_uninterruptible: YES + usleep_range: YES + + +------------------------------------------------------------------ +| TESTING ON CONSUMER LINUX OPERATING SYSTEMS | +------------------------------------------------------------------ + +Android +_______ + + The easiest way to execute on an android device is to run the android.sh + script on the device, then pull the ftrace log back to the host and run + sleepgraph.py on it. + + Here are the steps: + + [download and install the tool on the device] + + host%> wget https://raw.githubusercontent.com/intel/pm-graph/master/tools/android.sh + host%> adb connect 192.168.1.6 + host%> adb root + # push the script to a writeable location + host%> adb push android.sh /sdcard/ + + [check whether the tool will run on your device] + + host%> adb shell + dev%> cd /sdcard + dev%> sh android.sh status + host : asus_t100 + kernel : 3.14.0-i386-dirty + modes : freeze mem + rtcwake : supported + ftrace : supported + trace events { + suspend_resume: found + device_pm_callback_end: found + device_pm_callback_start: found + } + # the above is what you see on a system that's properly patched + + [execute the suspend] + + # NOTE: The suspend will only work if the screen isn't timed out, + # so you have to press some keys first to wake it up b4 suspend) + dev%> sh android.sh suspend mem + ------------------------------------ + Suspend/Resume timing test initiated + ------------------------------------ + hostname : asus_t100 + kernel : 3.14.0-i386-dirty + mode : mem + ftrace out : /mnt/shell/emulated/0/ftrace.txt + dmesg out : /mnt/shell/emulated/0/dmesg.txt + log file : /mnt/shell/emulated/0/log.txt + ------------------------------------ + INITIALIZING FTRACE........DONE + STARTING FTRACE + SUSPEND START @ 21:24:02 (rtcwake in 10 seconds) + <adb connection will now terminate> + + [retrieve the data from the device] + + # I find that you have to actually kill the adb process and + # reconnect sometimes in order for the connection to work post-suspend + host%> adb connect 192.168.1.6 + # (required) get the ftrace data, this is the most important piece + host%> adb pull /sdcard/ftrace.txt + # (optional) get the dmesg data, this is for debugging + host%> adb pull /sdcard/dmesg.txt + # (optional) get the log, which just lists some test times for comparison + host%> adb pull /sdcard/log.txt + + [create an output html file using sleepgraph.py] + + host%> sleepgraph.py -ftrace ftrace.txt + + You should now have an output.html with the android data, enjoy! diff --git a/tools/power/pm-graph/bootgraph.py b/tools/power/pm-graph/bootgraph.py index 3d899dd8147a..666bcbda648d 100755 --- a/tools/power/pm-graph/bootgraph.py +++ b/tools/power/pm-graph/bootgraph.py @@ -325,9 +325,9 @@ def parseKernelLog(): if(not sysvals.stamp['kernel']): sysvals.stamp['kernel'] = sysvals.kernelVersion(msg) continue - m = re.match('.* setting system clock to (?P<t>.*) UTC.*', msg) + m = re.match('.* setting system clock to (?P<d>[0-9\-]*)[ A-Z](?P<t>[0-9:]*) UTC.*', msg) if(m): - bt = datetime.strptime(m.group('t'), '%Y-%m-%d %H:%M:%S') + bt = datetime.strptime(m.group('d')+' '+m.group('t'), '%Y-%m-%d %H:%M:%S') bt = bt - timedelta(seconds=int(ktime)) data.boottime = bt.strftime('%Y-%m-%d_%H:%M:%S') sysvals.stamp['time'] = bt.strftime('%B %d %Y, %I:%M:%S %p') @@ -348,7 +348,7 @@ def parseKernelLog(): data.newAction(phase, f, pid, start, ktime, int(r), int(t)) del devtemp[f] continue - if(re.match('^Freeing unused kernel memory.*', msg)): + if(re.match('^Freeing unused kernel .*', msg)): data.tUserMode = ktime data.dmesg['kernel']['end'] = ktime data.dmesg['user']['start'] = ktime @@ -1008,7 +1008,7 @@ if __name__ == '__main__': updateKernelParams() elif cmd == 'flistall': for f in sysvals.getBootFtraceFilterFunctions(): - print f + print(f) elif cmd == 'checkbl': sysvals.getBootLoader() pprint('Boot Loader: %s\n%s' % (sysvals.bootloader, sysvals.blexec)) diff --git a/tools/power/pm-graph/config/example.cfg b/tools/power/pm-graph/config/example.cfg index 05b2efb9bb54..1ef3eb9383fa 100644 --- a/tools/power/pm-graph/config/example.cfg +++ b/tools/power/pm-graph/config/example.cfg @@ -98,12 +98,34 @@ postdelay: 0 # graph only devices longer than min in the timeline (default: 0.001 ms) mindev: 0.001 +# Call Loop Max Gap (dev mode only) +# merge loops of the same call if each is less than maxgap apart (def: 100us) +callloop-maxgap: 0.0001 + +# Call Loop Max Length (dev mode only) +# merge loops of the same call if each is less than maxlen in length (def: 5ms) +callloop-maxlen: 0.005 + +# Override default timeline entries: +# Do not use the internal default functions for timeline entries (def: false) +# Set this to true if you intend to only use the ones defined in the config +override-timeline-functions: true + +# Override default dev timeline entries: +# Do not use the internal default functions for dev timeline entries (def: false) +# Set this to true if you intend to only use the ones defined in the config +override-dev-timeline-functions: true + # ---- Debug Options ---- # Callgraph # gather detailed ftrace callgraph data on all timeline events (default: false) callgraph: false +# Max graph depth +# limit the callgraph trace to this depth (default: 0 = all) +maxdepth: 2 + # Callgraph phase filter # Only enable callgraphs for one phase, i.e. resume_noirq (default: all) cgphase: suspend @@ -131,3 +153,7 @@ timeprec: 6 # Add kprobe functions to the timeline # Add functions to the timeline from a text file (default: no-action) # fadd: file.txt + +# Ftrace buffer size +# Set trace buffer size to N kilo-bytes (default: all of free memory up to 3GB) +# bufsize: 1000 diff --git a/tools/power/pm-graph/sleepgraph.8 b/tools/power/pm-graph/sleepgraph.8 index 24a2e7d0ae63..9648be644d5f 100644 --- a/tools/power/pm-graph/sleepgraph.8 +++ b/tools/power/pm-graph/sleepgraph.8 @@ -53,6 +53,11 @@ disable rtcwake and require a user keypress to resume. Add the dmesg and ftrace logs to the html output. They will be viewable by clicking buttons in the timeline. .TP +\fB-turbostat\fR +Use turbostat to execute the command in freeze mode (default: disabled). This +will provide turbostat output in the log which will tell you which actual +power modes were entered. +.TP \fB-result \fIfile\fR Export a results table to a text file for parsing. .TP @@ -121,6 +126,10 @@ be created in a new subdirectory with a summary page: suspend-xN-{date}-{time}. Use ftrace to create device callgraphs (default: disabled). This can produce very large outputs, i.e. 10MB - 100MB. .TP +\fB-ftop\fR +Use ftrace on the top level call: "suspend_devices_and_enter" only (default: disabled). +This option implies -f and creates a single callgraph covering all of suspend/resume. +.TP \fB-maxdepth \fIlevel\fR limit the callgraph trace depth to \fIlevel\fR (default: 0=all). This is the best way to limit the output size when using callgraphs via -f. @@ -138,8 +147,8 @@ which are barely visible in the timeline. The value is a float: e.g. 0.001 represents 1 us. .TP \fB-cgfilter \fI"func1,func2,..."\fR -Reduce callgraph output in the timeline by limiting it to a list of calls. The -argument can be a single function name or a comma delimited list. +Reduce callgraph output in the timeline by limiting it certain devices. The +argument can be a single device name or a comma delimited list. (default: none) .TP \fB-cgskip \fIfile\fR @@ -183,6 +192,9 @@ Print out the contents of the ACPI Firmware Performance Data Table. \fB-battery\fR Print out battery status and current charge. .TP +\fB-wifi\fR +Print out wifi status and connection details. +.TP \fB-xon/-xoff/-xstandby/-xsuspend\fR Test xset by attempting to switch the display to the given mode. This is the same command which will be issued by \fB-display \fImode\fR. diff --git a/tools/power/pm-graph/sleepgraph.py b/tools/power/pm-graph/sleepgraph.py index d1a88d05e976..4f46a7a1feb6 100755 --- a/tools/power/pm-graph/sleepgraph.py +++ b/tools/power/pm-graph/sleepgraph.py @@ -9,9 +9,9 @@ # # Links: # Home Page -# https://01.org/suspendresume +# https://01.org/pm-graph # Source repo -# git@github.com:01org/pm-graph +# git@github.com:intel/pm-graph # # Description: # This tool is designed to assist kernel and OS developers in optimizing @@ -24,6 +24,7 @@ # viewed in firefox or chrome. # # The following kernel build options are required: +# CONFIG_DEVMEM=y # CONFIG_PM_DEBUG=y # CONFIG_PM_SLEEP_DEBUG=y # CONFIG_FTRACE=y @@ -53,6 +54,7 @@ import ConfigParser import gzip from threading import Thread from subprocess import call, Popen, PIPE +import base64 def pprint(msg): print(msg) @@ -66,7 +68,7 @@ def pprint(msg): # store system values and test parameters class SystemValues: title = 'SleepGraph' - version = '5.2' + version = '5.4' ansi = False rs = 0 display = '' @@ -74,8 +76,9 @@ class SystemValues: sync = False verbose = False testlog = True - dmesglog = False + dmesglog = True ftracelog = False + tstat = False mindevlen = 0.0 mincglen = 0.0 cgphase = '' @@ -99,6 +102,8 @@ class SystemValues: pmdpath = '/sys/power/pm_debug_messages' traceevents = [ 'suspend_resume', + 'wakeup_source_activate', + 'wakeup_source_deactivate', 'device_pm_callback_end', 'device_pm_callback_start' ] @@ -130,6 +135,8 @@ class SystemValues: x2delay = 0 skiphtml = False usecallgraph = False + ftopfunc = 'suspend_devices_and_enter' + ftop = False usetraceevents = False usetracemarkers = True usekprobes = True @@ -158,6 +165,13 @@ class SystemValues: 'acpi_hibernation_leave': {}, 'acpi_pm_freeze': {}, 'acpi_pm_thaw': {}, + 'acpi_s2idle_end': {}, + 'acpi_s2idle_sync': {}, + 'acpi_s2idle_begin': {}, + 'acpi_s2idle_prepare': {}, + 'acpi_s2idle_wake': {}, + 'acpi_s2idle_wakeup': {}, + 'acpi_s2idle_restore': {}, 'hibernate_preallocate_memory': {}, 'create_basic_memory_bitmaps': {}, 'swsusp_write': {}, @@ -191,9 +205,14 @@ class SystemValues: 'usleep_range': { 'args_x86_64': {'min':'%di:s32', 'max':'%si:s32'}, 'ub': 1 }, 'mutex_lock_slowpath': { 'func':'__mutex_lock_slowpath', 'ub': 1 }, 'acpi_os_stall': {'ub': 1}, + 'rt_mutex_slowlock': {'ub': 1}, # ACPI 'acpi_resume_power_resources': {}, - 'acpi_ps_parse_aml': {}, + 'acpi_ps_execute_method': { 'args_x86_64': { + 'fullpath':'+0(+40(%di)):string', + }}, + # mei_me + 'mei_reset': {}, # filesystem 'ext4_sync_fs': {}, # 80211 @@ -242,6 +261,7 @@ class SystemValues: timeformat = '%.3f' cmdline = '%s %s' % \ (os.path.basename(sys.argv[0]), ' '.join(sys.argv[1:])) + kparams = '' sudouser = '' def __init__(self): self.archargs = 'args_'+platform.machine() @@ -320,6 +340,7 @@ class SystemValues: args['date'] = n.strftime('%y%m%d') args['time'] = n.strftime('%H%M%S') args['hostname'] = args['host'] = self.hostname + args['mode'] = self.suspendmode return value.format(**args) def setOutputFile(self): if self.dmesgfile != '': @@ -331,21 +352,28 @@ class SystemValues: if(m): self.htmlfile = m.group('name')+'.html' def systemInfo(self, info): - p = c = m = b = '' + p = m = '' if 'baseboard-manufacturer' in info: m = info['baseboard-manufacturer'] elif 'system-manufacturer' in info: m = info['system-manufacturer'] - if 'baseboard-product-name' in info: - p = info['baseboard-product-name'] - elif 'system-product-name' in info: + if 'system-product-name' in info: p = info['system-product-name'] - if 'processor-version' in info: - c = info['processor-version'] - if 'bios-version' in info: - b = info['bios-version'] - self.sysstamp = '# sysinfo | man:%s | plat:%s | cpu:%s | bios:%s | numcpu:%d | memsz:%d | memfr:%d' % \ - (m, p, c, b, self.cpucount, self.memtotal, self.memfree) + elif 'baseboard-product-name' in info: + p = info['baseboard-product-name'] + if m[:5].lower() == 'intel' and 'baseboard-product-name' in info: + p = info['baseboard-product-name'] + c = info['processor-version'] if 'processor-version' in info else '' + b = info['bios-version'] if 'bios-version' in info else '' + r = info['bios-release-date'] if 'bios-release-date' in info else '' + self.sysstamp = '# sysinfo | man:%s | plat:%s | cpu:%s | bios:%s | biosdate:%s | numcpu:%d | memsz:%d | memfr:%d' % \ + (m, p, c, b, r, self.cpucount, self.memtotal, self.memfree) + try: + kcmd = open('/proc/cmdline', 'r').read().strip() + except: + kcmd = '' + if kcmd: + self.sysstamp += '\n# kparams | %s' % kcmd def printSystemInfo(self, fatal=False): self.rootCheck(True) out = dmidecode(self.mempath, fatal) @@ -353,10 +381,10 @@ class SystemValues: return fmt = '%-24s: %s' for name in sorted(out): - print fmt % (name, out[name]) - print fmt % ('cpucount', ('%d' % self.cpucount)) - print fmt % ('memtotal', ('%d kB' % self.memtotal)) - print fmt % ('memfree', ('%d kB' % self.memfree)) + print(fmt % (name, out[name])) + print(fmt % ('cpucount', ('%d' % self.cpucount))) + print(fmt % ('memtotal', ('%d kB' % self.memtotal))) + print(fmt % ('memfree', ('%d kB' % self.memfree))) def cpuInfo(self): self.cpucount = 0 fp = open('/proc/cpuinfo', 'r') @@ -376,7 +404,7 @@ class SystemValues: def initTestOutput(self, name): self.prefix = self.hostname v = open('/proc/version', 'r').read().strip() - kver = string.split(v)[2] + kver = v.split()[2] fmt = name+'-%m%d%y-%H%M%S' testtime = datetime.now().strftime(fmt) self.teststamp = \ @@ -391,7 +419,7 @@ class SystemValues: self.htmlfile = \ self.testdir+'/'+self.prefix+'_'+self.suspendmode+'.html' if not os.path.isdir(self.testdir): - os.mkdir(self.testdir) + os.makedirs(self.testdir) def getValueList(self, value): out = [] for i in value.split(','): @@ -402,6 +430,12 @@ class SystemValues: self.devicefilter = self.getValueList(value) def setCallgraphFilter(self, value): self.cgfilter = self.getValueList(value) + def skipKprobes(self, value): + for k in self.getValueList(value): + if k in self.tracefuncs: + del self.tracefuncs[k] + if k in self.dev_tracefuncs: + del self.dev_tracefuncs[k] def setCallgraphBlacklist(self, file): self.cgblacklist = self.listFromFile(file) def rtcWakeAlarmOn(self): @@ -471,9 +505,9 @@ class SystemValues: if 'func' in self.tracefuncs[i]: i = self.tracefuncs[i]['func'] if i in master: - print i + print(i) else: - print self.colorText(i) + print(self.colorText(i)) def setFtraceFilterFunctions(self, list): master = self.listFromFile(self.tpath+'available_filter_functions') flist = '' @@ -680,7 +714,8 @@ class SystemValues: if self.bufsize > 0: tgtsize = self.bufsize elif self.usecallgraph or self.usedevsrc: - bmax = (1*1024*1024) if self.suspendmode == 'disk' else (3*1024*1024) + bmax = (1*1024*1024) if self.suspendmode in ['disk', 'command'] \ + else (3*1024*1024) tgtsize = min(self.memfree, bmax) else: tgtsize = 65536 @@ -715,7 +750,10 @@ class SystemValues: cf.append(self.tracefuncs[fn]['func']) else: cf.append(fn) - self.setFtraceFilterFunctions(cf) + if self.ftop: + self.setFtraceFilterFunctions([self.ftopfunc]) + else: + self.setFtraceFilterFunctions(cf) # initialize the kprobe trace elif self.usekprobes: for name in self.tracefuncs: @@ -768,9 +806,21 @@ class SystemValues: fw = test['fw'] if(fw): fp.write('# fwsuspend %u fwresume %u\n' % (fw[0], fw[1])) + if 'mcelog' in test: + fp.write('# mcelog %s\n' % test['mcelog']) + if 'turbo' in test: + fp.write('# turbostat %s\n' % test['turbo']) if 'bat' in test: (a1, c1), (a2, c2) = test['bat'] fp.write('# battery %s %d %s %d\n' % (a1, c1, a2, c2)) + if 'wifi' in test: + wstr = [] + for wifi in test['wifi']: + tmp = [] + for key in sorted(wifi): + tmp.append('%s:%s' % (key, wifi[key])) + wstr.append('|'.join(tmp)) + fp.write('# wifi %s\n' % (','.join(wstr))) if test['error'] or len(testdata) > 1: fp.write('# enter_sleep_error %s\n' % test['error']) return fp @@ -821,6 +871,106 @@ class SystemValues: if isgz: return gzip.open(filename, mode+'b') return open(filename, mode) + def mcelog(self, clear=False): + cmd = self.getExec('mcelog') + if not cmd: + return '' + if clear: + call(cmd+' > /dev/null 2>&1', shell=True) + return '' + fp = Popen([cmd], stdout=PIPE, stderr=PIPE).stdout + out = fp.read().strip() + fp.close() + if not out: + return '' + return base64.b64encode(out.encode('zlib')) + def haveTurbostat(self): + if not self.tstat: + return False + cmd = self.getExec('turbostat') + if not cmd: + return False + fp = Popen([cmd, '-v'], stdout=PIPE, stderr=PIPE).stderr + out = fp.read().strip() + fp.close() + return re.match('turbostat version [0-9\.]* .*', out) + def turbostat(self): + cmd = self.getExec('turbostat') + if not cmd: + return 'missing turbostat executable' + text = [] + fullcmd = '%s -q -S echo freeze > %s' % (cmd, self.powerfile) + fp = Popen(['sh', '-c', fullcmd], stdout=PIPE, stderr=PIPE).stderr + for line in fp: + if re.match('[0-9.]* sec', line): + continue + text.append(line.split()) + fp.close() + if len(text) < 2: + return 'turbostat output format error' + out = [] + for key in text[0]: + values = [] + idx = text[0].index(key) + for line in text[1:]: + if len(line) > idx: + values.append(line[idx]) + out.append('%s=%s' % (key, ','.join(values))) + return '|'.join(out) + def checkWifi(self): + out = dict() + iwcmd, ifcmd = self.getExec('iwconfig'), self.getExec('ifconfig') + if not iwcmd or not ifcmd: + return out + fp = Popen(iwcmd, stdout=PIPE, stderr=PIPE).stdout + for line in fp: + m = re.match('(?P<dev>\S*) .* ESSID:(?P<ess>\S*)', line) + if not m: + continue + out['device'] = m.group('dev') + if '"' in m.group('ess'): + out['essid'] = m.group('ess').strip('"') + break + fp.close() + if 'device' in out: + fp = Popen([ifcmd, out['device']], stdout=PIPE, stderr=PIPE).stdout + for line in fp: + m = re.match('.* inet (?P<ip>[0-9\.]*)', line) + if m: + out['ip'] = m.group('ip') + break + fp.close() + return out + def errorSummary(self, errinfo, msg): + found = False + for entry in errinfo: + if re.match(entry['match'], msg): + entry['count'] += 1 + if self.hostname not in entry['urls']: + entry['urls'][self.hostname] = [self.htmlfile] + elif self.htmlfile not in entry['urls'][self.hostname]: + entry['urls'][self.hostname].append(self.htmlfile) + found = True + break + if found: + return + arr = msg.split() + for j in range(len(arr)): + if re.match('^[0-9,\-\.]*$', arr[j]): + arr[j] = '[0-9,\-\.]*' + else: + arr[j] = arr[j]\ + .replace('\\', '\\\\').replace(']', '\]').replace('[', '\[')\ + .replace('.', '\.').replace('+', '\+').replace('*', '\*')\ + .replace('(', '\(').replace(')', '\)') + mstr = ' '.join(arr) + entry = { + 'line': msg, + 'match': mstr, + 'count': 1, + 'urls': {self.hostname: [self.htmlfile]} + } + errinfo.append(entry) sysvals = SystemValues() switchvalues = ['enable', 'disable', 'on', 'off', 'true', 'false', '1', '0'] @@ -915,7 +1065,14 @@ class Data: 'ERROR' : '.*ERROR.*', 'WARNING' : '.*WARNING.*', 'IRQ' : '.*genirq: .*', - 'TASKFAIL': '.*Freezing of tasks failed.*', + 'TASKFAIL': '.*Freezing of tasks *.*', + 'ACPI' : '.*ACPI *(?P<b>[A-Za-z]*) *Error[: ].*', + 'DEVFAIL' : '.* failed to (?P<b>[a-z]*) async: .*', + 'DISKFULL': '.*No space left on device.*', + 'USBERR' : '.*usb .*device .*, error [0-9-]*', + 'ATAERR' : ' *ata[0-9\.]*: .*failed.*', + 'MEIERR' : ' *mei.*: .*failed.*', + 'TPMERR' : '(?i) *tpm *tpm[0-9]*: .*error.*', } def __init__(self, num): idchar = 'abcdefghij' @@ -933,6 +1090,9 @@ class Data: self.outfile = '' self.kerror = False self.battery = 0 + self.wifi = 0 + self.turbostat = 0 + self.mcelog = 0 self.enterfail = '' self.currphase = '' self.pstl = dict() # process timeline @@ -967,8 +1127,24 @@ class Data: if len(plist) < 1: return '' return plist[-1] + def turbostatInfo(self): + tp = TestProps() + out = {'syslpi':'N/A','pkgpc10':'N/A'} + for line in self.dmesgtext: + m = re.match(tp.tstatfmt, line) + if not m: + continue + for i in m.group('t').split('|'): + if 'SYS%LPI' in i: + out['syslpi'] = i.split('=')[-1]+'%' + elif 'pc10' in i: + out['pkgpc10'] = i.split('=')[-1]+'%' + break + return out def extractErrorInfo(self): - lf = sysvals.openlog(sysvals.dmesgfile, 'r') + lf = self.dmesgtext + if len(self.dmesgtext) < 1 and sysvals.dmesgfile: + lf = sysvals.openlog(sysvals.dmesgfile, 'r') i = 0 list = [] for line in lf: @@ -983,16 +1159,19 @@ class Data: msg = m.group('msg') for err in self.errlist: if re.match(self.errlist[err], msg): - list.append((err, dir, t, i, i)) + list.append((msg, err, dir, t, i, i)) self.kerror = True break - for e in list: - type, dir, t, idx1, idx2 = e + msglist = [] + for msg, type, dir, t, idx1, idx2 in list: + msglist.append(msg) sysvals.vprint('kernel %s found in %s at %f' % (type, dir, t)) self.errorinfo[dir].append((type, t, idx1, idx2)) if self.kerror: sysvals.dmesglog = True - lf.close() + if len(self.dmesgtext) < 1 and sysvals.dmesgfile: + lf.close() + return msglist def setStart(self, time): self.start = time def setEnd(self, time): @@ -2045,7 +2224,7 @@ class FTraceCallGraph: if(data.dmesg[p]['start'] <= self.start and self.start <= data.dmesg[p]['end']): list = data.dmesg[p]['list'] - for devname in list: + for devname in sorted(list, key=lambda k:list[k]['start']): dev = list[devname] if(pid == dev['pid'] and self.start <= dev['start'] and @@ -2350,6 +2529,9 @@ class TestProps: '(?P<H>[0-9]{2})(?P<M>[0-9]{2})(?P<S>[0-9]{2})'+\ ' (?P<host>.*) (?P<mode>.*) (?P<kernel>.*)$' batteryfmt = '^# battery (?P<a1>\w*) (?P<c1>\d*) (?P<a2>\w*) (?P<c2>\d*)' + wififmt = '^# wifi (?P<w>.*)' + tstatfmt = '^# turbostat (?P<t>\S*)' + mcelogfmt = '^# mcelog (?P<m>\S*)' testerrfmt = '^# enter_sleep_error (?P<e>.*)' sysinfofmt = '^# sysinfo .*' cmdlinefmt = '^# command \| (?P<cmd>.*)' @@ -2372,7 +2554,10 @@ class TestProps: self.cmdline = '' self.kparams = '' self.testerror = [] + self.mcelog = [] + self.turbostat = [] self.battery = [] + self.wifi = [] self.fwdata = [] self.ftrace_line_fmt = self.ftrace_line_fmt_nop self.cgformat = False @@ -2386,6 +2571,44 @@ class TestProps: self.ftrace_line_fmt = self.ftrace_line_fmt_nop else: doError('Invalid tracer format: [%s]' % tracer) + def decode(self, data): + try: + out = base64.b64decode(data).decode('zlib') + except: + out = data + return out + def stampInfo(self, line): + if re.match(self.stampfmt, line): + self.stamp = line + return True + elif re.match(self.sysinfofmt, line): + self.sysinfo = line + return True + elif re.match(self.kparamsfmt, line): + self.kparams = line + return True + elif re.match(self.cmdlinefmt, line): + self.cmdline = line + return True + elif re.match(self.mcelogfmt, line): + self.mcelog.append(line) + return True + elif re.match(self.tstatfmt, line): + self.turbostat.append(line) + return True + elif re.match(self.batteryfmt, line): + self.battery.append(line) + return True + elif re.match(self.wififmt, line): + self.wifi.append(line) + return True + elif re.match(self.testerrfmt, line): + self.testerror.append(line) + return True + elif re.match(self.firmwarefmt, line): + self.fwdata.append(line) + return True + return False def parseStamp(self, data, sv): # global test data m = re.match(self.stampfmt, self.stamp) @@ -2428,14 +2651,31 @@ class TestProps: sv.stamp = data.stamp # firmware data if sv.suspendmode == 'mem' and len(self.fwdata) > data.testnumber: - data.fwSuspend, data.fwResume = self.fwdata[data.testnumber] - if(data.fwSuspend > 0 or data.fwResume > 0): - data.fwValid = True + m = re.match(self.firmwarefmt, self.fwdata[data.testnumber]) + if m: + data.fwSuspend, data.fwResume = int(m.group('s')), int(m.group('r')) + if(data.fwSuspend > 0 or data.fwResume > 0): + data.fwValid = True + # mcelog data + if len(self.mcelog) > data.testnumber: + m = re.match(self.mcelogfmt, self.mcelog[data.testnumber]) + if m: + data.mcelog = self.decode(m.group('m')) + # turbostat data + if len(self.turbostat) > data.testnumber: + m = re.match(self.tstatfmt, self.turbostat[data.testnumber]) + if m: + data.turbostat = m.group('t') # battery data if len(self.battery) > data.testnumber: m = re.match(self.batteryfmt, self.battery[data.testnumber]) if m: data.battery = m.groups() + # wifi data + if len(self.wifi) > data.testnumber: + m = re.match(self.wififmt, self.wifi[data.testnumber]) + if m: + data.wifi = m.group('w') # sleep mode enter errors if len(self.testerror) > data.testnumber: m = re.match(self.testerrfmt, self.testerror[data.testnumber]) @@ -2505,9 +2745,9 @@ class ProcessMonitor: # Quickly determine if the ftrace log has all of the trace events, # markers, and/or kprobes required for primary parsing. def doesTraceLogHaveTraceEvents(): - kpcheck = ['_cal: (', '_cpu_down()'] + kpcheck = ['_cal: (', '_ret: ('] techeck = ['suspend_resume', 'device_pm_callback'] - tmcheck = ['tracing_mark_write'] + tmcheck = ['SUSPEND START', 'RESUME COMPLETE'] sysvals.usekprobes = False fp = sysvals.openlog(sysvals.ftracefile, 'r') for line in fp: @@ -2556,21 +2796,7 @@ def appendIncompleteTraceLog(testruns): for line in tf: # remove any latent carriage returns line = line.replace('\r\n', '') - # grab the stamp and sysinfo - if re.match(tp.stampfmt, line): - tp.stamp = line - continue - elif re.match(tp.sysinfofmt, line): - tp.sysinfo = line - continue - elif re.match(tp.cmdlinefmt, line): - tp.cmdline = line - continue - elif re.match(tp.batteryfmt, line): - tp.battery.append(line) - continue - elif re.match(tp.testerrfmt, line): - tp.testerror.append(line) + if tp.stampInfo(line): continue # determine the trace data type (required for further parsing) m = re.match(tp.tracertypefmt, line) @@ -2693,26 +2919,7 @@ def parseTraceLog(live=False): for line in tf: # remove any latent carriage returns line = line.replace('\r\n', '') - # stamp and sysinfo lines - if re.match(tp.stampfmt, line): - tp.stamp = line - continue - elif re.match(tp.sysinfofmt, line): - tp.sysinfo = line - continue - elif re.match(tp.cmdlinefmt, line): - tp.cmdline = line - continue - elif re.match(tp.batteryfmt, line): - tp.battery.append(line) - continue - elif re.match(tp.testerrfmt, line): - tp.testerror.append(line) - continue - # firmware line: pull out any firmware data - m = re.match(tp.firmwarefmt, line) - if(m): - tp.fwdata.append((int(m.group('s')), int(m.group('r')))) + if tp.stampInfo(line): continue # tracer type line: determine the trace data type m = re.match(tp.tracertypefmt, line) @@ -2925,7 +3132,7 @@ def parseTraceLog(live=False): tp.ktemp[key].append({ 'pid': pid, 'begin': t.time, - 'end': t.time, + 'end': -1, 'name': displayname, 'cdata': kprobedata, 'proc': m_proc, @@ -2936,12 +3143,11 @@ def parseTraceLog(live=False): elif(t.freturn): if(key not in tp.ktemp) or len(tp.ktemp[key]) < 1: continue - e = tp.ktemp[key][-1] - if e['begin'] < 0.0 or t.time - e['begin'] < 0.000001: - tp.ktemp[key].pop() - else: - e['end'] = t.time - e['rdata'] = kprobedata + e = next((x for x in reversed(tp.ktemp[key]) if x['end'] < 0), 0) + if not e: + continue + e['end'] = t.time + e['rdata'] = kprobedata # end of kernel resume if(phase != 'suspend_prepare' and kprobename in krescalls): if phase in data.dmesg: @@ -2963,8 +3169,10 @@ def parseTraceLog(live=False): if(res == -1): testrun.ftemp[key][-1].addLine(t) tf.close() + if len(testdata) < 1: + sysvals.vprint('WARNING: ftrace start marker is missing') if data and not data.devicegroups: - sysvals.vprint('WARNING: end marker is missing') + sysvals.vprint('WARNING: ftrace end marker is missing') data.handleEndMarker(t.time) if sysvals.suspendmode == 'command': @@ -3013,9 +3221,11 @@ def parseTraceLog(live=False): name, pid = key if name not in sysvals.tracefuncs: continue + if pid not in data.devpids: + data.devpids.append(pid) for e in tp.ktemp[key]: kb, ke = e['begin'], e['end'] - if kb == ke or tlb > kb or tle <= kb: + if ke - kb < 0.000001 or tlb > kb or tle <= kb: continue color = sysvals.kprobeColor(name) data.newActionGlobal(e['name'], kb, ke, pid, color) @@ -3027,7 +3237,7 @@ def parseTraceLog(live=False): continue for e in tp.ktemp[key]: kb, ke = e['begin'], e['end'] - if kb == ke or tlb > kb or tle <= kb: + if ke - kb < 0.000001 or tlb > kb or tle <= kb: continue data.addDeviceFunctionCall(e['name'], name, e['proc'], pid, kb, ke, e['cdata'], e['rdata']) @@ -3051,7 +3261,7 @@ def parseTraceLog(live=False): if not devname: sortkey = '%f%f%d' % (cg.start, cg.end, pid) sortlist[sortkey] = cg - elif len(cg.list) > 1000000: + elif len(cg.list) > 1000000 and cg.name != sysvals.ftopfunc: sysvals.vprint('WARNING: the callgraph for %s is massive (%d lines)' %\ (devname, len(cg.list))) # create blocks for orphan cg data @@ -3133,25 +3343,7 @@ def loadKernelLog(): idx = line.find('[') if idx > 1: line = line[idx:] - # grab the stamp and sysinfo - if re.match(tp.stampfmt, line): - tp.stamp = line - continue - elif re.match(tp.sysinfofmt, line): - tp.sysinfo = line - continue - elif re.match(tp.cmdlinefmt, line): - tp.cmdline = line - continue - elif re.match(tp.batteryfmt, line): - tp.battery.append(line) - continue - elif re.match(tp.testerrfmt, line): - tp.testerror.append(line) - continue - m = re.match(tp.firmwarefmt, line) - if(m): - tp.fwdata.append((int(m.group('s')), int(m.group('r')))) + if tp.stampInfo(line): continue m = re.match('[ \t]*(\[ *)(?P<ktime>[0-9\.]*)(\]) (?P<msg>.*)', line) if(not m): @@ -3176,7 +3368,7 @@ def loadKernelLog(): if data: testruns.append(data) if len(testruns) < 1: - pprint('ERROR: dmesg log has no suspend/resume data: %s' \ + doError('dmesg log has no suspend/resume data: %s' \ % sysvals.dmesgfile) # fix lines with same timestamp/function with the call and return swapped @@ -3515,6 +3707,8 @@ def addCallgraphs(sv, hf, data): name += ' '+p if('ftrace' in dev): cg = dev['ftrace'] + if cg.name == sv.ftopfunc: + name = 'top level suspend/resume call' num = callgraphHTML(sv, hf, num, cg, name, color, dev['id']) if('ftraces' in dev): @@ -3523,22 +3717,16 @@ def addCallgraphs(sv, hf, data): name+' → '+cg.name, color, dev['id']) hf.write('\n\n </section>\n') -# Function: createHTMLSummarySimple -# Description: -# Create summary html file for a series of tests -# Arguments: -# testruns: array of Data objects from parseTraceLog -def createHTMLSummarySimple(testruns, htmlfile, title): - # write the html header first (html head, css code, up to body start) - html = '<!DOCTYPE html>\n<html>\n<head>\n\ +def summaryCSS(title, center=True): + tdcenter = 'text-align:center;' if center else '' + out = '<!DOCTYPE html>\n<html>\n<head>\n\ <meta http-equiv="content-type" content="text/html; charset=UTF-8">\n\ - <title>SleepGraph Summary</title>\n\ + <title>'+title+'</title>\n\ <style type=\'text/css\'>\n\ .stamp {width: 100%;text-align:center;background:#888;line-height:30px;color:white;font: 25px Arial;}\n\ - table {width:100%;border-collapse: collapse;}\n\ - .summary {border:1px solid;}\n\ + table {width:100%;border-collapse: collapse;border:1px solid;}\n\ th {border: 1px solid black;background:#222;color:white;}\n\ - td {font: 14px "Times New Roman";text-align: center;}\n\ + td {font: 14px "Times New Roman";'+tdcenter+'}\n\ tr.head td {border: 1px solid black;background:#aaa;}\n\ tr.alt {background-color:#ddd;}\n\ tr.notice {color:red;}\n\ @@ -3547,12 +3735,23 @@ def createHTMLSummarySimple(testruns, htmlfile, title): .maxval {background-color:#FFBBBB;}\n\ .head a {color:#000;text-decoration: none;}\n\ </style>\n</head>\n<body>\n' + return out + +# Function: createHTMLSummarySimple +# Description: +# Create summary html file for a series of tests +# Arguments: +# testruns: array of Data objects from parseTraceLog +def createHTMLSummarySimple(testruns, htmlfile, title): + # write the html header first (html head, css code, up to body start) + html = summaryCSS('Summary - SleepGraph') # extract the test data into list list = dict() - tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [[], []] + tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [dict(), dict()] iMin, iMed, iMax = [0, 0], [0, 0], [0, 0] num = 0 + useturbo = False lastmode = '' cnt = dict() for data in sorted(testruns, key=lambda v:(v['mode'], v['host'], v['kernel'], v['time'])): @@ -3563,27 +3762,35 @@ def createHTMLSummarySimple(testruns, htmlfile, title): for i in range(2): s = sorted(tMed[i]) list[lastmode]['med'][i] = s[int(len(s)/2)] - iMed[i] = tMed[i].index(list[lastmode]['med'][i]) + iMed[i] = tMed[i][list[lastmode]['med'][i]] list[lastmode]['avg'] = [tAvg[0] / num, tAvg[1] / num] list[lastmode]['min'] = tMin list[lastmode]['max'] = tMax list[lastmode]['idx'] = (iMin, iMed, iMax) - tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [[], []] + tAvg, tMin, tMax, tMed = [0.0, 0.0], [0.0, 0.0], [0.0, 0.0], [dict(), dict()] iMin, iMed, iMax = [0, 0], [0, 0], [0, 0] num = 0 + pkgpc10 = syslpi = '' + if 'pkgpc10' in data and 'syslpi' in data: + pkgpc10 = data['pkgpc10'] + syslpi = data['syslpi'] + useturbo = True + res = data['result'] tVal = [float(data['suspend']), float(data['resume'])] list[mode]['data'].append([data['host'], data['kernel'], - data['time'], tVal[0], tVal[1], data['url'], data['result'], + data['time'], tVal[0], tVal[1], data['url'], res, data['issues'], data['sus_worst'], data['sus_worsttime'], - data['res_worst'], data['res_worsttime']]) + data['res_worst'], data['res_worsttime'], pkgpc10, syslpi]) idx = len(list[mode]['data']) - 1 - if data['result'] not in cnt: - cnt[data['result']] = 1 + if res.startswith('fail in'): + res = 'fail' + if res not in cnt: + cnt[res] = 1 else: - cnt[data['result']] += 1 - if data['result'] == 'pass': + cnt[res] += 1 + if res == 'pass': for i in range(2): - tMed[i].append(tVal[i]) + tMed[i][tVal[i]] = idx tAvg[i] += tVal[i] if tMin[i] == 0 or tVal[i] < tMin[i]: iMin[i] = idx @@ -3597,7 +3804,7 @@ def createHTMLSummarySimple(testruns, htmlfile, title): for i in range(2): s = sorted(tMed[i]) list[lastmode]['med'][i] = s[int(len(s)/2)] - iMed[i] = tMed[i].index(list[lastmode]['med'][i]) + iMed[i] = tMed[i][list[lastmode]['med'][i]] list[lastmode]['avg'] = [tAvg[0] / num, tAvg[1] / num] list[lastmode]['min'] = tMin list[lastmode]['max'] = tMax @@ -3613,19 +3820,21 @@ def createHTMLSummarySimple(testruns, htmlfile, title): td = '\t<td>{0}</td>\n' tdh = '\t<td{1}>{0}</td>\n' tdlink = '\t<td><a href="{0}">html</a></td>\n' + colspan = '14' if useturbo else '12' # table header - html += '<table class="summary">\n<tr>\n' + th.format('#') +\ + html += '<table>\n<tr>\n' + th.format('#') +\ th.format('Mode') + th.format('Host') + th.format('Kernel') +\ th.format('Test Time') + th.format('Result') + th.format('Issues') +\ th.format('Suspend') + th.format('Resume') +\ th.format('Worst Suspend Device') + th.format('SD Time') +\ - th.format('Worst Resume Device') + th.format('RD Time') +\ - th.format('Detail') + '</tr>\n' - + th.format('Worst Resume Device') + th.format('RD Time') + if useturbo: + html += th.format('PkgPC10') + th.format('SysLPI') + html += th.format('Detail')+'</tr>\n' # export list into html head = '<tr class="head"><td>{0}</td><td>{1}</td>'+\ - '<td colspan=12 class="sus">Suspend Avg={2} '+\ + '<td colspan='+colspan+' class="sus">Suspend Avg={2} '+\ '<span class=minval><a href="#s{10}min">Min={3}</a></span> '+\ '<span class=medval><a href="#s{10}med">Med={4}</a></span> '+\ '<span class=maxval><a href="#s{10}max">Max={5}</a></span> '+\ @@ -3634,7 +3843,8 @@ def createHTMLSummarySimple(testruns, htmlfile, title): '<span class=medval><a href="#r{10}med">Med={8}</a></span> '+\ '<span class=maxval><a href="#r{10}max">Max={9}</a></span></td>'+\ '</tr>\n' - headnone = '<tr class="head"><td>{0}</td><td>{1}</td><td colspan=12></td></tr>\n' + headnone = '<tr class="head"><td>{0}</td><td>{1}</td><td colspan='+\ + colspan+'></td></tr>\n' for mode in list: # header line for each suspend mode num = 0 @@ -3681,6 +3891,9 @@ def createHTMLSummarySimple(testruns, htmlfile, title): html += td.format('%.3f ms' % d[9]) if d[9] else td.format('') # sus_worst time html += td.format(d[10]) # res_worst html += td.format('%.3f ms' % d[11]) if d[11] else td.format('') # res_worst time + if useturbo: + html += td.format(d[12]) # pkg_pc10 + html += td.format(d[13]) # syslpi html += tdlink.format(d[5]) if d[5] else td.format('') # url html += '</tr>\n' num += 1 @@ -3690,6 +3903,115 @@ def createHTMLSummarySimple(testruns, htmlfile, title): hf.write(html+'</table>\n</body>\n</html>\n') hf.close() +def createHTMLDeviceSummary(testruns, htmlfile, title): + html = summaryCSS('Device Summary - SleepGraph', False) + + # create global device list from all tests + devall = dict() + for data in testruns: + host, url, devlist = data['host'], data['url'], data['devlist'] + for type in devlist: + if type not in devall: + devall[type] = dict() + mdevlist, devlist = devall[type], data['devlist'][type] + for name in devlist: + length = devlist[name] + if name not in mdevlist: + mdevlist[name] = {'name': name, 'host': host, + 'worst': length, 'total': length, 'count': 1, + 'url': url} + else: + if length > mdevlist[name]['worst']: + mdevlist[name]['worst'] = length + mdevlist[name]['url'] = url + mdevlist[name]['host'] = host + mdevlist[name]['total'] += length + mdevlist[name]['count'] += 1 + + # generate the html + th = '\t<th>{0}</th>\n' + td = '\t<td align=center>{0}</td>\n' + tdr = '\t<td align=right>{0}</td>\n' + tdlink = '\t<td align=center><a href="{0}">html</a></td>\n' + limit = 1 + for type in sorted(devall, reverse=True): + num = 0 + devlist = devall[type] + # table header + html += '<div class="stamp">%s (%s devices > %d ms)</div><table>\n' % \ + (title, type.upper(), limit) + html += '<tr>\n' + '<th align=right>Device Name</th>' +\ + th.format('Average Time') + th.format('Count') +\ + th.format('Worst Time') + th.format('Host (worst time)') +\ + th.format('Link (worst time)') + '</tr>\n' + for name in sorted(devlist, key=lambda k:devlist[k]['worst'], reverse=True): + data = devall[type][name] + data['average'] = data['total'] / data['count'] + if data['average'] < limit: + continue + # row classes - alternate row color + rcls = ['alt'] if num % 2 == 1 else [] + html += '<tr class="'+(' '.join(rcls))+'">\n' if len(rcls) > 0 else '<tr>\n' + html += tdr.format(data['name']) # name + html += td.format('%.3f ms' % data['average']) # average + html += td.format(data['count']) # count + html += td.format('%.3f ms' % data['worst']) # worst + html += td.format(data['host']) # host + html += tdlink.format(data['url']) # url + html += '</tr>\n' + num += 1 + html += '</table>\n' + + # flush the data to file + hf = open(htmlfile, 'w') + hf.write(html+'</body>\n</html>\n') + hf.close() + return devall + +def createHTMLIssuesSummary(testruns, issues, htmlfile, title, extra=''): + multihost = len([e for e in issues if len(e['urls']) > 1]) > 0 + html = summaryCSS('Issues Summary - SleepGraph', False) + total = len(testruns) + + # generate the html + th = '\t<th>{0}</th>\n' + td = '\t<td align={0}>{1}</td>\n' + tdlink = '<a href="{1}">{0}</a>' + subtitle = '%d issues' % len(issues) if len(issues) > 0 else 'no issues' + html += '<div class="stamp">%s (%s)</div><table>\n' % (title, subtitle) + html += '<tr>\n' + th.format('Issue') + th.format('Count') + if multihost: + html += th.format('Hosts') + html += th.format('Tests') + th.format('Fail Rate') +\ + th.format('First Instance') + '</tr>\n' + + num = 0 + for e in sorted(issues, key=lambda v:v['count'], reverse=True): + testtotal = 0 + links = [] + for host in sorted(e['urls']): + links.append(tdlink.format(host, e['urls'][host][0])) + testtotal += len(e['urls'][host]) + rate = '%d/%d (%.2f%%)' % (testtotal, total, 100*float(testtotal)/float(total)) + # row classes - alternate row color + rcls = ['alt'] if num % 2 == 1 else [] + html += '<tr class="'+(' '.join(rcls))+'">\n' if len(rcls) > 0 else '<tr>\n' + html += td.format('left', e['line']) # issue + html += td.format('center', e['count']) # count + if multihost: + html += td.format('center', len(e['urls'])) # hosts + html += td.format('center', testtotal) # test count + html += td.format('center', rate) # test rate + html += td.format('center nowrap', '<br>'.join(links)) # links + html += '</tr>\n' + num += 1 + + # flush the data to file + hf = open(htmlfile, 'w') + hf.write(html+'</table>\n'+extra+'</body>\n</html>\n') + hf.close() + return issues + def ordinal(value): suffix = 'th' if value < 10 or value > 19: @@ -3991,7 +4313,7 @@ def createHTML(testruns, testfail): for word in phase.split('_'): id += word[0] order = '%.2f' % ((p['order'] * pdelta) + pmargin) - name = string.replace(phase, '_', ' ') + name = phase.replace('_', ' ') devtl.html += devtl.html_legend.format(order, p['color'], name, id) devtl.html += '</div>\n' @@ -4580,6 +4902,7 @@ def setRuntimeSuspend(before=True): def executeSuspend(): pm = ProcessMonitor() tp = sysvals.tpath + wifi = sysvals.checkWifi() testdata = [] battery = True if getBattery() else False # run these commands to prepare the system for suspend @@ -4613,6 +4936,7 @@ def executeSuspend(): pprint('SUSPEND START') else: pprint('SUSPEND START (press a key to resume)') + sysvals.mcelog(True) bat1 = getBattery() if battery else False # set rtcwake if(sysvals.rtcwake): @@ -4644,13 +4968,23 @@ def executeSuspend(): pf = open(sysvals.diskpowerfile, 'w') pf.write(sysvals.diskmode) pf.close() - pf = open(sysvals.powerfile, 'w') - pf.write(mode) - # execution will pause here - try: - pf.close() - except Exception as e: - tdata['error'] = str(e) + if mode == 'freeze' and sysvals.haveTurbostat(): + # execution will pause here + turbo = sysvals.turbostat() + if '|' in turbo: + tdata['turbo'] = turbo + else: + tdata['error'] = turbo + else: + if sysvals.haveTurbostat(): + sysvals.vprint('WARNING: ignoring turbostat in mode "%s"' % mode) + pf = open(sysvals.powerfile, 'w') + pf.write(mode) + # execution will pause here + try: + pf.close() + except Exception as e: + tdata['error'] = str(e) if(sysvals.rtcwake): sysvals.rtcWakeAlarmOff() # postdelay delay @@ -4664,9 +4998,14 @@ def executeSuspend(): sysvals.fsetVal('RESUME COMPLETE', 'trace_marker') if(sysvals.suspendmode == 'mem' or sysvals.suspendmode == 'command'): tdata['fw'] = getFPDT(False) + mcelog = sysvals.mcelog() + if mcelog: + tdata['mcelog'] = mcelog bat2 = getBattery() if battery else False if battery and bat1 and bat2: tdata['bat'] = (bat1, bat2) + if 'device' in wifi and 'ip' in wifi: + tdata['wifi'] = (wifi, sysvals.checkWifi()) testdata.append(tdata) # stop ftrace if(sysvals.usecallgraph or sysvals.usetraceevents): @@ -4686,6 +5025,7 @@ def executeSuspend(): op.close() sysvals.fsetVal('', 'trace') devProps() + return testdata def readFile(file): if os.path.islink(file): @@ -4772,7 +5112,7 @@ def deviceInfo(output=''): ms2nice(power['runtime_active_time']), \ ms2nice(power['runtime_suspended_time'])) for i in sorted(lines): - print lines[i] + print(lines[i]) return res # Function: devProps @@ -4905,12 +5245,12 @@ def getModes(): modes = [] if(os.path.exists(sysvals.powerfile)): fp = open(sysvals.powerfile, 'r') - modes = string.split(fp.read()) + modes = fp.read().split() fp.close() if(os.path.exists(sysvals.mempowerfile)): deep = False fp = open(sysvals.mempowerfile, 'r') - for m in string.split(fp.read()): + for m in fp.read().split(): memmode = m.strip('[]') if memmode == 'deep': deep = True @@ -4921,7 +5261,7 @@ def getModes(): modes.remove('mem') if('disk' in modes and os.path.exists(sysvals.diskpowerfile)): fp = open(sysvals.diskpowerfile, 'r') - for m in string.split(fp.read()): + for m in fp.read().split(): modes.append('disk-%s' % m.strip('[]')) fp.close() return modes @@ -4984,14 +5324,15 @@ def dmidecode(mempath, fatal=False): continue # read in the memory for scanning - fp = open(mempath, 'rb') try: + fp = open(mempath, 'rb') fp.seek(memaddr) buf = fp.read(memsize) except: if(fatal): doError('DMI table is unreachable, sorry') else: + pprint('WARNING: /dev/mem is not readable, ignoring DMI data') return out fp.close() @@ -5014,14 +5355,15 @@ def dmidecode(mempath, fatal=False): return out # read in the SM or DMI table - fp = open(mempath, 'rb') try: + fp = open(mempath, 'rb') fp.seek(base) buf = fp.read(length) except: if(fatal): doError('DMI table is unreachable, sorry') else: + pprint('WARNING: /dev/mem is not readable, ignoring DMI data') return out fp.close() @@ -5165,7 +5507,11 @@ def getFPDT(output): i = 0 fwData = [0, 0] records = buf[36:] - fp = open(sysvals.mempath, 'rb') + try: + fp = open(sysvals.mempath, 'rb') + except: + pprint('WARNING: /dev/mem is not readable, ignoring the FPDT data') + return False while(i < len(records)): header = struct.unpack('HBB', records[i:i+4]) if(header[0] not in rectype): @@ -5282,13 +5628,14 @@ def statusCheck(probecheck=False): pprint(' is ftrace supported: %s' % res) # check if kprobes are available - res = sysvals.colorText('NO') - sysvals.usekprobes = sysvals.verifyKprobes() - if(sysvals.usekprobes): - res = 'YES' - else: - sysvals.usedevsrc = False - pprint(' are kprobes supported: %s' % res) + if sysvals.usekprobes: + res = sysvals.colorText('NO') + sysvals.usekprobes = sysvals.verifyKprobes() + if(sysvals.usekprobes): + res = 'YES' + else: + sysvals.usedevsrc = False + pprint(' are kprobes supported: %s' % res) # what data source are we using res = 'DMESG' @@ -5376,6 +5723,8 @@ def getArgFloat(name, args, min, max, main=True): def processData(live=False): pprint('PROCESSING DATA') + sysvals.vprint('usetraceevents=%s, usetracemarkers=%s, usekprobes=%s' % \ + (sysvals.usetraceevents, sysvals.usetracemarkers, sysvals.usekprobes)) error = '' if(sysvals.usetraceevents): testruns, error = parseTraceLog(live) @@ -5388,13 +5737,36 @@ def processData(live=False): parseKernelLog(data) if(sysvals.ftracefile and (sysvals.usecallgraph or sysvals.usetraceevents)): appendIncompleteTraceLog(testruns) + sysvals.vprint('System Info:') + for key in sorted(sysvals.stamp): + sysvals.vprint(' %-8s : %s' % (key.upper(), sysvals.stamp[key])) + if sysvals.kparams: + sysvals.vprint('Kparams:\n %s' % sysvals.kparams) sysvals.vprint('Command:\n %s' % sysvals.cmdline) for data in testruns: + if data.mcelog: + sysvals.vprint('MCELOG Data:') + for line in data.mcelog.split('\n'): + sysvals.vprint(' %s' % line) + if data.turbostat: + idx, s = 0, 'Turbostat:\n ' + for val in data.turbostat.split('|'): + idx += len(val) + 1 + if idx >= 80: + idx = 0 + s += '\n ' + s += val + ' ' + sysvals.vprint(s) if data.battery: a1, c1, a2, c2 = data.battery s = 'Battery:\n Before - AC: %s, Charge: %d\n After - AC: %s, Charge: %d' % \ (a1, int(c1), a2, int(c2)) sysvals.vprint(s) + if data.wifi: + w = data.wifi.replace('|', ' ').split(',') + s = 'Wifi:\n Before %s\n After %s' % \ + (w[0], w[1]) + sysvals.vprint(s) data.printDetails() if sysvals.cgdump: for data in testruns: @@ -5418,12 +5790,15 @@ def processData(live=False): # Function: rerunTest # Description: # generate an output from an existing set of ftrace/dmesg logs -def rerunTest(): +def rerunTest(htmlfile=''): if sysvals.ftracefile: doesTraceLogHaveTraceEvents() if not sysvals.dmesgfile and not sysvals.usetraceevents: doError('recreating this html output requires a dmesg file') - sysvals.setOutputFile() + if htmlfile: + sysvals.htmlfile = htmlfile + else: + sysvals.setOutputFile() if os.path.exists(sysvals.htmlfile): if not os.path.isfile(sysvals.htmlfile): doError('a directory already exists with this name: %s' % sysvals.htmlfile) @@ -5442,14 +5817,18 @@ def runTest(n=0): sysvals.initTestOutput('suspend') # execute the test - executeSuspend() + testdata = executeSuspend() sysvals.cleanupFtrace() if sysvals.skiphtml: sysvals.sudoUserchown(sysvals.testdir) return - testruns, stamp = processData(True) - for data in testruns: - del data + if not testdata[0]['error']: + testruns, stamp = processData(True) + for data in testruns: + del data + else: + stamp = testdata[0] + sysvals.sudoUserchown(sysvals.testdir) sysvals.outputResult(stamp, n) if 'error' in stamp: @@ -5479,10 +5858,13 @@ def find_in_html(html, start, end, firstonly=True): return '' return out -def data_from_html(file, outpath, devlist=False): +def data_from_html(file, outpath, issues, fulldetail=False): html = open(file, 'r').read() + sysvals.htmlfile = os.path.relpath(file, outpath) + # extract general info suspend = find_in_html(html, 'Kernel Suspend', 'ms') resume = find_in_html(html, 'Kernel Resume', 'ms') + sysinfo = find_in_html(html, '<div class="stamp sysinfo">', '</div>') line = find_in_html(html, '<div class="stamp">', '</div>') stmp = line.split() if not suspend or not resume or len(stmp) != 8: @@ -5491,6 +5873,7 @@ def data_from_html(file, outpath, devlist=False): dt = datetime.strptime(' '.join(stmp[3:]), '%B %d %Y, %I:%M:%S %p') except: return False + sysvals.hostname = stmp[0] tstr = dt.strftime('%Y/%m/%d %H:%M:%S') error = find_in_html(html, '<table class="testfail"><tr><td>', '</td>') if error: @@ -5501,13 +5884,45 @@ def data_from_html(file, outpath, devlist=False): result = 'fail' else: result = 'pass' + # extract error info ilist = [] - e = find_in_html(html, 'class="err"[\w=":;\.%\- ]*>', '→</div>', False) - for i in list(set(e)): - ilist.append('%sx%d' % (i, e.count(i)) if e.count(i) > 1 else i) + extra = dict() + log = find_in_html(html, '<div id="dmesglog" style="display:none;">', + '</div>').strip() + if log: + d = Data(0) + d.end = 999999999 + d.dmesgtext = log.split('\n') + msglist = d.extractErrorInfo() + for msg in msglist: + sysvals.errorSummary(issues, msg) + if stmp[2] == 'freeze': + extra = d.turbostatInfo() + elist = dict() + for dir in d.errorinfo: + for err in d.errorinfo[dir]: + if err[0] not in elist: + elist[err[0]] = 0 + elist[err[0]] += 1 + for i in elist: + ilist.append('%sx%d' % (i, elist[i]) if elist[i] > 1 else i) low = find_in_html(html, 'freeze time: <b>', ' ms</b>') if low and '|' in low: - ilist.append('FREEZEx%d' % len(low.split('|'))) + issue = 'FREEZEx%d' % len(low.split('|')) + match = [i for i in issues if i['match'] == issue] + if len(match) > 0: + match[0]['count'] += 1 + if sysvals.hostname not in match[0]['urls']: + match[0]['urls'][sysvals.hostname] = [sysvals.htmlfile] + elif sysvals.htmlfile not in match[0]['urls'][sysvals.hostname]: + match[0]['urls'][sysvals.hostname].append(sysvals.htmlfile) + else: + issues.append({ + 'match': issue, 'count': 1, 'line': issue, + 'urls': {sysvals.hostname: [sysvals.htmlfile]}, + }) + ilist.append(issue) + # extract device info devices = dict() for line in html.split('\n'): m = re.match(' *<div id=\"[a,0-9]*\" *title=\"(?P<title>.*)\" class=\"thread.*', line) @@ -5519,82 +5934,98 @@ def data_from_html(file, outpath, devlist=False): name, time, phase = m.group('n'), m.group('t'), m.group('p') if ' async' in name or ' sync' in name: name = ' '.join(name.split(' ')[:-1]) - d = phase.split('_')[0] + if phase.startswith('suspend'): + d = 'suspend' + elif phase.startswith('resume'): + d = 'resume' + else: + continue if d not in devices: devices[d] = dict() if name not in devices[d]: devices[d][name] = 0.0 devices[d][name] += float(time) - worst = {'suspend': {'name':'', 'time': 0.0}, - 'resume': {'name':'', 'time': 0.0}} - for d in devices: - if d not in worst: - worst[d] = dict() - dev = devices[d] - if len(dev.keys()) > 0: + # create worst device info + worst = dict() + for d in ['suspend', 'resume']: + worst[d] = {'name':'', 'time': 0.0} + dev = devices[d] if d in devices else 0 + if dev and len(dev.keys()) > 0: n = sorted(dev, key=dev.get, reverse=True)[0] worst[d]['name'], worst[d]['time'] = n, dev[n] data = { 'mode': stmp[2], 'host': stmp[0], 'kernel': stmp[1], + 'sysinfo': sysinfo, 'time': tstr, 'result': result, 'issues': ' '.join(ilist), 'suspend': suspend, 'resume': resume, + 'devlist': devices, 'sus_worst': worst['suspend']['name'], 'sus_worsttime': worst['suspend']['time'], 'res_worst': worst['resume']['name'], 'res_worsttime': worst['resume']['time'], - 'url': os.path.relpath(file, outpath), + 'url': sysvals.htmlfile, } - if devlist: - data['devlist'] = devices + for key in extra: + data[key] = extra[key] + if fulldetail: + data['funclist'] = find_in_html(html, '<div title="', '" class="traceevent"', False) return data +def genHtml(subdir): + for dirname, dirnames, filenames in os.walk(subdir): + sysvals.dmesgfile = sysvals.ftracefile = sysvals.htmlfile = '' + for filename in filenames: + if(re.match('.*_dmesg.txt', filename)): + sysvals.dmesgfile = os.path.join(dirname, filename) + elif(re.match('.*_ftrace.txt', filename)): + sysvals.ftracefile = os.path.join(dirname, filename) + sysvals.setOutputFile() + if sysvals.ftracefile and sysvals.htmlfile and \ + not os.path.exists(sysvals.htmlfile): + pprint('FTRACE: %s' % sysvals.ftracefile) + if sysvals.dmesgfile: + pprint('DMESG : %s' % sysvals.dmesgfile) + rerunTest() + # Function: runSummary # Description: # create a summary of tests in a sub-directory def runSummary(subdir, local=True, genhtml=False): inpath = os.path.abspath(subdir) outpath = os.path.abspath('.') if local else inpath - pprint('Generating a summary of folder "%s"' % inpath) + pprint('Generating a summary of folder:\n %s' % inpath) if genhtml: - for dirname, dirnames, filenames in os.walk(subdir): - sysvals.dmesgfile = sysvals.ftracefile = sysvals.htmlfile = '' - for filename in filenames: - if(re.match('.*_dmesg.txt', filename)): - sysvals.dmesgfile = os.path.join(dirname, filename) - elif(re.match('.*_ftrace.txt', filename)): - sysvals.ftracefile = os.path.join(dirname, filename) - sysvals.setOutputFile() - if sysvals.ftracefile and sysvals.htmlfile and \ - not os.path.exists(sysvals.htmlfile): - pprint('FTRACE: %s' % sysvals.ftracefile) - if sysvals.dmesgfile: - pprint('DMESG : %s' % sysvals.dmesgfile) - rerunTest() + genHtml(subdir) + issues = [] testruns = [] desc = {'host':[],'mode':[],'kernel':[]} for dirname, dirnames, filenames in os.walk(subdir): for filename in filenames: if(not re.match('.*.html', filename)): continue - data = data_from_html(os.path.join(dirname, filename), outpath) + data = data_from_html(os.path.join(dirname, filename), outpath, issues) if(not data): continue testruns.append(data) for key in desc: if data[key] not in desc[key]: desc[key].append(data[key]) - outfile = os.path.join(outpath, 'summary.html') - pprint('Summary file: %s' % outfile) + pprint('Summary files:') if len(desc['host']) == len(desc['mode']) == len(desc['kernel']) == 1: title = '%s %s %s' % (desc['host'][0], desc['kernel'][0], desc['mode'][0]) else: title = inpath - createHTMLSummarySimple(testruns, outfile, title) + createHTMLSummarySimple(testruns, os.path.join(outpath, 'summary.html'), title) + pprint(' summary.html - tabular list of test data found') + createHTMLDeviceSummary(testruns, os.path.join(outpath, 'summary-devices.html'), title) + pprint(' summary-devices.html - kernel device list sorted by total execution time') + createHTMLIssuesSummary(testruns, issues, os.path.join(outpath, 'summary-issues.html'), title) + pprint(' summary-issues.html - kernel issues found sorted by frequency') # Function: checkArgBool # Description: @@ -5839,6 +6270,7 @@ def printHelp(): ' default: suspend-{date}-{time}\n'\ ' -rtcwake t Wakeup t seconds after suspend, set t to "off" to disable (default: 15)\n'\ ' -addlogs Add the dmesg and ftrace logs to the html output\n'\ + ' -turbostat Use turbostat to execute the command in freeze mode (default: disabled)\n'\ ' -srgap Add a visible gap in the timeline between sus/res (default: disabled)\n'\ ' -skiphtml Run the test and capture the trace logs, but skip the timeline (default: disabled)\n'\ ' -result fn Export a results table to a text file for parsing.\n'\ @@ -5860,6 +6292,7 @@ def printHelp(): ' be created in a new subdirectory with a summary page.\n'\ ' [debug]\n'\ ' -f Use ftrace to create device callgraphs (default: disabled)\n'\ + ' -ftop Use ftrace on the top level call: "%s" (default: disabled)\n'\ ' -maxdepth N limit the callgraph data to N call levels (default: 0=all)\n'\ ' -expandcg pre-expand the callgraph data in the html output (default: disabled)\n'\ ' -fadd file Add functions to be graphed in the timeline from a list in a text file\n'\ @@ -5879,6 +6312,7 @@ def printHelp(): ' -status Test to see if the system is enabled to run this tool\n'\ ' -fpdt Print out the contents of the ACPI Firmware Performance Data Table\n'\ ' -battery Print out battery info (if available)\n'\ + ' -wifi Print out wifi connection info (if wireless-tools and device exists)\n'\ ' -x<mode> Test xset by toggling the given mode (on/off/standby/suspend)\n'\ ' -sysinfo Print out system info extracted from BIOS\n'\ ' -devinfo Print out the pm settings of all devices which support runtime suspend\n'\ @@ -5888,7 +6322,7 @@ def printHelp(): ' [redo]\n'\ ' -ftrace ftracefile Create HTML output using ftrace input (used with -dmesg)\n'\ ' -dmesg dmesgfile Create HTML output using dmesg (used with -ftrace)\n'\ - '' % (sysvals.title, sysvals.version, sysvals.suspendmode)) + '' % (sysvals.title, sysvals.version, sysvals.suspendmode, sysvals.ftopfunc)) return True # ----------------- MAIN -------------------- @@ -5898,7 +6332,7 @@ if __name__ == '__main__': cmd = '' simplecmds = ['-sysinfo', '-modes', '-fpdt', '-flist', '-flistall', '-devinfo', '-status', '-battery', '-xon', '-xoff', '-xstandby', - '-xsuspend', '-xinit', '-xreset', '-xstat'] + '-xsuspend', '-xinit', '-xreset', '-xstat', '-wifi'] if '-f' in sys.argv: sysvals.cgskip = sysvals.configFile('cgskip.txt') # loop through the command line arguments @@ -5930,6 +6364,10 @@ if __name__ == '__main__': sysvals.postdelay = getArgInt('-postdelay', args, 0, 60000) elif(arg == '-f'): sysvals.usecallgraph = True + elif(arg == '-ftop'): + sysvals.usecallgraph = True + sysvals.ftop = True + sysvals.usekprobes = False elif(arg == '-skiphtml'): sysvals.skiphtml = True elif(arg == '-cgdump'): @@ -5940,10 +6378,16 @@ if __name__ == '__main__': genhtml = True elif(arg == '-addlogs'): sysvals.dmesglog = sysvals.ftracelog = True + elif(arg == '-nologs'): + sysvals.dmesglog = sysvals.ftracelog = False elif(arg == '-addlogdmesg'): sysvals.dmesglog = True elif(arg == '-addlogftrace'): sysvals.ftracelog = True + elif(arg == '-turbostat'): + sysvals.tstat = True + if not sysvals.haveTurbostat(): + doError('Turbostat command not found') elif(arg == '-verbose'): sysvals.verbose = True elif(arg == '-proc'): @@ -6013,6 +6457,12 @@ if __name__ == '__main__': except: doError('No callgraph functions supplied', True) sysvals.setCallgraphFilter(val) + elif(arg == '-skipkprobe'): + try: + val = args.next() + except: + doError('No kprobe functions supplied', True) + sysvals.skipKprobes(val) elif(arg == '-cgskip'): try: val = args.next() @@ -6151,7 +6601,7 @@ if __name__ == '__main__': elif(cmd == 'devinfo'): deviceInfo() elif(cmd == 'modes'): - print getModes() + pprint(getModes()) elif(cmd == 'flist'): sysvals.getFtraceFilterFunctions(True) elif(cmd == 'flistall'): @@ -6163,11 +6613,18 @@ if __name__ == '__main__': ret = displayControl(cmd[1:]) elif(cmd == 'xstat'): pprint('Display Status: %s' % displayControl('stat').upper()) + elif(cmd == 'wifi'): + out = sysvals.checkWifi() + if 'device' not in out: + pprint('WIFI interface not found') + else: + for key in sorted(out): + pprint('%6s: %s' % (key.upper(), out[key])) sys.exit(ret) # if instructed, re-analyze existing data files if(sysvals.notestrun): - stamp = rerunTest() + stamp = rerunTest(sysvals.outdir) sysvals.outputResult(stamp) sys.exit(0) @@ -6204,7 +6661,7 @@ if __name__ == '__main__': s = 'suspend-x%d' % sysvals.multitest['count'] sysvals.outdir = datetime.now().strftime(s+'-%y%m%d-%H%M%S') if not os.path.isdir(sysvals.outdir): - os.mkdir(sysvals.outdir) + os.makedirs(sysvals.outdir) for i in range(sysvals.multitest['count']): if(i != 0): pprint('Waiting %d seconds...' % (sysvals.multitest['delay'])) diff --git a/tools/testing/radix-tree/linux/rcupdate.h b/tools/testing/radix-tree/linux/rcupdate.h index fd280b070fdb..fed468fb0c78 100644 --- a/tools/testing/radix-tree/linux/rcupdate.h +++ b/tools/testing/radix-tree/linux/rcupdate.h @@ -7,6 +7,6 @@ #define rcu_dereference_raw(p) rcu_dereference(p) #define rcu_dereference_protected(p, cond) rcu_dereference(p) #define rcu_dereference_check(p, cond) rcu_dereference(p) -#define RCU_INIT_POINTER(p, v) (p) = (v) +#define RCU_INIT_POINTER(p, v) do { (p) = (v); } while (0) #endif diff --git a/tools/testing/selftests/kvm/x86_64/evmcs_test.c b/tools/testing/selftests/kvm/x86_64/evmcs_test.c index b38260e29775..241919ef1eac 100644 --- a/tools/testing/selftests/kvm/x86_64/evmcs_test.c +++ b/tools/testing/selftests/kvm/x86_64/evmcs_test.c @@ -146,6 +146,7 @@ int main(int argc, char *argv[]) kvm_vm_restart(vm, O_RDWR); vm_vcpu_add(vm, VCPU_ID, 0, 0); vcpu_set_cpuid(vm, VCPU_ID, kvm_get_supported_cpuid()); + vcpu_ioctl(vm, VCPU_ID, KVM_ENABLE_CAP, &enable_evmcs_cap); vcpu_load_state(vm, VCPU_ID, state); run = vcpu_state(vm, VCPU_ID); free(state); diff --git a/tools/testing/selftests/rcutorture/Makefile b/tools/testing/selftests/rcutorture/Makefile new file mode 100644 index 000000000000..5202dc666206 --- /dev/null +++ b/tools/testing/selftests/rcutorture/Makefile @@ -0,0 +1,3 @@ +# SPDX-License-Identifier: GPL-2.0+ +all: + ( cd ../../../..; tools/testing/selftests/rcutorture/bin/kvm.sh --duration 10 --configs TREE01 ) diff --git a/tools/testing/selftests/rcutorture/bin/configinit.sh b/tools/testing/selftests/rcutorture/bin/configinit.sh index 40359486b3a8..93e80a42249a 100755 --- a/tools/testing/selftests/rcutorture/bin/configinit.sh +++ b/tools/testing/selftests/rcutorture/bin/configinit.sh @@ -1,7 +1,7 @@ #!/bin/bash # SPDX-License-Identifier: GPL-2.0+ # -# Usage: configinit.sh config-spec-file build-output-dir results-dir +# Usage: configinit.sh config-spec-file results-dir # # Create a .config file from the spec file. Run from the kernel source tree. # Exits with 0 if all went well, with 1 if all went well but the config @@ -11,10 +11,6 @@ # desired settings, for example, "CONFIG_NO_HZ=y". For best results, # this should be a full pathname. # -# The second argument is a optional path to a build output directory, -# for example, "O=/tmp/foo". If this argument is omitted, the .config -# file will be generated directly in the current directory. -# # Copyright (C) IBM Corporation, 2013 # # Authors: Paul E. McKenney <paulmck@linux.ibm.com> @@ -26,34 +22,23 @@ mkdir $T # Capture config spec file. c=$1 -buildloc=$2 -resdir=$3 -builddir= -if echo $buildloc | grep -q '^O=' -then - builddir=`echo $buildloc | sed -e 's/^O=//'` - if test ! -d $builddir - then - mkdir $builddir - fi -else - echo Bad build directory: \"$buildloc\" - exit 2 -fi +resdir=$2 sed -e 's/^\(CONFIG[0-9A-Z_]*\)=.*$/grep -v "^# \1" |/' < $c > $T/u.sh sed -e 's/^\(CONFIG[0-9A-Z_]*=\).*$/grep -v \1 |/' < $c >> $T/u.sh grep '^grep' < $T/u.sh > $T/upd.sh echo "cat - $c" >> $T/upd.sh -make mrproper -make $buildloc distclean > $resdir/Make.distclean 2>&1 -make $buildloc $TORTURE_DEFCONFIG > $resdir/Make.defconfig.out 2>&1 -mv $builddir/.config $builddir/.config.sav -sh $T/upd.sh < $builddir/.config.sav > $builddir/.config -cp $builddir/.config $builddir/.config.new -yes '' | make $buildloc oldconfig > $resdir/Make.oldconfig.out 2> $resdir/Make.oldconfig.err +if test -z "$TORTURE_TRUST_MAKE" +then + make clean > $resdir/Make.clean 2>&1 +fi +make $TORTURE_DEFCONFIG > $resdir/Make.defconfig.out 2>&1 +mv .config .config.sav +sh $T/upd.sh < .config.sav > .config +cp .config .config.new +yes '' | make oldconfig > $resdir/Make.oldconfig.out 2> $resdir/Make.oldconfig.err # verify new config matches specification. -configcheck.sh $builddir/.config $c +configcheck.sh .config $c exit 0 diff --git a/tools/testing/selftests/rcutorture/bin/cpus2use.sh b/tools/testing/selftests/rcutorture/bin/cpus2use.sh index ff7102212703..4e9485590c10 100755 --- a/tools/testing/selftests/rcutorture/bin/cpus2use.sh +++ b/tools/testing/selftests/rcutorture/bin/cpus2use.sh @@ -9,6 +9,11 @@ # # Authors: Paul E. McKenney <paulmck@linux.ibm.com> +if test -n "$TORTURE_ALLOTED_CPUS" +then + echo $TORTURE_ALLOTED_CPUS + exit 0 +fi ncpus=`grep '^processor' /proc/cpuinfo | wc -l` idlecpus=`mpstat | tail -1 | \ awk -v ncpus=$ncpus '{ print ncpus * ($7 + $NF) / 100 }'` diff --git a/tools/testing/selftests/rcutorture/bin/functions.sh b/tools/testing/selftests/rcutorture/bin/functions.sh index 6bcb8b5b2ff2..c3a49fb4d6f6 100644 --- a/tools/testing/selftests/rcutorture/bin/functions.sh +++ b/tools/testing/selftests/rcutorture/bin/functions.sh @@ -172,7 +172,7 @@ identify_qemu_append () { local console=ttyS0 case "$1" in qemu-system-x86_64|qemu-system-i386) - echo noapic selinux=0 initcall_debug debug + echo selinux=0 initcall_debug debug ;; qemu-system-aarch64) console=ttyAMA0 @@ -191,8 +191,19 @@ identify_qemu_append () { # Output arguments for qemu arguments based on the TORTURE_QEMU_MAC # and TORTURE_QEMU_INTERACTIVE environment variables. identify_qemu_args () { + local KVM_CPU="" + case "$1" in + qemu-system-x86_64) + KVM_CPU=kvm64 + ;; + qemu-system-i386) + KVM_CPU=kvm32 + ;; + esac case "$1" in qemu-system-x86_64|qemu-system-i386) + echo -machine q35,accel=kvm + echo -cpu ${KVM_CPU} ;; qemu-system-aarch64) echo -machine virt,gic-version=host -cpu host diff --git a/tools/testing/selftests/rcutorture/bin/jitter.sh b/tools/testing/selftests/rcutorture/bin/jitter.sh index 435b60933985..dc49a3ba6111 100755 --- a/tools/testing/selftests/rcutorture/bin/jitter.sh +++ b/tools/testing/selftests/rcutorture/bin/jitter.sh @@ -34,10 +34,15 @@ do exit 0; fi - # Set affinity to randomly selected CPU - cpus=`ls /sys/devices/system/cpu/*/online | - sed -e 's,/[^/]*$,,' -e 's/^[^0-9]*//' | - grep -v '^0*$'` + # Set affinity to randomly selected online CPU + cpus=`grep 1 /sys/devices/system/cpu/*/online | + sed -e 's,/[^/]*$,,' -e 's/^[^0-9]*//'` + + # Do not leave out poor old cpu0 which may not be hot-pluggable + if [ ! -f "/sys/devices/system/cpu/cpu0/online" ]; then + cpus="0 $cpus" + fi + cpumask=`awk -v cpus="$cpus" -v me=$me -v n=$n 'BEGIN { srand(n + me + systime()); ncpus = split(cpus, ca); diff --git a/tools/testing/selftests/rcutorture/bin/kvm-build.sh b/tools/testing/selftests/rcutorture/bin/kvm-build.sh index c27a0bbb9c02..18d6518504ee 100755 --- a/tools/testing/selftests/rcutorture/bin/kvm-build.sh +++ b/tools/testing/selftests/rcutorture/bin/kvm-build.sh @@ -3,7 +3,7 @@ # # Build a kvm-ready Linux kernel from the tree in the current directory. # -# Usage: kvm-build.sh config-template build-dir resdir +# Usage: kvm-build.sh config-template resdir # # Copyright (C) IBM Corporation, 2011 # @@ -15,8 +15,7 @@ then echo "kvm-build.sh :$config_template: Not a readable file" exit 1 fi -builddir=${2} -resdir=${3} +resdir=${2} T=${TMPDIR-/tmp}/test-linux.sh.$$ trap 'rm -rf $T' 0 @@ -29,14 +28,14 @@ CONFIG_VIRTIO_PCI=y CONFIG_VIRTIO_CONSOLE=y ___EOF___ -configinit.sh $T/config O=$builddir $resdir +configinit.sh $T/config $resdir retval=$? if test $retval -gt 1 then exit 2 fi ncpus=`cpus2use.sh` -make O=$builddir -j$ncpus $TORTURE_KMAKE_ARG > $resdir/Make.out 2>&1 +make -j$ncpus $TORTURE_KMAKE_ARG > $resdir/Make.out 2>&1 retval=$? if test $retval -ne 0 || grep "rcu[^/]*": < $resdir/Make.out | egrep -q "Stop|Error|error:|warning:" || egrep -q "Stop|Error|error:" < $resdir/Make.out then diff --git a/tools/testing/selftests/rcutorture/bin/kvm-find-errors.sh b/tools/testing/selftests/rcutorture/bin/kvm-find-errors.sh index 8426fe1f15ee..1871d00bccd7 100755 --- a/tools/testing/selftests/rcutorture/bin/kvm-find-errors.sh +++ b/tools/testing/selftests/rcutorture/bin/kvm-find-errors.sh @@ -11,6 +11,7 @@ # # The "directory" above should end with the date/time directory, for example, # "tools/testing/selftests/rcutorture/res/2018.02.25-14:27:27". +# Returns error status reflecting the success (or not) of the specified run. # # Copyright (C) IBM Corporation, 2018 # @@ -56,6 +57,8 @@ done if test -n "$files" then $editor $files + exit 1 else echo No errors in console logs. + exit 0 fi diff --git a/tools/testing/selftests/rcutorture/bin/kvm-recheck.sh b/tools/testing/selftests/rcutorture/bin/kvm-recheck.sh index 2adde6aaafdb..e5edd5198725 100755 --- a/tools/testing/selftests/rcutorture/bin/kvm-recheck.sh +++ b/tools/testing/selftests/rcutorture/bin/kvm-recheck.sh @@ -7,6 +7,8 @@ # # Usage: kvm-recheck.sh resdir ... # +# Returns status reflecting the success or not of the last run specified. +# # Copyright (C) IBM Corporation, 2011 # # Authors: Paul E. McKenney <paulmck@linux.ibm.com> @@ -28,8 +30,16 @@ do TORTURE_SUITE="`cat $i/../TORTURE_SUITE`" rm -f $i/console.log.*.diags kvm-recheck-${TORTURE_SUITE}.sh $i - if test -f "$i/console.log" + if test -f "$i/qemu-retval" && test "`cat $i/qemu-retval`" -ne 0 && test "`cat $i/qemu-retval`" -ne 137 + then + echo QEMU error, output: + cat $i/qemu-output + elif test -f "$i/console.log" then + if test -f "$i/qemu-retval" && test "`cat $i/qemu-retval`" -eq 137 + then + echo QEMU killed + fi configcheck.sh $i/.config $i/ConfigFragment if test -r $i/Make.oldconfig.err then @@ -58,3 +68,4 @@ do fi done done +EDITOR=echo kvm-find-errors.sh "${@: -1}" > /dev/null 2>&1 diff --git a/tools/testing/selftests/rcutorture/bin/kvm-test-1-run.sh b/tools/testing/selftests/rcutorture/bin/kvm-test-1-run.sh index 0eb1ec16d78a..27b7b5693ede 100755 --- a/tools/testing/selftests/rcutorture/bin/kvm-test-1-run.sh +++ b/tools/testing/selftests/rcutorture/bin/kvm-test-1-run.sh @@ -36,11 +36,6 @@ config_template=${1} config_dir=`echo $config_template | sed -e 's,/[^/]*$,,'` title=`echo $config_template | sed -e 's/^.*\///'` builddir=${2} -if test -z "$builddir" -o ! -d "$builddir" -o ! -w "$builddir" -then - echo "kvm-test-1-run.sh :$builddir: Not a writable directory, cannot build into it" - exit 1 -fi resdir=${3} if test -z "$resdir" -o ! -d "$resdir" -o ! -w "$resdir" then @@ -85,18 +80,18 @@ then ln -s $base_resdir/.config $resdir # for kvm-recheck.sh # Arch-independent indicator touch $resdir/builtkernel -elif kvm-build.sh $T/Kc2 $builddir $resdir +elif kvm-build.sh $T/Kc2 $resdir then # Had to build a kernel for this test. - QEMU="`identify_qemu $builddir/vmlinux`" + QEMU="`identify_qemu vmlinux`" BOOT_IMAGE="`identify_boot_image $QEMU`" - cp $builddir/vmlinux $resdir - cp $builddir/.config $resdir - cp $builddir/Module.symvers $resdir > /dev/null || : - cp $builddir/System.map $resdir > /dev/null || : + cp vmlinux $resdir + cp .config $resdir + cp Module.symvers $resdir > /dev/null || : + cp System.map $resdir > /dev/null || : if test -n "$BOOT_IMAGE" then - cp $builddir/$BOOT_IMAGE $resdir + cp $BOOT_IMAGE $resdir KERNEL=$resdir/${BOOT_IMAGE##*/} # Arch-independent indicator touch $resdir/builtkernel @@ -107,7 +102,7 @@ then parse-build.sh $resdir/Make.out $title else # Build failed. - cp $builddir/.config $resdir || : + cp .config $resdir || : echo Build failed, not running KVM, see $resdir. if test -f $builddir.wait then @@ -165,7 +160,7 @@ then fi echo "NOTE: $QEMU either did not run or was interactive" > $resdir/console.log echo $QEMU $qemu_args -m $TORTURE_QEMU_MEM -kernel $KERNEL -append \"$qemu_append $boot_args\" > $resdir/qemu-cmd -( $QEMU $qemu_args -m $TORTURE_QEMU_MEM -kernel $KERNEL -append "$qemu_append $boot_args"& echo $! > $resdir/qemu_pid; wait `cat $resdir/qemu_pid`; echo $? > $resdir/qemu-retval ) & +( $QEMU $qemu_args -m $TORTURE_QEMU_MEM -kernel $KERNEL -append "$qemu_append $boot_args" > $resdir/qemu-output 2>&1 & echo $! > $resdir/qemu_pid; wait `cat $resdir/qemu_pid`; echo $? > $resdir/qemu-retval ) & commandcompleted=0 sleep 10 # Give qemu's pid a chance to reach the file if test -s "$resdir/qemu_pid" diff --git a/tools/testing/selftests/rcutorture/bin/kvm.sh b/tools/testing/selftests/rcutorture/bin/kvm.sh index 8f1e337b9b54..72518580df23 100755 --- a/tools/testing/selftests/rcutorture/bin/kvm.sh +++ b/tools/testing/selftests/rcutorture/bin/kvm.sh @@ -24,6 +24,7 @@ dur=$((30*60)) dryrun="" KVM="`pwd`/tools/testing/selftests/rcutorture"; export KVM PATH=${KVM}/bin:$PATH; export PATH +TORTURE_ALLOTED_CPUS="" TORTURE_DEFCONFIG=defconfig TORTURE_BOOT_IMAGE="" TORTURE_INITRD="$KVM/initrd"; export TORTURE_INITRD @@ -32,6 +33,7 @@ TORTURE_KMAKE_ARG="" TORTURE_QEMU_MEM=512 TORTURE_SHUTDOWN_GRACE=180 TORTURE_SUITE=rcu +TORTURE_TRUST_MAKE="" resdir="" configs="" cpus=0 @@ -62,6 +64,7 @@ usage () { echo " --qemu-cmd qemu-system-..." echo " --results absolute-pathname" echo " --torture rcu" + echo " --trust-make" exit 1 } @@ -89,6 +92,7 @@ do --cpus) checkarg --cpus "(number)" "$#" "$2" '^[0-9]*$' '^--' cpus=$2 + TORTURE_ALLOTED_CPUS="$2" shift ;; --datestamp) @@ -173,6 +177,9 @@ do jitter=0 fi ;; + --trust-make) + TORTURE_TRUST_MAKE="y" + ;; *) echo Unknown argument $1 usage @@ -285,6 +292,7 @@ cat << ___EOF___ > $T/script CONFIGFRAG="$CONFIGFRAG"; export CONFIGFRAG KVM="$KVM"; export KVM PATH="$PATH"; export PATH +TORTURE_ALLOTED_CPUS="$TORTURE_ALLOTED_CPUS"; export TORTURE_ALLOTED_CPUS TORTURE_BOOT_IMAGE="$TORTURE_BOOT_IMAGE"; export TORTURE_BOOT_IMAGE TORTURE_BUILDONLY="$TORTURE_BUILDONLY"; export TORTURE_BUILDONLY TORTURE_DEFCONFIG="$TORTURE_DEFCONFIG"; export TORTURE_DEFCONFIG @@ -297,6 +305,7 @@ TORTURE_QEMU_MAC="$TORTURE_QEMU_MAC"; export TORTURE_QEMU_MAC TORTURE_QEMU_MEM="$TORTURE_QEMU_MEM"; export TORTURE_QEMU_MEM TORTURE_SHUTDOWN_GRACE="$TORTURE_SHUTDOWN_GRACE"; export TORTURE_SHUTDOWN_GRACE TORTURE_SUITE="$TORTURE_SUITE"; export TORTURE_SUITE +TORTURE_TRUST_MAKE="$TORTURE_TRUST_MAKE"; export TORTURE_TRUST_MAKE if ! test -e $resdir then mkdir -p "$resdir" || : @@ -342,7 +351,7 @@ function dump(first, pastlast, batchnum) print "needqemurun=" jn=1 for (j = first; j < pastlast; j++) { - builddir=KVM "/b1" + builddir=KVM "/b" j - first + 1 cpusr[jn] = cpus[j]; if (cfrep[cf[j]] == "") { cfr[jn] = cf[j]; @@ -358,7 +367,6 @@ function dump(first, pastlast, batchnum) print "echo ", cfr[jn], cpusr[jn] ovf ": Starting build. `date` | tee -a " rd "log"; print "rm -f " builddir ".*"; print "touch " builddir ".wait"; - print "mkdir " builddir " > /dev/null 2>&1 || :"; print "mkdir " rd cfr[jn] " || :"; print "kvm-test-1-run.sh " CONFIGDIR cf[j], builddir, rd cfr[jn], dur " \"" TORTURE_QEMU_ARG "\" \"" TORTURE_BOOTARGS "\" > " rd cfr[jn] "/kvm-test-1-run.sh.out 2>&1 &" print "echo ", cfr[jn], cpusr[jn] ovf ": Waiting for build to complete. `date` | tee -a " rd "log"; @@ -464,3 +472,5 @@ else fi # Tracing: trace_event=rcu:rcu_grace_period,rcu:rcu_future_grace_period,rcu:rcu_grace_period_init,rcu:rcu_nocb_wake,rcu:rcu_preempt_task,rcu:rcu_unlock_preempted_task,rcu:rcu_quiescent_state_report,rcu:rcu_fqs,rcu:rcu_callback,rcu:rcu_kfree_callback,rcu:rcu_batch_start,rcu:rcu_invoke_callback,rcu:rcu_invoke_kfree_callback,rcu:rcu_batch_end,rcu:rcu_torture_read,rcu:rcu_barrier +# Function-graph tracing: ftrace=function_graph ftrace_graph_filter=sched_setaffinity,migration_cpu_stop +# Also --kconfig "CONFIG_FUNCTION_TRACER=y CONFIG_FUNCTION_GRAPH_TRACER=y" diff --git a/tools/testing/selftests/rcutorture/bin/parse-build.sh b/tools/testing/selftests/rcutorture/bin/parse-build.sh index 0701b3bf6ade..09155c15ea65 100755 --- a/tools/testing/selftests/rcutorture/bin/parse-build.sh +++ b/tools/testing/selftests/rcutorture/bin/parse-build.sh @@ -21,7 +21,7 @@ mkdir $T . functions.sh -if grep -q CC < $F +if grep -q CC < $F || test -n "$TORTURE_TRUST_MAKE" then : else diff --git a/tools/testing/selftests/rcutorture/bin/parse-console.sh b/tools/testing/selftests/rcutorture/bin/parse-console.sh index 4508373a922f..4bf62d7b1cbc 100755 --- a/tools/testing/selftests/rcutorture/bin/parse-console.sh +++ b/tools/testing/selftests/rcutorture/bin/parse-console.sh @@ -106,6 +106,7 @@ fi | tee -a $file.diags egrep 'Badness|WARNING:|Warn|BUG|===========|Call Trace:|Oops:|detected stalls on CPUs/tasks:|self-detected stall on CPU|Stall ended before state dump start|\?\?\? Writer stall state|rcu_.*kthread starved for' < $file | grep -v 'ODEBUG: ' | +grep -v 'This means that this is a DEBUG kernel and it is' | grep -v 'Warning: unable to open an initial console' > $T.diags if test -s $T.diags then diff --git a/tools/testing/selftests/rcutorture/configs/rcu/CFcommon b/tools/testing/selftests/rcutorture/configs/rcu/CFcommon index d2d2a86139db..e19a444a0684 100644 --- a/tools/testing/selftests/rcutorture/configs/rcu/CFcommon +++ b/tools/testing/selftests/rcutorture/configs/rcu/CFcommon @@ -1,2 +1,5 @@ CONFIG_RCU_TORTURE_TEST=y CONFIG_PRINTK_TIME=y +CONFIG_HYPERVISOR_GUEST=y +CONFIG_PARAVIRT=y +CONFIG_KVM_GUEST=y diff --git a/tools/testing/selftests/rcutorture/configs/rcu/TREE01.boot b/tools/testing/selftests/rcutorture/configs/rcu/TREE01.boot index ea47da95374b..d6da9a61d44a 100644 --- a/tools/testing/selftests/rcutorture/configs/rcu/TREE01.boot +++ b/tools/testing/selftests/rcutorture/configs/rcu/TREE01.boot @@ -3,3 +3,4 @@ rcutree.gp_preinit_delay=3 rcutree.gp_init_delay=3 rcutree.gp_cleanup_delay=3 rcu_nocbs=0 +rcutorture.fwd_progress=0 diff --git a/tools/testing/selftests/rcutorture/configs/rcu/TRIVIAL b/tools/testing/selftests/rcutorture/configs/rcu/TRIVIAL new file mode 100644 index 000000000000..4d8eb5bfb6f6 --- /dev/null +++ b/tools/testing/selftests/rcutorture/configs/rcu/TRIVIAL @@ -0,0 +1,14 @@ +CONFIG_SMP=y +CONFIG_NR_CPUS=8 +CONFIG_PREEMPT_NONE=y +CONFIG_PREEMPT_VOLUNTARY=n +CONFIG_PREEMPT=n +CONFIG_HZ_PERIODIC=n +CONFIG_NO_HZ_IDLE=y +CONFIG_NO_HZ_FULL=n +CONFIG_HOTPLUG_CPU=n +CONFIG_SUSPEND=n +CONFIG_HIBERNATION=n +CONFIG_DEBUG_LOCK_ALLOC=n +CONFIG_DEBUG_OBJECTS_RCU_HEAD=n +CONFIG_RCU_EXPERT=y diff --git a/tools/testing/selftests/rcutorture/configs/rcu/TRIVIAL.boot b/tools/testing/selftests/rcutorture/configs/rcu/TRIVIAL.boot new file mode 100644 index 000000000000..7017f5f5a55f --- /dev/null +++ b/tools/testing/selftests/rcutorture/configs/rcu/TRIVIAL.boot @@ -0,0 +1,3 @@ +rcutorture.torture_type=trivial +rcutorture.onoff_interval=0 +rcutorture.shuffle_interval=0 diff --git a/tools/testing/selftests/timers/freq-step.c b/tools/testing/selftests/timers/freq-step.c index 8cd10662ffba..4b76450d78d1 100644 --- a/tools/testing/selftests/timers/freq-step.c +++ b/tools/testing/selftests/timers/freq-step.c @@ -21,9 +21,9 @@ #define SAMPLE_READINGS 10 #define MEAN_SAMPLE_INTERVAL 0.1 #define STEP_INTERVAL 1.0 -#define MAX_PRECISION 100e-9 -#define MAX_FREQ_ERROR 10e-6 -#define MAX_STDDEV 1000e-9 +#define MAX_PRECISION 500e-9 +#define MAX_FREQ_ERROR 0.02e-6 +#define MAX_STDDEV 50e-9 #ifndef ADJ_SETOFFSET #define ADJ_SETOFFSET 0x0100 diff --git a/tools/testing/selftests/x86/Makefile b/tools/testing/selftests/x86/Makefile index 186520198de7..fa07d526fe39 100644 --- a/tools/testing/selftests/x86/Makefile +++ b/tools/testing/selftests/x86/Makefile @@ -12,8 +12,9 @@ CAN_BUILD_WITH_NOPIE := $(shell ./check_cc.sh $(CC) trivial_program.c -no-pie) TARGETS_C_BOTHBITS := single_step_syscall sysret_ss_attrs syscall_nt test_mremap_vdso \ check_initial_reg_state sigreturn iopl mpx-mini-test ioperm \ - protection_keys test_vdso test_vsyscall mov_ss_trap -TARGETS_C_32BIT_ONLY := entry_from_vm86 syscall_arg_fault test_syscall_vdso unwind_vdso \ + protection_keys test_vdso test_vsyscall mov_ss_trap \ + syscall_arg_fault +TARGETS_C_32BIT_ONLY := entry_from_vm86 test_syscall_vdso unwind_vdso \ test_FCMOV test_FCOMI test_FISTTP \ vdso_restorer TARGETS_C_64BIT_ONLY := fsgsbase sysret_rip diff --git a/tools/testing/selftests/x86/fsgsbase.c b/tools/testing/selftests/x86/fsgsbase.c index af85bd4752a5..5ab4c60c100e 100644 --- a/tools/testing/selftests/x86/fsgsbase.c +++ b/tools/testing/selftests/x86/fsgsbase.c @@ -23,6 +23,10 @@ #include <pthread.h> #include <asm/ldt.h> #include <sys/mman.h> +#include <stddef.h> +#include <sys/ptrace.h> +#include <sys/wait.h> +#include <setjmp.h> #ifndef __x86_64__ # error This test is 64-bit only @@ -31,6 +35,8 @@ static volatile sig_atomic_t want_segv; static volatile unsigned long segv_addr; +static unsigned short *shared_scratch; + static int nerrs; static void sethandler(int sig, void (*handler)(int, siginfo_t *, void *), @@ -71,6 +77,43 @@ static void sigsegv(int sig, siginfo_t *si, void *ctx_void) } +static jmp_buf jmpbuf; + +static void sigill(int sig, siginfo_t *si, void *ctx_void) +{ + siglongjmp(jmpbuf, 1); +} + +static bool have_fsgsbase; + +static inline unsigned long rdgsbase(void) +{ + unsigned long gsbase; + + asm volatile("rdgsbase %0" : "=r" (gsbase) :: "memory"); + + return gsbase; +} + +static inline unsigned long rdfsbase(void) +{ + unsigned long fsbase; + + asm volatile("rdfsbase %0" : "=r" (fsbase) :: "memory"); + + return fsbase; +} + +static inline void wrgsbase(unsigned long gsbase) +{ + asm volatile("wrgsbase %0" :: "r" (gsbase) : "memory"); +} + +static inline void wrfsbase(unsigned long fsbase) +{ + asm volatile("wrfsbase %0" :: "r" (fsbase) : "memory"); +} + enum which_base { FS, GS }; static unsigned long read_base(enum which_base which) @@ -199,16 +242,13 @@ static void do_remote_base() to_set, hard_zero ? " and clear gs" : "", sel); } -void do_unexpected_base(void) +static __thread int set_thread_area_entry_number = -1; + +static unsigned short load_gs(void) { /* - * The goal here is to try to arrange for GS == 0, GSBASE != - * 0, and for the the kernel the think that GSBASE == 0. - * - * To make the test as reliable as possible, this uses - * explicit descriptorss. (This is not the only way. This - * could use ARCH_SET_GS with a low, nonzero base, but the - * relevant side effect of ARCH_SET_GS could change.) + * Sets GS != 0 and GSBASE != 0 but arranges for the kernel to think + * that GSBASE == 0 (i.e. thread.gsbase == 0). */ /* Step 1: tell the kernel that we have GSBASE == 0. */ @@ -228,8 +268,9 @@ void do_unexpected_base(void) .useable = 0 }; if (syscall(SYS_modify_ldt, 1, &desc, sizeof(desc)) == 0) { - printf("\tother thread: using LDT slot 0\n"); + printf("\tusing LDT slot 0\n"); asm volatile ("mov %0, %%gs" : : "rm" ((unsigned short)0x7)); + return 0x7; } else { /* No modify_ldt for us (configured out, perhaps) */ @@ -239,7 +280,7 @@ void do_unexpected_base(void) MAP_PRIVATE | MAP_ANONYMOUS | MAP_32BIT, -1, 0); memcpy(low_desc, &desc, sizeof(desc)); - low_desc->entry_number = -1; + low_desc->entry_number = set_thread_area_entry_number; /* 32-bit set_thread_area */ long ret; @@ -251,18 +292,43 @@ void do_unexpected_base(void) if (ret != 0) { printf("[NOTE]\tcould not create a segment -- test won't do anything\n"); - return; + return 0; } - printf("\tother thread: using GDT slot %d\n", desc.entry_number); - asm volatile ("mov %0, %%gs" : : "rm" ((unsigned short)((desc.entry_number << 3) | 0x3))); + printf("\tusing GDT slot %d\n", desc.entry_number); + set_thread_area_entry_number = desc.entry_number; + + unsigned short gs = (unsigned short)((desc.entry_number << 3) | 0x3); + asm volatile ("mov %0, %%gs" : : "rm" (gs)); + return gs; } +} - /* - * Step 3: set the selector back to zero. On AMD chips, this will - * preserve GSBASE. - */ +void test_wrbase(unsigned short index, unsigned long base) +{ + unsigned short newindex; + unsigned long newbase; - asm volatile ("mov %0, %%gs" : : "rm" ((unsigned short)0)); + printf("[RUN]\tGS = 0x%hx, GSBASE = 0x%lx\n", index, base); + + asm volatile ("mov %0, %%gs" : : "rm" (index)); + wrgsbase(base); + + remote_base = 0; + ftx = 1; + syscall(SYS_futex, &ftx, FUTEX_WAKE, 0, NULL, NULL, 0); + while (ftx != 0) + syscall(SYS_futex, &ftx, FUTEX_WAIT, 1, NULL, NULL, 0); + + asm volatile ("mov %%gs, %0" : "=rm" (newindex)); + newbase = rdgsbase(); + + if (newindex == index && newbase == base) { + printf("[OK]\tIndex and base were preserved\n"); + } else { + printf("[FAIL]\tAfter switch, GS = 0x%hx and GSBASE = 0x%lx\n", + newindex, newbase); + nerrs++; + } } static void *threadproc(void *ctx) @@ -273,12 +339,19 @@ static void *threadproc(void *ctx) if (ftx == 3) return NULL; - if (ftx == 1) + if (ftx == 1) { do_remote_base(); - else if (ftx == 2) - do_unexpected_base(); - else + } else if (ftx == 2) { + /* + * On AMD chips, this causes GSBASE != 0, GS == 0, and + * thread.gsbase == 0. + */ + + load_gs(); + asm volatile ("mov %0, %%gs" : : "rm" ((unsigned short)0)); + } else { errx(1, "helper thread got bad command"); + } ftx = 0; syscall(SYS_futex, &ftx, FUTEX_WAKE, 0, NULL, NULL, 0); @@ -367,10 +440,99 @@ static void test_unexpected_base(void) } } +#define USER_REGS_OFFSET(r) offsetof(struct user_regs_struct, r) + +static void test_ptrace_write_gsbase(void) +{ + int status; + pid_t child = fork(); + + if (child < 0) + err(1, "fork"); + + if (child == 0) { + printf("[RUN]\tPTRACE_POKE(), write GSBASE from ptracer\n"); + + *shared_scratch = load_gs(); + + if (ptrace(PTRACE_TRACEME, 0, NULL, NULL) != 0) + err(1, "PTRACE_TRACEME"); + + raise(SIGTRAP); + _exit(0); + } + + wait(&status); + + if (WSTOPSIG(status) == SIGTRAP) { + unsigned long gs, base; + unsigned long gs_offset = USER_REGS_OFFSET(gs); + unsigned long base_offset = USER_REGS_OFFSET(gs_base); + + gs = ptrace(PTRACE_PEEKUSER, child, gs_offset, NULL); + + if (gs != *shared_scratch) { + nerrs++; + printf("[FAIL]\tGS is not prepared with nonzero\n"); + goto END; + } + + if (ptrace(PTRACE_POKEUSER, child, base_offset, 0xFF) != 0) + err(1, "PTRACE_POKEUSER"); + + gs = ptrace(PTRACE_PEEKUSER, child, gs_offset, NULL); + base = ptrace(PTRACE_PEEKUSER, child, base_offset, NULL); + + /* + * In a non-FSGSBASE system, the nonzero selector will load + * GSBASE (again). But what is tested here is whether the + * selector value is changed or not by the GSBASE write in + * a ptracer. + */ + if (gs != *shared_scratch) { + nerrs++; + printf("[FAIL]\tGS changed to %lx\n", gs); + + /* + * On older kernels, poking a nonzero value into the + * base would zero the selector. On newer kernels, + * this behavior has changed -- poking the base + * changes only the base and, if FSGSBASE is not + * available, this may have no effect. + */ + if (gs == 0) + printf("\tNote: this is expected behavior on older kernels.\n"); + } else if (have_fsgsbase && (base != 0xFF)) { + nerrs++; + printf("[FAIL]\tGSBASE changed to %lx\n", base); + } else { + printf("[OK]\tGS remained 0x%hx%s", *shared_scratch, have_fsgsbase ? " and GSBASE changed to 0xFF" : ""); + printf("\n"); + } + } + +END: + ptrace(PTRACE_CONT, child, NULL, NULL); +} + int main() { pthread_t thread; + shared_scratch = mmap(NULL, 4096, PROT_READ | PROT_WRITE, + MAP_ANONYMOUS | MAP_SHARED, -1, 0); + + /* Probe FSGSBASE */ + sethandler(SIGILL, sigill, 0); + if (sigsetjmp(jmpbuf, 1) == 0) { + rdfsbase(); + have_fsgsbase = true; + printf("\tFSGSBASE instructions are enabled\n"); + } else { + printf("\tFSGSBASE instructions are disabled\n"); + } + clearhandler(SIGILL); + sethandler(SIGSEGV, sigsegv, 0); check_gs_value(0); @@ -417,11 +579,28 @@ int main() test_unexpected_base(); + if (have_fsgsbase) { + unsigned short ss; + + asm volatile ("mov %%ss, %0" : "=rm" (ss)); + + test_wrbase(0, 0); + test_wrbase(0, 1); + test_wrbase(0, 0x200000000); + test_wrbase(0, 0xffffffffffffffff); + test_wrbase(ss, 0); + test_wrbase(ss, 1); + test_wrbase(ss, 0x200000000); + test_wrbase(ss, 0xffffffffffffffff); + } + ftx = 3; /* Kill the thread. */ syscall(SYS_futex, &ftx, FUTEX_WAKE, 0, NULL, NULL, 0); if (pthread_join(thread, NULL) != 0) err(1, "pthread_join"); + test_ptrace_write_gsbase(); + return nerrs == 0 ? 0 : 1; } diff --git a/tools/testing/selftests/x86/syscall_arg_fault.c b/tools/testing/selftests/x86/syscall_arg_fault.c index 4e25d38c8bbd..bc0ecc2e862e 100644 --- a/tools/testing/selftests/x86/syscall_arg_fault.c +++ b/tools/testing/selftests/x86/syscall_arg_fault.c @@ -15,9 +15,30 @@ #include <setjmp.h> #include <errno.h> +#ifdef __x86_64__ +# define WIDTH "q" +#else +# define WIDTH "l" +#endif + /* Our sigaltstack scratch space. */ static unsigned char altstack_data[SIGSTKSZ]; +static unsigned long get_eflags(void) +{ + unsigned long eflags; + asm volatile ("pushf" WIDTH "\n\tpop" WIDTH " %0" : "=rm" (eflags)); + return eflags; +} + +static void set_eflags(unsigned long eflags) +{ + asm volatile ("push" WIDTH " %0\n\tpopf" WIDTH + : : "rm" (eflags) : "flags"); +} + +#define X86_EFLAGS_TF (1UL << 8) + static void sethandler(int sig, void (*handler)(int, siginfo_t *, void *), int flags) { @@ -35,13 +56,22 @@ static sigjmp_buf jmpbuf; static volatile sig_atomic_t n_errs; +#ifdef __x86_64__ +#define REG_AX REG_RAX +#define REG_IP REG_RIP +#else +#define REG_AX REG_EAX +#define REG_IP REG_EIP +#endif + static void sigsegv_or_sigbus(int sig, siginfo_t *info, void *ctx_void) { ucontext_t *ctx = (ucontext_t*)ctx_void; + long ax = (long)ctx->uc_mcontext.gregs[REG_AX]; - if (ctx->uc_mcontext.gregs[REG_EAX] != -EFAULT) { - printf("[FAIL]\tAX had the wrong value: 0x%x\n", - ctx->uc_mcontext.gregs[REG_EAX]); + if (ax != -EFAULT && ax != -ENOSYS) { + printf("[FAIL]\tAX had the wrong value: 0x%lx\n", + (unsigned long)ax); n_errs++; } else { printf("[OK]\tSeems okay\n"); @@ -50,9 +80,42 @@ static void sigsegv_or_sigbus(int sig, siginfo_t *info, void *ctx_void) siglongjmp(jmpbuf, 1); } +static volatile sig_atomic_t sigtrap_consecutive_syscalls; + +static void sigtrap(int sig, siginfo_t *info, void *ctx_void) +{ + /* + * KVM has some bugs that can cause us to stop making progress. + * detect them and complain, but don't infinite loop or fail the + * test. + */ + + ucontext_t *ctx = (ucontext_t*)ctx_void; + unsigned short *ip = (unsigned short *)ctx->uc_mcontext.gregs[REG_IP]; + + if (*ip == 0x340f || *ip == 0x050f) { + /* The trap was on SYSCALL or SYSENTER */ + sigtrap_consecutive_syscalls++; + if (sigtrap_consecutive_syscalls > 3) { + printf("[WARN]\tGot stuck single-stepping -- you probably have a KVM bug\n"); + siglongjmp(jmpbuf, 1); + } + } else { + sigtrap_consecutive_syscalls = 0; + } +} + static void sigill(int sig, siginfo_t *info, void *ctx_void) { - printf("[SKIP]\tIllegal instruction\n"); + ucontext_t *ctx = (ucontext_t*)ctx_void; + unsigned short *ip = (unsigned short *)ctx->uc_mcontext.gregs[REG_IP]; + + if (*ip == 0x0b0f) { + /* one of the ud2 instructions faulted */ + printf("[OK]\tSYSCALL returned normally\n"); + } else { + printf("[SKIP]\tIllegal instruction\n"); + } siglongjmp(jmpbuf, 1); } @@ -120,9 +183,48 @@ int main() "movl $-1, %%ebp\n\t" "movl $-1, %%esp\n\t" "syscall\n\t" - "pushl $0" /* make sure we segfault cleanly */ + "ud2" /* make sure we recover cleanly */ + : : : "memory", "flags"); + } + + printf("[RUN]\tSYSENTER with TF and invalid state\n"); + sethandler(SIGTRAP, sigtrap, SA_ONSTACK); + + if (sigsetjmp(jmpbuf, 1) == 0) { + sigtrap_consecutive_syscalls = 0; + set_eflags(get_eflags() | X86_EFLAGS_TF); + asm volatile ( + "movl $-1, %%eax\n\t" + "movl $-1, %%ebx\n\t" + "movl $-1, %%ecx\n\t" + "movl $-1, %%edx\n\t" + "movl $-1, %%esi\n\t" + "movl $-1, %%edi\n\t" + "movl $-1, %%ebp\n\t" + "movl $-1, %%esp\n\t" + "sysenter" + : : : "memory", "flags"); + } + set_eflags(get_eflags() & ~X86_EFLAGS_TF); + + printf("[RUN]\tSYSCALL with TF and invalid state\n"); + if (sigsetjmp(jmpbuf, 1) == 0) { + sigtrap_consecutive_syscalls = 0; + set_eflags(get_eflags() | X86_EFLAGS_TF); + asm volatile ( + "movl $-1, %%eax\n\t" + "movl $-1, %%ebx\n\t" + "movl $-1, %%ecx\n\t" + "movl $-1, %%edx\n\t" + "movl $-1, %%esi\n\t" + "movl $-1, %%edi\n\t" + "movl $-1, %%ebp\n\t" + "movl $-1, %%esp\n\t" + "syscall\n\t" + "ud2" /* make sure we recover cleanly */ : : : "memory", "flags"); } + set_eflags(get_eflags() & ~X86_EFLAGS_TF); return 0; } diff --git a/tools/testing/selftests/x86/test_vsyscall.c b/tools/testing/selftests/x86/test_vsyscall.c index 0b4f1cc2291c..4602326b8f5b 100644 --- a/tools/testing/selftests/x86/test_vsyscall.c +++ b/tools/testing/selftests/x86/test_vsyscall.c @@ -18,6 +18,7 @@ #include <sched.h> #include <stdbool.h> #include <setjmp.h> +#include <sys/uio.h> #ifdef __x86_64__ # define VSYS(x) (x) @@ -49,21 +50,21 @@ static void sethandler(int sig, void (*handler)(int, siginfo_t *, void *), } /* vsyscalls and vDSO */ -bool should_read_vsyscall = false; +bool vsyscall_map_r = false, vsyscall_map_x = false; typedef long (*gtod_t)(struct timeval *tv, struct timezone *tz); -gtod_t vgtod = (gtod_t)VSYS(0xffffffffff600000); +const gtod_t vgtod = (gtod_t)VSYS(0xffffffffff600000); gtod_t vdso_gtod; typedef int (*vgettime_t)(clockid_t, struct timespec *); vgettime_t vdso_gettime; typedef long (*time_func_t)(time_t *t); -time_func_t vtime = (time_func_t)VSYS(0xffffffffff600400); +const time_func_t vtime = (time_func_t)VSYS(0xffffffffff600400); time_func_t vdso_time; typedef long (*getcpu_t)(unsigned *, unsigned *, void *); -getcpu_t vgetcpu = (getcpu_t)VSYS(0xffffffffff600800); +const getcpu_t vgetcpu = (getcpu_t)VSYS(0xffffffffff600800); getcpu_t vdso_getcpu; static void init_vdso(void) @@ -107,7 +108,7 @@ static int init_vsys(void) maps = fopen("/proc/self/maps", "r"); if (!maps) { printf("[WARN]\tCould not open /proc/self/maps -- assuming vsyscall is r-x\n"); - should_read_vsyscall = true; + vsyscall_map_r = true; return 0; } @@ -133,12 +134,8 @@ static int init_vsys(void) } printf("\tvsyscall permissions are %c-%c\n", r, x); - should_read_vsyscall = (r == 'r'); - if (x != 'x') { - vgtod = NULL; - vtime = NULL; - vgetcpu = NULL; - } + vsyscall_map_r = (r == 'r'); + vsyscall_map_x = (x == 'x'); found = true; break; @@ -148,10 +145,8 @@ static int init_vsys(void) if (!found) { printf("\tno vsyscall map in /proc/self/maps\n"); - should_read_vsyscall = false; - vgtod = NULL; - vtime = NULL; - vgetcpu = NULL; + vsyscall_map_r = false; + vsyscall_map_x = false; } return nerrs; @@ -183,9 +178,13 @@ static inline long sys_getcpu(unsigned * cpu, unsigned * node, } static jmp_buf jmpbuf; +static volatile unsigned long segv_err; static void sigsegv(int sig, siginfo_t *info, void *ctx_void) { + ucontext_t *ctx = (ucontext_t *)ctx_void; + + segv_err = ctx->uc_mcontext.gregs[REG_ERR]; siglongjmp(jmpbuf, 1); } @@ -238,7 +237,7 @@ static int test_gtod(void) err(1, "syscall gettimeofday"); if (vdso_gtod) ret_vdso = vdso_gtod(&tv_vdso, &tz_vdso); - if (vgtod) + if (vsyscall_map_x) ret_vsys = vgtod(&tv_vsys, &tz_vsys); if (sys_gtod(&tv_sys2, &tz_sys) != 0) err(1, "syscall gettimeofday"); @@ -252,7 +251,7 @@ static int test_gtod(void) } } - if (vgtod) { + if (vsyscall_map_x) { if (ret_vsys == 0) { nerrs += check_gtod(&tv_sys1, &tv_sys2, &tz_sys, "vsyscall", &tv_vsys, &tz_vsys); } else { @@ -273,7 +272,7 @@ static int test_time(void) { t_sys1 = sys_time(&t2_sys1); if (vdso_time) t_vdso = vdso_time(&t2_vdso); - if (vtime) + if (vsyscall_map_x) t_vsys = vtime(&t2_vsys); t_sys2 = sys_time(&t2_sys2); if (t_sys1 < 0 || t_sys1 != t2_sys1 || t_sys2 < 0 || t_sys2 != t2_sys2) { @@ -294,7 +293,7 @@ static int test_time(void) { } } - if (vtime) { + if (vsyscall_map_x) { if (t_vsys < 0 || t_vsys != t2_vsys) { printf("[FAIL]\tvsyscall failed (ret:%ld output:%ld)\n", t_vsys, t2_vsys); nerrs++; @@ -330,7 +329,7 @@ static int test_getcpu(int cpu) ret_sys = sys_getcpu(&cpu_sys, &node_sys, 0); if (vdso_getcpu) ret_vdso = vdso_getcpu(&cpu_vdso, &node_vdso, 0); - if (vgetcpu) + if (vsyscall_map_x) ret_vsys = vgetcpu(&cpu_vsys, &node_vsys, 0); if (ret_sys == 0) { @@ -369,7 +368,7 @@ static int test_getcpu(int cpu) } } - if (vgetcpu) { + if (vsyscall_map_x) { if (ret_vsys) { printf("[FAIL]\tvsyscall getcpu() failed\n"); nerrs++; @@ -410,20 +409,88 @@ static int test_vsys_r(void) can_read = false; } - if (can_read && !should_read_vsyscall) { + if (can_read && !vsyscall_map_r) { printf("[FAIL]\tWe have read access, but we shouldn't\n"); return 1; - } else if (!can_read && should_read_vsyscall) { + } else if (!can_read && vsyscall_map_r) { printf("[FAIL]\tWe don't have read access, but we should\n"); return 1; + } else if (can_read) { + printf("[OK]\tWe have read access\n"); } else { - printf("[OK]\tgot expected result\n"); + printf("[OK]\tWe do not have read access: #PF(0x%lx)\n", + segv_err); } #endif return 0; } +static int test_vsys_x(void) +{ +#ifdef __x86_64__ + if (vsyscall_map_x) { + /* We already tested this adequately. */ + return 0; + } + + printf("[RUN]\tMake sure that vsyscalls really page fault\n"); + + bool can_exec; + if (sigsetjmp(jmpbuf, 1) == 0) { + vgtod(NULL, NULL); + can_exec = true; + } else { + can_exec = false; + } + + if (can_exec) { + printf("[FAIL]\tExecuting the vsyscall did not page fault\n"); + return 1; + } else if (segv_err & (1 << 4)) { /* INSTR */ + printf("[OK]\tExecuting the vsyscall page failed: #PF(0x%lx)\n", + segv_err); + } else { + printf("[FAILT]\tExecution failed with the wrong error: #PF(0x%lx)\n", + segv_err); + return 1; + } +#endif + + return 0; +} + +static int test_process_vm_readv(void) +{ +#ifdef __x86_64__ + char buf[4096]; + struct iovec local, remote; + int ret; + + printf("[RUN]\tprocess_vm_readv() from vsyscall page\n"); + + local.iov_base = buf; + local.iov_len = 4096; + remote.iov_base = (void *)0xffffffffff600000; + remote.iov_len = 4096; + ret = process_vm_readv(getpid(), &local, 1, &remote, 1, 0); + if (ret != 4096) { + printf("[OK]\tprocess_vm_readv() failed (ret = %d, errno = %d)\n", ret, errno); + return 0; + } + + if (vsyscall_map_r) { + if (!memcmp(buf, (const void *)0xffffffffff600000, 4096)) { + printf("[OK]\tIt worked and read correct data\n"); + } else { + printf("[FAIL]\tIt worked but returned incorrect data\n"); + return 1; + } + } +#endif + + return 0; +} #ifdef __x86_64__ #define X86_EFLAGS_TF (1UL << 8) @@ -455,7 +522,7 @@ static int test_emulation(void) time_t tmp; bool is_native; - if (!vtime) + if (!vsyscall_map_x) return 0; printf("[RUN]\tchecking that vsyscalls are emulated\n"); @@ -497,6 +564,9 @@ int main(int argc, char **argv) sethandler(SIGSEGV, sigsegv, 0); nerrs += test_vsys_r(); + nerrs += test_vsys_x(); + + nerrs += test_process_vm_readv(); #ifdef __x86_64__ nerrs += test_emulation(); |