* [RFC 0/2] CPU-Idle latency selftest framework
@ 2021-03-15 11:48 Pratik Rajesh Sampat
2021-03-15 11:48 ` [RFC 1/2] cpuidle: Extract IPI based and timer based wakeup latency from idle states Pratik Rajesh Sampat
2021-03-15 11:48 ` [RFC 2/2] selftest/cpuidle: Add support for cpuidle latency measurement Pratik Rajesh Sampat
0 siblings, 2 replies; 7+ messages in thread
From: Pratik Rajesh Sampat @ 2021-03-15 11:48 UTC (permalink / raw)
To: rjw, daniel.lezcano, shuah, ego, svaidy, linux-pm, linux-kernel,
linux-kselftest, pratik.r.sampat, psampat
A kernel module + userspace driver to estimate the wakeup latency
caused by going into stop states. The motivation behind this program is
to find significant deviations behind advertised latency and residency
values.
The patchset measures latencies for two kinds of events. IPIs and Timers
As this is a software-only mechanism, there will additional latencies of
the kernel-firmware-hardware interactions. To account for that, the
program also measures a baseline latency on a 100 percent loaded CPU
and the latencies achieved must be in view relative to that.
To achieve this, we introduce a kernel module and expose its control
knobs through the debugfs interface that the selftests can engage with.
The kernel module provides the following interfaces within
/sys/kernel/debug/latency_test/ for,
IPI test:
ipi_cpu_dest = Destination CPU for the IPI
ipi_cpu_src = Origin of the IPI
ipi_latency_ns = Measured latency time in ns
Timeout test:
timeout_cpu_src = CPU on which the timer to be queued
timeout_expected_ns = Timer duration
timeout_diff_ns = Difference of actual duration vs expected timer
Sample output on a POWER9 system is as follows:
# --IPI Latency Test---
# Baseline Average IPI latency(ns): 3114
# Observed Average IPI latency(ns) - State0: 3265
# Observed Average IPI latency(ns) - State1: 3507
# Observed Average IPI latency(ns) - State2: 3739
# Observed Average IPI latency(ns) - State3: 3807
# Observed Average IPI latency(ns) - State4: 17070
# Observed Average IPI latency(ns) - State5: 1038174
# Observed Average IPI latency(ns) - State6: 1068784
#
# --Timeout Latency Test--
# Baseline Average timeout diff(ns): 1420
# Observed Average timeout diff(ns) - State0: 1640
# Observed Average timeout diff(ns) - State1: 1764
# Observed Average timeout diff(ns) - State2: 1715
# Observed Average timeout diff(ns) - State3: 1845
# Observed Average timeout diff(ns) - State4: 16581
# Observed Average timeout diff(ns) - State5: 939977
# Observed Average timeout diff(ns) - State6: 1073024
Things to keep in mind:
1. This kernel module + bash driver does not guarantee idleness on a
core when the IPI and the Timer is armed. It only invokes sleep and
hopes that the core is idle once the IPI/Timer is invoked onto it.
Hence this program must be run on a completely idle system for best
results
2. Even on a completely idle system, there maybe book-keeping tasks or
jitter tasks that can run on the core we want idle. This can create
outliers in the latency measurement. Thankfully, these outliers
should be large enough to easily weed them out.
3. A userspace only selftest variant was also sent out as RFC based on
suggestions over the previous patchset to simply the kernel
complexeity. However, a userspace only approach had more noise in
the latency measurement due to userspace-kernel interactions
which led to run to run variance and a lesser accurate test.
Another downside of the nature of a userspace program is that it
takes orders of magnitude longer to complete a full system test
compared to the kernel framework.
RFC patch: https://lkml.org/lkml/2020/9/2/356
4. For Intel Systems, the Timer based latencies don't exactly give out
the measure of idle latencies. This is because of a hardware
optimization mechanism that pre-arms a CPU when a timer is set to
wakeup. That doesn't make this metric useless for Intel systems,
it just means that is measuring IPI/Timer responding latency rather
than idle wakeup latencies.
(Source: https://lkml.org/lkml/2020/9/2/610)
For solution to this problem, a hardware based latency analyzer is
devised by Artem Bityutskiy from Intel.
https://youtu.be/Opk92aQyvt0?t=8266
https://intel.github.io/wult/
Pratik Rajesh Sampat (2):
cpuidle: Extract IPI based and timer based wakeup latency from idle
states
selftest/cpuidle: Add support for cpuidle latency measurement
drivers/cpuidle/Makefile | 1 +
drivers/cpuidle/test-cpuidle_latency.c | 157 ++++++++++
lib/Kconfig.debug | 10 +
tools/testing/selftests/Makefile | 1 +
tools/testing/selftests/cpuidle/Makefile | 6 +
tools/testing/selftests/cpuidle/cpuidle.sh | 316 +++++++++++++++++++++
tools/testing/selftests/cpuidle/settings | 2 +
7 files changed, 493 insertions(+)
create mode 100644 drivers/cpuidle/test-cpuidle_latency.c
create mode 100644 tools/testing/selftests/cpuidle/Makefile
create mode 100755 tools/testing/selftests/cpuidle/cpuidle.sh
create mode 100644 tools/testing/selftests/cpuidle/settings
--
2.17.1
^ permalink raw reply [flat|nested] 7+ messages in thread
* [RFC 1/2] cpuidle: Extract IPI based and timer based wakeup latency from idle states
2021-03-15 11:48 [RFC 0/2] CPU-Idle latency selftest framework Pratik Rajesh Sampat
@ 2021-03-15 11:48 ` Pratik Rajesh Sampat
2021-03-15 11:48 ` [RFC 2/2] selftest/cpuidle: Add support for cpuidle latency measurement Pratik Rajesh Sampat
1 sibling, 0 replies; 7+ messages in thread
From: Pratik Rajesh Sampat @ 2021-03-15 11:48 UTC (permalink / raw)
To: rjw, daniel.lezcano, shuah, ego, svaidy, linux-pm, linux-kernel,
linux-kselftest, pratik.r.sampat, psampat
Introduce a mechanism to fire directed IPIs from a specified source CPU
to a specified target CPU and measure the difference in time incurred on
wakeup.
Also, introduce a mechanism to queue a HR timer on a specified CPU and
subsequently measure the time taken to wakeup the CPU.
Finally define a simple debugfs interface to control the knobs to fire
the IPI and Timer events on specified CPU and view their incurred idle
wakeup latencies.
Signed-off-by: Pratik Rajesh Sampat <psampat@linux.ibm.com>
---
drivers/cpuidle/Makefile | 1 +
drivers/cpuidle/test-cpuidle_latency.c | 157 +++++++++++++++++++++++++
lib/Kconfig.debug | 10 ++
3 files changed, 168 insertions(+)
create mode 100644 drivers/cpuidle/test-cpuidle_latency.c
diff --git a/drivers/cpuidle/Makefile b/drivers/cpuidle/Makefile
index 26bbc5e74123..3b4ee06a9164 100644
--- a/drivers/cpuidle/Makefile
+++ b/drivers/cpuidle/Makefile
@@ -8,6 +8,7 @@ obj-$(CONFIG_ARCH_NEEDS_CPU_IDLE_COUPLED) += coupled.o
obj-$(CONFIG_DT_IDLE_STATES) += dt_idle_states.o
obj-$(CONFIG_ARCH_HAS_CPU_RELAX) += poll_state.o
obj-$(CONFIG_HALTPOLL_CPUIDLE) += cpuidle-haltpoll.o
+obj-$(CONFIG_IDLE_LATENCY_SELFTEST) += test-cpuidle_latency.o
##################################################################################
# ARM SoC drivers
diff --git a/drivers/cpuidle/test-cpuidle_latency.c b/drivers/cpuidle/test-cpuidle_latency.c
new file mode 100644
index 000000000000..f138011ac225
--- /dev/null
+++ b/drivers/cpuidle/test-cpuidle_latency.c
@@ -0,0 +1,157 @@
+// SPDX-License-Identifier: GPL-2.0-or-later
+/*
+ * Module-based API test facility for cpuidle latency using IPIs and timers
+ */
+
+#include <linux/debugfs.h>
+#include <linux/kernel.h>
+#include <linux/module.h>
+
+/*
+ * IPI based wakeup latencies
+ * Measure time taken for a CPU to wakeup on a IPI sent from another CPU
+ * The latency measured also includes the latency of sending the IPI
+ */
+struct latency {
+ unsigned int src_cpu;
+ unsigned int dest_cpu;
+ ktime_t time_start;
+ ktime_t time_end;
+ u64 latency_ns;
+} ipi_wakeup;
+
+static void measure_latency(void *info)
+{
+ struct latency *v;
+ ktime_t time_diff;
+
+ v = (struct latency *)info;
+ v->time_end = ktime_get();
+ time_diff = ktime_sub(v->time_end, v->time_start);
+ v->latency_ns = ktime_to_ns(time_diff);
+}
+
+void run_smp_call_function_test(unsigned int cpu)
+{
+ ipi_wakeup.src_cpu = smp_processor_id();
+ ipi_wakeup.dest_cpu = cpu;
+ ipi_wakeup.time_start = ktime_get();
+ smp_call_function_single(cpu, measure_latency, &ipi_wakeup, 1);
+}
+
+/*
+ * Timer based wakeup latencies
+ * Measure time taken for a CPU to wakeup on a timer being armed and fired
+ */
+struct timer_data {
+ unsigned int src_cpu;
+ u64 timeout;
+ ktime_t time_start;
+ ktime_t time_end;
+ struct hrtimer timer;
+ u64 timeout_diff_ns;
+} timer_wakeup;
+
+static enum hrtimer_restart timer_called(struct hrtimer *hrtimer)
+{
+ struct timer_data *w;
+ ktime_t time_diff;
+
+ w = container_of(hrtimer, struct timer_data, timer);
+ w->time_end = ktime_get();
+
+ time_diff = ktime_sub(w->time_end, w->time_start);
+ time_diff = ktime_sub(time_diff, ns_to_ktime(w->timeout));
+ w->timeout_diff_ns = ktime_to_ns(time_diff);
+ return HRTIMER_NORESTART;
+}
+
+static void run_timer_test(unsigned int ns)
+{
+ hrtimer_init(&timer_wakeup.timer, CLOCK_MONOTONIC,
+ HRTIMER_MODE_REL);
+ timer_wakeup.timer.function = timer_called;
+ timer_wakeup.src_cpu = smp_processor_id();
+ timer_wakeup.timeout = ns;
+ timer_wakeup.time_start = ktime_get();
+
+ hrtimer_start(&timer_wakeup.timer, ns_to_ktime(ns),
+ HRTIMER_MODE_REL_PINNED);
+}
+
+static struct dentry *dir;
+
+static int cpu_read_op(void *data, u64 *dest_cpu)
+{
+ *dest_cpu = ipi_wakeup.dest_cpu;
+ return 0;
+}
+
+static int cpu_write_op(void *data, u64 value)
+{
+ run_smp_call_function_test(value);
+ return 0;
+}
+DEFINE_SIMPLE_ATTRIBUTE(ipi_ops, cpu_read_op, cpu_write_op, "%llu\n");
+
+static int timeout_read_op(void *data, u64 *timeout)
+{
+ *timeout = timer_wakeup.timeout;
+ return 0;
+}
+
+static int timeout_write_op(void *data, u64 value)
+{
+ run_timer_test(value);
+ return 0;
+}
+DEFINE_SIMPLE_ATTRIBUTE(timeout_ops, timeout_read_op, timeout_write_op, "%llu\n");
+
+static int __init latency_init(void)
+{
+ struct dentry *temp;
+
+ dir = debugfs_create_dir("latency_test", 0);
+ if (!dir) {
+ pr_alert("latency_test: failed to create /sys/kernel/debug/latency_test\n");
+ return -1;
+ }
+ temp = debugfs_create_file("ipi_cpu_dest",
+ 0666,
+ dir,
+ NULL,
+ &ipi_ops);
+ if (!temp) {
+ pr_alert("latency_test: failed to create /sys/kernel/debug/ipi_cpu_dest\n");
+ return -1;
+ }
+ debugfs_create_u64("ipi_latency_ns", 0444, dir, &ipi_wakeup.latency_ns);
+ debugfs_create_u32("ipi_cpu_src", 0444, dir, &ipi_wakeup.src_cpu);
+
+ temp = debugfs_create_file("timeout_expected_ns",
+ 0666,
+ dir,
+ NULL,
+ &timeout_ops);
+ if (!temp) {
+ pr_alert("latency_test: failed to create /sys/kernel/debug/timeout_expected_ns\n");
+ return -1;
+ }
+ debugfs_create_u64("timeout_diff_ns", 0444, dir, &timer_wakeup.timeout_diff_ns);
+ debugfs_create_u32("timeout_cpu_src", 0444, dir, &timer_wakeup.src_cpu);
+ pr_info("Latency Test module loaded\n");
+ return 0;
+}
+
+static void __exit latency_cleanup(void)
+{
+ pr_info("Cleaning up Latency Test module.\n");
+ debugfs_remove_recursive(dir);
+}
+
+module_init(latency_init);
+module_exit(latency_cleanup);
+
+MODULE_LICENSE("GPL");
+MODULE_AUTHOR("IBM Corporation");
+MODULE_DESCRIPTION("Measuring idle latency for IPIs and Timers");
diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 7937265ef879..3d6baea16913 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -1467,6 +1467,16 @@ config DEBUG_KOBJECT
If you say Y here, some extra kobject debugging messages will be sent
to the syslog.
+config IDLE_LATENCY_SELFTEST
+ tristate "Cpuidle latency selftests"
+ depends on CPU_IDLE
+ help
+ This option provides a kernel module that runs tests using the IPI and
+ timers to measure latency.
+
+ Say M if you want these self tests to build as a module.
+ Say N if you are unsure.
+
config DEBUG_KOBJECT_RELEASE
bool "kobject release debugging"
depends on DEBUG_OBJECTS_TIMERS
--
2.17.1
^ permalink raw reply related [flat|nested] 7+ messages in thread
* [RFC 2/2] selftest/cpuidle: Add support for cpuidle latency measurement
2021-03-15 11:48 [RFC 0/2] CPU-Idle latency selftest framework Pratik Rajesh Sampat
2021-03-15 11:48 ` [RFC 1/2] cpuidle: Extract IPI based and timer based wakeup latency from idle states Pratik Rajesh Sampat
@ 2021-03-15 11:48 ` Pratik Rajesh Sampat
2021-03-17 21:00 ` Doug Smythies
1 sibling, 1 reply; 7+ messages in thread
From: Pratik Rajesh Sampat @ 2021-03-15 11:48 UTC (permalink / raw)
To: rjw, daniel.lezcano, shuah, ego, svaidy, linux-pm, linux-kernel,
linux-kselftest, pratik.r.sampat, psampat
The cpuidle latency selftest provides support to systematically extract,
analyse and present IPI and timer based wakeup latencies for each CPU
and each idle state available on the system.
The selftest leverages test-cpuidle_latency module's debugfs interface
to interact and extract latency information from the kernel.
The selftest inserts the module if already not inserted, disables all
the idle states and enables them one by one testing the following:
1. Keeping source CPU constant, iterate through all the CPUS measuring
IPI latency for baseline (CPU is busy with cat /dev/random > /dev/null
workload) and then when the CPU is allowed to be at rest
2. Iterating through all the CPUs, sending expected timer durations to
be equivalent to the residency of the deepest idle state enabled
and extracting the difference in time between the time of wakeup and
the expected timer duration
To run this test specifically:
$ make -C tools/testing/selftests TARGETS="cpuidle" run_tests
There are a few optinal arguments too that the script can take
[-h <help>]
[-m <location of the module>]
[-o <location of the output>]
[-v <verbose> (run on all cpus)]
Default Output location in: tools/testing/cpuidle/cpuidle.log
Signed-off-by: Pratik Rajesh Sampat <psampat@linux.ibm.com>
---
tools/testing/selftests/Makefile | 1 +
tools/testing/selftests/cpuidle/Makefile | 6 +
tools/testing/selftests/cpuidle/cpuidle.sh | 316 +++++++++++++++++++++
tools/testing/selftests/cpuidle/settings | 2 +
4 files changed, 325 insertions(+)
create mode 100644 tools/testing/selftests/cpuidle/Makefile
create mode 100755 tools/testing/selftests/cpuidle/cpuidle.sh
create mode 100644 tools/testing/selftests/cpuidle/settings
diff --git a/tools/testing/selftests/Makefile b/tools/testing/selftests/Makefile
index 8a917cb4426a..8ac7a4fb86f9 100644
--- a/tools/testing/selftests/Makefile
+++ b/tools/testing/selftests/Makefile
@@ -7,6 +7,7 @@ TARGETS += cgroup
TARGETS += clone3
TARGETS += core
TARGETS += cpufreq
+TARGETS += cpuidle
TARGETS += cpu-hotplug
TARGETS += drivers/dma-buf
TARGETS += efivarfs
diff --git a/tools/testing/selftests/cpuidle/Makefile b/tools/testing/selftests/cpuidle/Makefile
new file mode 100644
index 000000000000..cbe13feced34
--- /dev/null
+++ b/tools/testing/selftests/cpuidle/Makefile
@@ -0,0 +1,6 @@
+# SPDX-License-Identifier: GPL-2.0
+all:
+
+TEST_PROGS := cpuidle.sh
+
+include ../lib.mk
\ No newline at end of file
diff --git a/tools/testing/selftests/cpuidle/cpuidle.sh b/tools/testing/selftests/cpuidle/cpuidle.sh
new file mode 100755
index 000000000000..de5141d5b76b
--- /dev/null
+++ b/tools/testing/selftests/cpuidle/cpuidle.sh
@@ -0,0 +1,316 @@
+#!/bin/bash
+# SPDX-License-Identifier: GPL-2.0
+
+LOG=cpuidle.log
+MODULE=/lib/modules/$(uname -r)/kernel/drivers/cpuidle/test-cpuidle_latency.ko
+
+# Kselftest framework requirement - SKIP code is 4.
+ksft_skip=4
+
+SMT=$(lscpu | grep "Thread(s) per core" | awk '{print $4}')
+
+helpme()
+{
+ printf "Usage: $0 [-h] [-todg args]
+ [-h <help>]
+ [-m <location of the module>]
+ [-o <location of the output>]
+ [-v <verbose>]
+ \n"
+ exit 2
+}
+
+parse_arguments()
+{
+ while getopts ht:m:o:vt: arg
+ do
+ case $arg in
+ h) # --help
+ helpme
+ ;;
+ m) # --mod-file
+ MODULE=$OPTARG
+ ;;
+ o) # output log files
+ LOG=$OPTARG
+ ;;
+ v) # Verbose mode
+ SMT=1
+ ;;
+ \?)
+ helpme
+ ;;
+ esac
+ done
+}
+
+ins_mod()
+{
+ debugfs_file=/sys/kernel/debug/latency_test/ipi_latency_ns
+ # Check if the module is already loaded
+ if [ -f "$debugfs_file" ]; then
+ printf "Module already loaded\n\n"
+ return 0
+ fi
+ # Try to load the module
+ if [ ! -f "$MODULE" ]; then
+ printf "$MODULE module does not exist. Exitting\n"
+ exit $ksft_skip
+ fi
+ printf "Inserting $MODULE module\n\n"
+ insmod $MODULE
+ if [ $? != 0 ]; then
+ printf "Insmod $MODULE failed\n"
+ exit $ksft_skip
+ fi
+}
+
+compute_average()
+{
+ arr=("$@")
+ sum=0
+ size=${#arr[@]}
+ if [ $size == 0 ]; then
+ avg=0
+ return 1
+ fi
+ for i in "${arr[@]}"
+ do
+ sum=$((sum + i))
+ done
+ avg=$((sum/size))
+}
+
+# Disable all stop states
+disable_idle()
+{
+ for ((cpu=0; cpu<NUM_CPUS; cpu++))
+ do
+ local cpu_status=$(cpu_is_online $cpu)
+ if [ $cpu_status == 0 ]; then
+ continue
+ fi
+ for ((state=0; state<NUM_STATES; state++))
+ do
+ echo 1 > /sys/devices/system/cpu/cpu$cpu/cpuidle/state$state/disable
+ done
+ done
+}
+
+# Perform operation on each CPU for the given state
+# $1 - Operation: enable (0) / disable (1)
+# $2 - State to enable
+op_state()
+{
+ for ((cpu=0; cpu<NUM_CPUS; cpu++))
+ do
+ local cpu_status=$(cpu_is_online $cpu)
+ if [ $cpu_status == 0 ]; then
+ continue
+ fi
+ echo $1 > /sys/devices/system/cpu/cpu$cpu/cpuidle/state$2/disable
+ done
+}
+
+cpuidle_enable_state()
+{
+ state=$1
+ op_state 0 $state
+}
+
+cpuidle_disable_state()
+{
+ state=$1
+ op_state 1 $state
+}
+
+cpu_is_online()
+{
+ cpu=$1
+ if [ ! -f "/sys/devices/system/cpu/cpu$cpu/online" ]; then
+ echo 0
+ return
+ fi
+ status=$(cat /sys/devices/system/cpu/cpu$cpu/online)
+ echo $status
+}
+
+# Extract latency in microseconds and convert to nanoseconds
+extract_latency()
+{
+ for ((state=0; state<NUM_STATES; state++))
+ do
+ latency=$(($(cat /sys/devices/system/cpu/cpu0/cpuidle/state$state/latency) * 1000))
+ latency_arr+=($latency)
+ done
+}
+
+# Run the IPI test
+# $1 run for baseline - busy cpu or regular environment
+# $2 destination cpu
+ipi_test_once()
+{
+ dest_cpu=$2
+ if [ "$1" = "baseline" ]; then
+ # Keep the CPU busy
+ taskset -c $dest_cpu cat /dev/random > /dev/null &
+ task_pid=$!
+ # Wait for the workload to achieve 100% CPU usage
+ sleep 1
+ fi
+ taskset 0x1 echo $dest_cpu > /sys/kernel/debug/latency_test/ipi_cpu_dest
+ ipi_latency=$(cat /sys/kernel/debug/latency_test/ipi_latency_ns)
+ src_cpu=$(cat /sys/kernel/debug/latency_test/ipi_cpu_src)
+ if [ "$1" = "baseline" ]; then
+ kill $task_pid
+ wait $task_pid 2>/dev/null
+ fi
+}
+
+# Incrementally Enable idle states one by one and compute the latency
+run_ipi_tests()
+{
+ extract_latency
+ disable_idle
+ declare -a avg_arr
+ echo -e "--IPI Latency Test---" | tee -a $LOG
+
+ echo -e "--Baseline IPI Latency measurement: CPU Busy--" >> $LOG
+ printf "%s %10s %12s\n" "SRC_CPU" "DEST_CPU" "IPI_Latency(ns)" >> $LOG
+ for ((cpu=0; cpu<NUM_CPUS; cpu+=SMT))
+ do
+ local cpu_status=$(cpu_is_online $cpu)
+ if [ $cpu_status == 0 ]; then
+ continue
+ fi
+ ipi_test_once "baseline" $cpu
+ printf "%-3s %10s %12s\n" $src_cpu $cpu $ipi_latency >> $LOG
+ avg_arr+=($ipi_latency)
+ done
+ compute_average "${avg_arr[@]}"
+ echo -e "Baseline Avg IPI latency(ns): $avg" | tee -a $LOG
+
+ for ((state=0; state<NUM_STATES; state++))
+ do
+ unset avg_arr
+ echo -e "---Enabling state: $state---" >> $LOG
+ cpuidle_enable_state $state
+ printf "%s %10s %12s\n" "SRC_CPU" "DEST_CPU" "IPI_Latency(ns)" >> $LOG
+ for ((cpu=0; cpu<NUM_CPUS; cpu+=SMT))
+ do
+ local cpu_status=$(cpu_is_online $cpu)
+ if [ $cpu_status == 0 ]; then
+ continue
+ fi
+ # Running IPI test and logging results
+ sleep 1
+ ipi_test_once "test" $cpu
+ printf "%-3s %10s %12s\n" $src_cpu $cpu $ipi_latency >> $LOG
+ avg_arr+=($ipi_latency)
+ done
+ compute_average "${avg_arr[@]}"
+ echo -e "Expected IPI latency(ns): ${latency_arr[$state]}" >> $LOG
+ echo -e "Observed Avg IPI latency(ns) - State $state: $avg" | tee -a $LOG
+ cpuidle_disable_state $state
+ done
+}
+
+# Extract the residency in microseconds and convert to nanoseconds.
+# Add 100 ns so that the timer stays for a little longer than the residency
+extract_residency()
+{
+ for ((state=0; state<NUM_STATES; state++))
+ do
+ residency=$(($(cat /sys/devices/system/cpu/cpu0/cpuidle/state$state/residency) * 1000 + 200))
+ residency_arr+=($residency)
+ done
+}
+
+# Run the Timeout test
+# $1 run for baseline - busy cpu or regular environment
+# $2 destination cpu
+# $3 timeout
+timeout_test_once()
+{
+ dest_cpu=$2
+ if [ "$1" = "baseline" ]; then
+ # Keep the CPU busy
+ taskset -c $dest_cpu cat /dev/random > /dev/null &
+ task_pid=$!
+ # Wait for the workload to achieve 100% CPU usage
+ sleep 1
+ fi
+ taskset -c $dest_cpu echo $3 > /sys/kernel/debug/latency_test/timeout_expected_ns
+ # Wait for the result to populate
+ sleep 0.1
+ timeout_diff=$(cat /sys/kernel/debug/latency_test/timeout_diff_ns)
+ src_cpu=$(cat /sys/kernel/debug/latency_test/timeout_cpu_src)
+ if [ "$1" = "baseline" ]; then
+ kill $task_pid
+ wait $task_pid 2>/dev/null
+ fi
+}
+
+run_timeout_tests()
+{
+ extract_residency
+ disable_idle
+ declare -a avg_arr
+ echo -e "\n--Timeout Latency Test--" | tee -a $LOG
+
+ echo -e "--Baseline Timeout Latency measurement: CPU Busy--" >> $LOG
+ printf "%s %10s %10s\n" "Wakeup_src" "Baseline_delay(ns)">> $LOG
+ for ((cpu=0; cpu<NUM_CPUS; cpu+=SMT))
+ do
+ local cpu_status=$(cpu_is_online $cpu)
+ if [ $cpu_status == 0 ]; then
+ continue
+ fi
+ timeout_test_once "baseline" $cpu 1000000
+ printf "%-3s %13s\n" $src_cpu $timeout_diff >> $LOG
+ avg_arr+=($timeout_diff)
+ done
+ compute_average "${avg_arr[@]}"
+ echo -e "Baseline Avg timeout diff(ns): $avg" | tee -a $LOG
+
+ for ((state=0; state<NUM_STATES; state++))
+ do
+ unset avg_arr
+ echo -e "---Enabling state: $state---" >> $LOG
+ cpuidle_enable_state $state
+ printf "%s %10s %10s\n" "Wakeup_src" "Baseline_delay(ns)" "Delay(ns)" >> $LOG
+ for ((cpu=0; cpu<NUM_CPUS; cpu+=SMT))
+ do
+ local cpu_status=$(cpu_is_online $cpu)
+ if [ $cpu_status == 0 ]; then
+ continue
+ fi
+ timeout_test_once "test" $cpu 1000000
+ printf "%-3s %13s %18s\n" $src_cpu $baseline_timeout_diff $timeout_diff >> $LOG
+ avg_arr+=($timeout_diff)
+ done
+ compute_average "${avg_arr[@]}"
+ echo -e "Expected timeout(ns): ${residency_arr[$state]}" >> $LOG
+ echo -e "Observed Avg timeout diff(ns) - State $state: $avg" | tee -a $LOG
+ cpuidle_disable_state $state
+ done
+}
+
+declare -a residency_arr
+declare -a latency_arr
+
+parse_arguments $@
+
+rm -f $LOG
+touch $LOG
+NUM_CPUS=$(nproc --all)
+NUM_STATES=$(ls -1 /sys/devices/system/cpu/cpu0/cpuidle/ | wc -l)
+
+ins_mod $MODULE
+
+run_ipi_tests
+run_timeout_tests
+
+printf "Removing $MODULE module\n"
+printf "Full Output logged at: $LOG\n"
+rmmod $MODULE
diff --git a/tools/testing/selftests/cpuidle/settings b/tools/testing/selftests/cpuidle/settings
new file mode 100644
index 000000000000..a26c38a70d77
--- /dev/null
+++ b/tools/testing/selftests/cpuidle/settings
@@ -0,0 +1,2 @@
+timeout=0
+
--
2.17.1
^ permalink raw reply related [flat|nested] 7+ messages in thread
* Re: [RFC 2/2] selftest/cpuidle: Add support for cpuidle latency measurement
2021-03-15 11:48 ` [RFC 2/2] selftest/cpuidle: Add support for cpuidle latency measurement Pratik Rajesh Sampat
@ 2021-03-17 21:00 ` Doug Smythies
2021-03-18 6:44 ` Pratik Sampat
0 siblings, 1 reply; 7+ messages in thread
From: Doug Smythies @ 2021-03-17 21:00 UTC (permalink / raw)
To: Pratik Rajesh Sampat
Cc: rjw, Daniel Lezcano, shuah, ego, svaidy, Linux PM list,
Linux Kernel Mailing List, linux-kselftest, pratik.r.sampat,
dsmythies
Hi Pratik,
It just so happens that I have been trying Artem's version this last
week, so I tried yours.
On Mon, Mar 15, 2021 at 4:49 AM Pratik Rajesh Sampat
<psampat@linux.ibm.com> wrote:
>
...
> To run this test specifically:
> $ make -C tools/testing/selftests TARGETS="cpuidle" run_tests
While I suppose it should have been obvious, I interpreted
the "$" sign to mean I could run as a regular user, which I can not.
> There are a few optinal arguments too that the script can take
> [-h <help>]
> [-m <location of the module>]
> [-o <location of the output>]
> [-v <verbose> (run on all cpus)]
> Default Output location in: tools/testing/cpuidle/cpuidle.log
Isn't it:
tools/testing/selftests/cpuidle/cpuidle.log
? At least, that is where my file was.
Other notes:
No idle state for CPU 0 ever gets disabled.
I assume this is because CPU 0 can never be offline,
so that bit of code (Disable all stop states) doesn't find its state.
By the way, processor = Intel i5-9600K
The system is left with all idle states disabled, well not for CPU 0
as per the above comment. The suggestion is to restore them,
otherwise my processor hogs 42 watts instead of 2.
My results are highly variable per test.
My system is very idle:
Example (from turbostat at 6 seconds sample rate):
Busy% Bzy_MHz IRQ PkgTmp PkgWatt RAMWatt
0.03 4600 153 28 2.03 1.89
0.01 4600 103 29 2.03 1.89
0.05 4600 115 29 2.08 1.89
0.01 4600 95 28 2.09 1.89
0.03 4600 114 28 2.11 1.89
0.01 4600 107 29 2.07 1.89
0.02 4600 102 29 2.11 1.89
...
... Doug
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [RFC 2/2] selftest/cpuidle: Add support for cpuidle latency measurement
2021-03-17 21:00 ` Doug Smythies
@ 2021-03-18 6:44 ` Pratik Sampat
2021-03-20 15:04 ` Doug Smythies
0 siblings, 1 reply; 7+ messages in thread
From: Pratik Sampat @ 2021-03-18 6:44 UTC (permalink / raw)
To: Doug Smythies
Cc: rjw, Daniel Lezcano, shuah, ego, svaidy, Linux PM list,
Linux Kernel Mailing List, linux-kselftest, pratik.r.sampat
Hi Doug,
Thanks for trying these patches out.
On 18/03/21 2:30 am, Doug Smythies wrote:
> Hi Pratik,
>
> It just so happens that I have been trying Artem's version this last
> week, so I tried yours.
>
> On Mon, Mar 15, 2021 at 4:49 AM Pratik Rajesh Sampat
> <psampat@linux.ibm.com> wrote:
> ...
>> To run this test specifically:
>> $ make -C tools/testing/selftests TARGETS="cpuidle" run_tests
> While I suppose it should have been obvious, I interpreted
> the "$" sign to mean I could run as a regular user, which I can not.
Ah yes, this does need root privileges, I should have prefixed the command with
sudo in the instructions for better understanding.
>> There are a few optinal arguments too that the script can take
>> [-h <help>]
>> [-m <location of the module>]
>> [-o <location of the output>]
>> [-v <verbose> (run on all cpus)]
>> Default Output location in: tools/testing/cpuidle/cpuidle.log
> Isn't it:
>
> tools/testing/selftests/cpuidle/cpuidle.log
My bad, It was a typing error. I missed the "selftest" directory while
typing it out.
> ? At least, that is where my file was.
>
> Other notes:
>
> No idle state for CPU 0 ever gets disabled.
> I assume this is because CPU 0 can never be offline,
> so that bit of code (Disable all stop states) doesn't find its state.
> By the way, processor = Intel i5-9600K
I had tried these patches on an IBM POWER 9 processor and disabling CPU0's idle
state works there. However, it does make sense for some processors to treat CPU
0 differently.
Maybe I could write in a case if idle state disabling fails for a CPU then we
just skip it?
> The system is left with all idle states disabled, well not for CPU 0
> as per the above comment. The suggestion is to restore them,
> otherwise my processor hogs 42 watts instead of 2.
>
> My results are highly variable per test.
Question: Do you notice high variability with IPI test, Timer test or both?
I can think of two reasons for high run to run variance:
1. If you observe variance in timer tests, then I believe there could a
mechanism of "C-state pre-wake" on some Intel machines at play here, which can
pre-wake a CPU from an idle state when timers are armed. I'm not sure if the
Intel platform that you're running on does that or not.
Artem had described this behavior to me a while ago and I think his wult page
describes this behavior in more detail:
https://intel.github.io/wult/#c-state-pre-wake
2. I have noticed variability in results when there are kernel book-keeping or
jitter tasks scheduled from time to time on an otherwise idle core.
In the full per-CPU logs at tools/testing/selftests/cpuidle/cpuidle.log can you
spot any obvious outliers per-CPU state?
Also you may want to run the test in verbose mode which runs for all the
threads of each CPU with the following: "sudo ./cpuidle.sh -v". While latency
mostly matters for per-core basis but it still maybe a good idea to see if
that changes anything with the observations.
--
Thanks and regards,
Pratik
> My system is very idle:
> Example (from turbostat at 6 seconds sample rate):
> Busy% Bzy_MHz IRQ PkgTmp PkgWatt RAMWatt
> 0.03 4600 153 28 2.03 1.89
> 0.01 4600 103 29 2.03 1.89
> 0.05 4600 115 29 2.08 1.89
> 0.01 4600 95 28 2.09 1.89
> 0.03 4600 114 28 2.11 1.89
> 0.01 4600 107 29 2.07 1.89
> 0.02 4600 102 29 2.11 1.89
>
> ...
>
> ... Doug
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [RFC 2/2] selftest/cpuidle: Add support for cpuidle latency measurement
2021-03-18 6:44 ` Pratik Sampat
@ 2021-03-20 15:04 ` Doug Smythies
2021-03-22 12:56 ` Pratik Sampat
0 siblings, 1 reply; 7+ messages in thread
From: Doug Smythies @ 2021-03-20 15:04 UTC (permalink / raw)
To: Pratik Sampat
Cc: rjw, Daniel Lezcano, shuah, ego, svaidy, Linux PM list,
Linux Kernel Mailing List, linux-kselftest, pratik.r.sampat,
dsmythies
On Wed, Mar 17, 2021 at 11:44 PM Pratik Sampat <psampat@linux.ibm.com> wrote:
>
> Hi Doug,
> Thanks for trying these patches out.
>
> On 18/03/21 2:30 am, Doug Smythies wrote:
> > Hi Pratik,
> >
> > It just so happens that I have been trying Artem's version this last
> > week, so I tried yours.
> >
> > On Mon, Mar 15, 2021 at 4:49 AM Pratik Rajesh Sampat
> > <psampat@linux.ibm.com> wrote:
> > ...
...
> > Other notes:
> >
> > No idle state for CPU 0 ever gets disabled.
> > I assume this is because CPU 0 can never be offline,
> > so that bit of code (Disable all stop states) doesn't find its state.
> > By the way, processor = Intel i5-9600K
>
> I had tried these patches on an IBM POWER 9 processor and disabling CPU0's idle
> state works there. However, it does make sense for some processors to treat CPU
> 0 differently.
> Maybe I could write in a case if idle state disabling fails for a CPU then we
> just skip it?
I didn't try it, I just did a hack so I could continue for this reply.
> > The system is left with all idle states disabled, well not for CPU 0
> > as per the above comment. The suggestion is to restore them,
> > otherwise my processor hogs 42 watts instead of 2.
> >
> > My results are highly variable per test.
>
> Question: Do you notice high variability with IPI test, Timer test or both?
The IPI test has less variability than the Timer test.
>
> I can think of two reasons for high run to run variance:
>
> 1. If you observe variance in timer tests, then I believe there could a
> mechanism of "C-state pre-wake" on some Intel machines at play here, which can
> pre-wake a CPU from an idle state when timers are armed. I'm not sure if the
> Intel platform that you're running on does that or not.
>
> Artem had described this behavior to me a while ago and I think his wult page
> describes this behavior in more detail:
> https://intel.github.io/wult/#c-state-pre-wake
Yes, I have reviewed all the references.
And yes, I think my processors have the pre-wake stuff.
I do not have the proper hardware to do the Artem pre-wake workaround
method, but might buy it in future.
> 2. I have noticed variability in results when there are kernel book-keeping or
> jitter tasks scheduled from time to time on an otherwise idle core.
> In the full per-CPU logs at tools/testing/selftests/cpuidle/cpuidle.log can you
> spot any obvious outliers per-CPU state?
Yes.
I'll just paste in an example cpuidle.log file having used the -v option
below, along with my hack job diff.
doug@s19:~/temp-k-git/linux/tools/testing/selftests/cpuidle$ cat
cpuidle.log.v3-1
--IPI Latency Test---
--Baseline IPI Latency measurement: CPU Busy--
SRC_CPU DEST_CPU IPI_Latency(ns)
0 0 140
0 1 632
0 2 675
0 3 671
0 4 675
0 5 767
0 6 653
0 7 826
0 8 819
0 9 615
0 10 758
0 11 758
Baseline Avg IPI latency(ns): 665
---Enabling state: 0---
SRC_CPU DEST_CPU IPI_Latency(ns)
0 0 76
0 1 484
0 2 494
0 3 539
0 4 498
0 5 491
0 6 474
0 7 434
0 8 544
0 9 476
0 10 447
0 11 467
Expected IPI latency(ns): 0
Observed Avg IPI latency(ns) - State 0: 452
---Enabling state: 1---
SRC_CPU DEST_CPU IPI_Latency(ns)
0 0 72
0 1 1081
0 2 821
0 3 1486
0 4 1022
0 5 960
0 6 1634
0 7 933
0 8 1032
0 9 1046
0 10 1430
0 11 1338
Expected IPI latency(ns): 1000
Observed Avg IPI latency(ns) - State 1: 1071
---Enabling state: 2---
SRC_CPU DEST_CPU IPI_Latency(ns)
0 0 264
0 1 30836
0 2 30562
0 3 30748
0 4 35286
0 5 30978
0 6 1952
0 7 36066
0 8 30670
0 9 30605
0 10 30635
0 11 35423
Expected IPI latency(ns): 120000
Observed Avg IPI latency(ns) - State 2: 27002
---Enabling state: 3---
SRC_CPU DEST_CPU IPI_Latency(ns)
0 0 71
0 1 30853
0 2 32095
0 3 32661
0 4 30230
0 5 34348
0 6 2012
0 7 30816
0 8 30908
0 9 31130
0 10 34150
0 11 32050
Expected IPI latency(ns): 1034000
Observed Avg IPI latency(ns) - State 3: 26777
--Timeout Latency Test--
--Baseline Timeout Latency measurement: CPU Busy--
Wakeup_src Baseline_delay(ns)
0 453
1 568
2 387
3 337
4 433
5 579
6 330
7 400
8 561
9 544
10 569
11 523
Baseline Avg timeout diff(ns): 473
---Enabling state: 0---
Wakeup_src Baseline_delay(ns) Delay(ns)
0 399
1 388
2 352
3 385
4 334
5 415
6 320
7 356
8 401
9 379
10 339
11 384
Expected timeout(ns): 200
Observed Avg timeout diff(ns) - State 0: 371
---Enabling state: 1---
Wakeup_src Baseline_delay(ns) Delay(ns)
0 666
1 575
2 608
3 590
4 608
5 552
6 582
7 593
8 597
9 587
10 588
11 610
Expected timeout(ns): 1200
Observed Avg timeout diff(ns) - State 1: 596
---Enabling state: 2---
Wakeup_src Baseline_delay(ns) Delay(ns)
0 36386
1 1069
2 866
3 884
4 850
5 55642
6 408082
7 1184
8 406075
9 406830
10 414105
11 406594
Expected timeout(ns): 360200
Observed Avg timeout diff(ns) - State 2: 178213
---Enabling state: 3---
Wakeup_src Baseline_delay(ns) Delay(ns)
0 406049
1 913
2 410134
3 921
4 406237
5 950
6 407181
7 920
8 407678
9 894
10 406320
11 304161
Expected timeout(ns): 3102200
Observed Avg timeout diff(ns) - State 3: 229363
My hack job, (CPUs always online):
diff --git a/tools/testing/selftests/cpuidle/cpuidle.sh
b/tools/testing/selftests/cpuidle/cpuidle.sh
index de5141d5b76b..70bdacda5e91 100755
--- a/tools/testing/selftests/cpuidle/cpuidle.sh
+++ b/tools/testing/selftests/cpuidle/cpuidle.sh
@@ -86,10 +86,6 @@ disable_idle()
{
for ((cpu=0; cpu<NUM_CPUS; cpu++))
do
- local cpu_status=$(cpu_is_online $cpu)
- if [ $cpu_status == 0 ]; then
- continue
- fi
for ((state=0; state<NUM_STATES; state++))
do
echo 1 >
/sys/devices/system/cpu/cpu$cpu/cpuidle/state$state/disable
@@ -104,10 +100,6 @@ op_state()
{
for ((cpu=0; cpu<NUM_CPUS; cpu++))
do
- local cpu_status=$(cpu_is_online $cpu)
- if [ $cpu_status == 0 ]; then
- continue
- fi
echo $1 >
/sys/devices/system/cpu/cpu$cpu/cpuidle/state$2/disable
done
}
@@ -124,17 +116,6 @@ cpuidle_disable_state()
op_state 1 $state
}
-cpu_is_online()
-{
- cpu=$1
- if [ ! -f "/sys/devices/system/cpu/cpu$cpu/online" ]; then
- echo 0
- return
- fi
- status=$(cat /sys/devices/system/cpu/cpu$cpu/online)
- echo $status
-}
-
# Extract latency in microseconds and convert to nanoseconds
extract_latency()
{
@@ -179,10 +160,6 @@ run_ipi_tests()
printf "%s %10s %12s\n" "SRC_CPU" "DEST_CPU" "IPI_Latency(ns)" >> $LOG
for ((cpu=0; cpu<NUM_CPUS; cpu+=SMT))
do
- local cpu_status=$(cpu_is_online $cpu)
- if [ $cpu_status == 0 ]; then
- continue
- fi
ipi_test_once "baseline" $cpu
printf "%-3s %10s %12s\n" $src_cpu $cpu $ipi_latency >> $LOG
avg_arr+=($ipi_latency)
@@ -198,10 +175,6 @@ run_ipi_tests()
printf "%s %10s %12s\n" "SRC_CPU" "DEST_CPU"
"IPI_Latency(ns)" >> $LOG
for ((cpu=0; cpu<NUM_CPUS; cpu+=SMT))
do
- local cpu_status=$(cpu_is_online $cpu)
- if [ $cpu_status == 0 ]; then
- continue
- fi
# Running IPI test and logging results
sleep 1
ipi_test_once "test" $cpu
@@ -262,10 +235,6 @@ run_timeout_tests()
printf "%s %10s %10s\n" "Wakeup_src" "Baseline_delay(ns)">> $LOG
for ((cpu=0; cpu<NUM_CPUS; cpu+=SMT))
do
- local cpu_status=$(cpu_is_online $cpu)
- if [ $cpu_status == 0 ]; then
- continue
- fi
timeout_test_once "baseline" $cpu 1000000
printf "%-3s %13s\n" $src_cpu $timeout_diff >> $LOG
avg_arr+=($timeout_diff)
@@ -281,10 +250,6 @@ run_timeout_tests()
printf "%s %10s %10s\n" "Wakeup_src"
"Baseline_delay(ns)" "Delay(ns)" >> $LOG
for ((cpu=0; cpu<NUM_CPUS; cpu+=SMT))
do
- local cpu_status=$(cpu_is_online $cpu)
- if [ $cpu_status == 0 ]; then
- continue
- fi
timeout_test_once "test" $cpu 1000000
printf "%-3s %13s %18s\n" $src_cpu
$baseline_timeout_diff $timeout_diff >> $LOG
avg_arr+=($timeout_diff)
@@ -314,3 +279,7 @@ run_timeout_tests
printf "Removing $MODULE module\n"
printf "Full Output logged at: $LOG\n"
rmmod $MODULE
+
+printf "enabling idle states\n"
+
+echo 0 | tee /sys/devices/system/cpu/cpu*/cpuidle/state*/disable
(END)
^ permalink raw reply related [flat|nested] 7+ messages in thread
* Re: [RFC 2/2] selftest/cpuidle: Add support for cpuidle latency measurement
2021-03-20 15:04 ` Doug Smythies
@ 2021-03-22 12:56 ` Pratik Sampat
0 siblings, 0 replies; 7+ messages in thread
From: Pratik Sampat @ 2021-03-22 12:56 UTC (permalink / raw)
To: Doug Smythies
Cc: rjw, Daniel Lezcano, shuah, ego, svaidy, Linux PM list,
Linux Kernel Mailing List, linux-kselftest, pratik.r.sampat
Hi Doug,
On 20/03/21 8:34 pm, Doug Smythies wrote:
> On Wed, Mar 17, 2021 at 11:44 PM Pratik Sampat <psampat@linux.ibm.com> wrote:
>> Hi Doug,
>> Thanks for trying these patches out.
>>
>> On 18/03/21 2:30 am, Doug Smythies wrote:
>>> Hi Pratik,
>>>
>>> It just so happens that I have been trying Artem's version this last
>>> week, so I tried yours.
>>>
>>> On Mon, Mar 15, 2021 at 4:49 AM Pratik Rajesh Sampat
>>> <psampat@linux.ibm.com> wrote:
>>> ...
> ...
>>> Other notes:
>>>
>>> No idle state for CPU 0 ever gets disabled.
>>> I assume this is because CPU 0 can never be offline,
>>> so that bit of code (Disable all stop states) doesn't find its state.
>>> By the way, processor = Intel i5-9600K
>> I had tried these patches on an IBM POWER 9 processor and disabling CPU0's idle
>> state works there. However, it does make sense for some processors to treat CPU
>> 0 differently.
>> Maybe I could write in a case if idle state disabling fails for a CPU then we
>> just skip it?
> I didn't try it, I just did a hack so I could continue for this reply.
Sure. In subsequent version I could write something to cleanly handle online
fail checks, maybe even specifically for CPU0.
>>> The system is left with all idle states disabled, well not for CPU 0
>>> as per the above comment. The suggestion is to restore them,
>>> otherwise my processor hogs 42 watts instead of 2.
>>>
>>> My results are highly variable per test.
>> Question: Do you notice high variability with IPI test, Timer test or both?
> The IPI test has less variability than the Timer test.
>
>> I can think of two reasons for high run to run variance:
>>
>> 1. If you observe variance in timer tests, then I believe there could a
>> mechanism of "C-state pre-wake" on some Intel machines at play here, which can
>> pre-wake a CPU from an idle state when timers are armed. I'm not sure if the
>> Intel platform that you're running on does that or not.
>>
>> Artem had described this behavior to me a while ago and I think his wult page
>> describes this behavior in more detail:
>> https://intel.github.io/wult/#c-state-pre-wake
> Yes, I have reviewed all the references.
> And yes, I think my processors have the pre-wake stuff.
>
> I do not have the proper hardware to do the Artem pre-wake workaround
> method, but might buy it in future.
That explains the variability that we are seeing in the Timer tests on the
Intel processor you've tried on.
Also based on the data pasted below, it means that the IPI tests are more
reliable than Timers.
Maybe it would be better to not run the Timer test on Intel platforms that
support this pre-wakeup feature?
However, I don't know how (or if) Intel exposes this information to the
userspace and if other platforms like AMD also have this feature in some form.
Another way of solving this problem could be to have the timer test as an
optional parameter in the selftest for people to use while also printing a
disclaimer for x86 users about the potential hardware design?
--
Thanks
Pratik
>> 2. I have noticed variability in results when there are kernel book-keeping or
>> jitter tasks scheduled from time to time on an otherwise idle core.
>> In the full per-CPU logs at tools/testing/selftests/cpuidle/cpuidle.log can you
>> spot any obvious outliers per-CPU state?
> Yes.
> I'll just paste in an example cpuidle.log file having used the -v option
> below, along with my hack job diff.
>
> doug@s19:~/temp-k-git/linux/tools/testing/selftests/cpuidle$ cat
> cpuidle.log.v3-1
> --IPI Latency Test---
> --Baseline IPI Latency measurement: CPU Busy--
> SRC_CPU DEST_CPU IPI_Latency(ns)
> 0 0 140
> 0 1 632
> 0 2 675
> 0 3 671
> 0 4 675
> 0 5 767
> 0 6 653
> 0 7 826
> 0 8 819
> 0 9 615
> 0 10 758
> 0 11 758
> Baseline Avg IPI latency(ns): 665
> ---Enabling state: 0---
> SRC_CPU DEST_CPU IPI_Latency(ns)
> 0 0 76
> 0 1 484
> 0 2 494
> 0 3 539
> 0 4 498
> 0 5 491
> 0 6 474
> 0 7 434
> 0 8 544
> 0 9 476
> 0 10 447
> 0 11 467
> Expected IPI latency(ns): 0
> Observed Avg IPI latency(ns) - State 0: 452
> ---Enabling state: 1---
> SRC_CPU DEST_CPU IPI_Latency(ns)
> 0 0 72
> 0 1 1081
> 0 2 821
> 0 3 1486
> 0 4 1022
> 0 5 960
> 0 6 1634
> 0 7 933
> 0 8 1032
> 0 9 1046
> 0 10 1430
> 0 11 1338
> Expected IPI latency(ns): 1000
> Observed Avg IPI latency(ns) - State 1: 1071
> ---Enabling state: 2---
> SRC_CPU DEST_CPU IPI_Latency(ns)
> 0 0 264
> 0 1 30836
> 0 2 30562
> 0 3 30748
> 0 4 35286
> 0 5 30978
> 0 6 1952
> 0 7 36066
> 0 8 30670
> 0 9 30605
> 0 10 30635
> 0 11 35423
> Expected IPI latency(ns): 120000
> Observed Avg IPI latency(ns) - State 2: 27002
> ---Enabling state: 3---
> SRC_CPU DEST_CPU IPI_Latency(ns)
> 0 0 71
> 0 1 30853
> 0 2 32095
> 0 3 32661
> 0 4 30230
> 0 5 34348
> 0 6 2012
> 0 7 30816
> 0 8 30908
> 0 9 31130
> 0 10 34150
> 0 11 32050
> Expected IPI latency(ns): 1034000
> Observed Avg IPI latency(ns) - State 3: 26777
>
> --Timeout Latency Test--
> --Baseline Timeout Latency measurement: CPU Busy--
> Wakeup_src Baseline_delay(ns)
> 0 453
> 1 568
> 2 387
> 3 337
> 4 433
> 5 579
> 6 330
> 7 400
> 8 561
> 9 544
> 10 569
> 11 523
> Baseline Avg timeout diff(ns): 473
> ---Enabling state: 0---
> Wakeup_src Baseline_delay(ns) Delay(ns)
> 0 399
> 1 388
> 2 352
> 3 385
> 4 334
> 5 415
> 6 320
> 7 356
> 8 401
> 9 379
> 10 339
> 11 384
> Expected timeout(ns): 200
> Observed Avg timeout diff(ns) - State 0: 371
> ---Enabling state: 1---
> Wakeup_src Baseline_delay(ns) Delay(ns)
> 0 666
> 1 575
> 2 608
> 3 590
> 4 608
> 5 552
> 6 582
> 7 593
> 8 597
> 9 587
> 10 588
> 11 610
> Expected timeout(ns): 1200
> Observed Avg timeout diff(ns) - State 1: 596
> ---Enabling state: 2---
> Wakeup_src Baseline_delay(ns) Delay(ns)
> 0 36386
> 1 1069
> 2 866
> 3 884
> 4 850
> 5 55642
> 6 408082
> 7 1184
> 8 406075
> 9 406830
> 10 414105
> 11 406594
> Expected timeout(ns): 360200
> Observed Avg timeout diff(ns) - State 2: 178213
> ---Enabling state: 3---
> Wakeup_src Baseline_delay(ns) Delay(ns)
> 0 406049
> 1 913
> 2 410134
> 3 921
> 4 406237
> 5 950
> 6 407181
> 7 920
> 8 407678
> 9 894
> 10 406320
> 11 304161
> Expected timeout(ns): 3102200
> Observed Avg timeout diff(ns) - State 3: 229363
>
>
> My hack job, (CPUs always online):
>
> diff --git a/tools/testing/selftests/cpuidle/cpuidle.sh
> b/tools/testing/selftests/cpuidle/cpuidle.sh
> index de5141d5b76b..70bdacda5e91 100755
> --- a/tools/testing/selftests/cpuidle/cpuidle.sh
> +++ b/tools/testing/selftests/cpuidle/cpuidle.sh
> @@ -86,10 +86,6 @@ disable_idle()
> {
> for ((cpu=0; cpu<NUM_CPUS; cpu++))
> do
> - local cpu_status=$(cpu_is_online $cpu)
> - if [ $cpu_status == 0 ]; then
> - continue
> - fi
> for ((state=0; state<NUM_STATES; state++))
> do
> echo 1 >
> /sys/devices/system/cpu/cpu$cpu/cpuidle/state$state/disable
> @@ -104,10 +100,6 @@ op_state()
> {
> for ((cpu=0; cpu<NUM_CPUS; cpu++))
> do
> - local cpu_status=$(cpu_is_online $cpu)
> - if [ $cpu_status == 0 ]; then
> - continue
> - fi
> echo $1 >
> /sys/devices/system/cpu/cpu$cpu/cpuidle/state$2/disable
> done
> }
> @@ -124,17 +116,6 @@ cpuidle_disable_state()
> op_state 1 $state
> }
>
> -cpu_is_online()
> -{
> - cpu=$1
> - if [ ! -f "/sys/devices/system/cpu/cpu$cpu/online" ]; then
> - echo 0
> - return
> - fi
> - status=$(cat /sys/devices/system/cpu/cpu$cpu/online)
> - echo $status
> -}
> -
> # Extract latency in microseconds and convert to nanoseconds
> extract_latency()
> {
> @@ -179,10 +160,6 @@ run_ipi_tests()
> printf "%s %10s %12s\n" "SRC_CPU" "DEST_CPU" "IPI_Latency(ns)" >> $LOG
> for ((cpu=0; cpu<NUM_CPUS; cpu+=SMT))
> do
> - local cpu_status=$(cpu_is_online $cpu)
> - if [ $cpu_status == 0 ]; then
> - continue
> - fi
> ipi_test_once "baseline" $cpu
> printf "%-3s %10s %12s\n" $src_cpu $cpu $ipi_latency >> $LOG
> avg_arr+=($ipi_latency)
> @@ -198,10 +175,6 @@ run_ipi_tests()
> printf "%s %10s %12s\n" "SRC_CPU" "DEST_CPU"
> "IPI_Latency(ns)" >> $LOG
> for ((cpu=0; cpu<NUM_CPUS; cpu+=SMT))
> do
> - local cpu_status=$(cpu_is_online $cpu)
> - if [ $cpu_status == 0 ]; then
> - continue
> - fi
> # Running IPI test and logging results
> sleep 1
> ipi_test_once "test" $cpu
> @@ -262,10 +235,6 @@ run_timeout_tests()
> printf "%s %10s %10s\n" "Wakeup_src" "Baseline_delay(ns)">> $LOG
> for ((cpu=0; cpu<NUM_CPUS; cpu+=SMT))
> do
> - local cpu_status=$(cpu_is_online $cpu)
> - if [ $cpu_status == 0 ]; then
> - continue
> - fi
> timeout_test_once "baseline" $cpu 1000000
> printf "%-3s %13s\n" $src_cpu $timeout_diff >> $LOG
> avg_arr+=($timeout_diff)
> @@ -281,10 +250,6 @@ run_timeout_tests()
> printf "%s %10s %10s\n" "Wakeup_src"
> "Baseline_delay(ns)" "Delay(ns)" >> $LOG
> for ((cpu=0; cpu<NUM_CPUS; cpu+=SMT))
> do
> - local cpu_status=$(cpu_is_online $cpu)
> - if [ $cpu_status == 0 ]; then
> - continue
> - fi
> timeout_test_once "test" $cpu 1000000
> printf "%-3s %13s %18s\n" $src_cpu
> $baseline_timeout_diff $timeout_diff >> $LOG
> avg_arr+=($timeout_diff)
> @@ -314,3 +279,7 @@ run_timeout_tests
> printf "Removing $MODULE module\n"
> printf "Full Output logged at: $LOG\n"
> rmmod $MODULE
> +
> +printf "enabling idle states\n"
> +
> +echo 0 | tee /sys/devices/system/cpu/cpu*/cpuidle/state*/disable
> (END)
^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2021-03-22 13:11 UTC | newest]
Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-03-15 11:48 [RFC 0/2] CPU-Idle latency selftest framework Pratik Rajesh Sampat
2021-03-15 11:48 ` [RFC 1/2] cpuidle: Extract IPI based and timer based wakeup latency from idle states Pratik Rajesh Sampat
2021-03-15 11:48 ` [RFC 2/2] selftest/cpuidle: Add support for cpuidle latency measurement Pratik Rajesh Sampat
2021-03-17 21:00 ` Doug Smythies
2021-03-18 6:44 ` Pratik Sampat
2021-03-20 15:04 ` Doug Smythies
2021-03-22 12:56 ` Pratik Sampat
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).