tools/power turbostat: Enhance turbostat self-performance visibility

Include procfs and sysfs data collection time in the system summary
row of the "usec" column. This is useful for isolating where the
time goes during turbostat data collection.

Background:

Column "usec" shows
1. the number of microseconds elapsed during counter collection,
including thread migration -- if any, for each CPU row.
2. total elapsed time to collect the counters on all cpus, for the
summary row.
This can be used to check the time cost of a give column. For example,
run below commands separately
turbostat --show usec sleep 1
turbostat --show usec,CoreTmp sleep 1
and the delta in the usec column will tell the time cost for CoreTmp
(Thermal MSR read)

Problem:

Some of the kernel procfs/sysfs accesses are expensive, especially on
high core count systems. "usec" column cannot tell this because it only
includes the time cost of the counters.

Solution:

Leave the per CPU "usec" as it is and modify the summary "usec" to
include the time cost of the procfs/sysfs snapshot.

With it, the "usec" column can be used to get
1. the baseline, e.g.
turbostat --show usec sleep 1
2. the baseline + some per CPU counter cost, e.g.
turbostat --show usec,CoreTmp sleep 1
3. the baseline + some per CPU sysfs cost, e.g.
turbostat --show usec,C1 sleep 1
4. the baseline + /proc/interrupts cost, e.g
turbostat --show usec,IRQ sleep 1

Man-page update is also included.

Signed-off-by: Zhang Rui <rui.zhang@intel.com>
Signed-off-by: Len Brown <len.brown@intel.com>

authored by Zhang Rui and committed by Len Brown 1af5baed debe797c

+7 -2
+1 -1
tools/power/x86/turbostat/turbostat.8
··· 136 136 The system configuration dump (if --quiet is not used) is followed by statistics. The first row of the statistics labels the content of each column (below). The second row of statistics is the system summary line. The system summary line has a '-' in the columns for the Package, Core, and CPU. The contents of the system summary line depends on the type of column. Columns that count items (eg. IRQ) show the sum across all CPUs in the system. Columns that show a percentage show the average across all CPUs in the system. Columns that dump raw MSR values simply show 0 in the summary. After the system summary row, each row describes a specific Package/Core/CPU. Note that if the --cpu parameter is used to limit which specific CPUs are displayed, turbostat will still collect statistics for all CPUs in the system and will still show the system summary for all CPUs in the system. 137 137 .SH COLUMN DESCRIPTIONS 138 138 .PP 139 - \fBusec\fP For each CPU, the number of microseconds elapsed during counter collection, including thread migration -- if any. This counter is disabled by default, and is enabled with "--enable usec", or --debug. On the summary row, usec refers to the total elapsed time to collect the counters on all cpus. 139 + \fBusec\fP For each CPU, the number of microseconds elapsed during counter collection, including thread migration -- if any. This counter is disabled by default, and is enabled with "--enable usec", or --debug. On the summary row, usec refers to the total elapsed time to snapshot the procfs/sysfs and collect the counters on all cpus. 140 140 .PP 141 141 \fBTime_Of_Day_Seconds\fP For each CPU, the gettimeofday(2) value (seconds.subsec since Epoch) when the counters ending the measurement interval were collected. This column is disabled by default, and can be enabled with "--enable Time_Of_Day_Seconds" or "--debug". On the summary row, Time_Of_Day_Seconds refers to the timestamp following collection of counters on the last CPU. 142 142 .PP
+6 -1
tools/power/x86/turbostat/turbostat.c
··· 370 370 unsigned int has_hwp_epp; /* IA32_HWP_REQUEST[bits 31:24] */ 371 371 unsigned int has_hwp_pkg; /* IA32_HWP_REQUEST_PKG */ 372 372 unsigned int first_counter_read = 1; 373 + 374 + static struct timeval procsysfs_tv_begin; 375 + 373 376 int ignore_stdin; 374 377 bool no_msr; 375 378 bool no_perf; ··· 3641 3638 3642 3639 /* remember first tv_begin */ 3643 3640 if (average.threads.tv_begin.tv_sec == 0) 3644 - average.threads.tv_begin = t->tv_begin; 3641 + average.threads.tv_begin = procsysfs_tv_begin; 3645 3642 3646 3643 /* remember last tv_end */ 3647 3644 average.threads.tv_end = t->tv_end; ··· 5986 5983 */ 5987 5984 int snapshot_proc_sysfs_files(void) 5988 5985 { 5986 + gettimeofday(&procsysfs_tv_begin, (struct timezone *)NULL); 5987 + 5989 5988 if (DO_BIC(BIC_IRQ) || DO_BIC(BIC_NMI)) 5990 5989 if (snapshot_proc_interrupts()) 5991 5990 return 1;