Add support in showbootdata for the new firmware time keyvals.
This adds a new -f/--firmware option for reporting the
power_on_to_* keyvals. These report timings of various firmware
phases during boot.
BUG=chromium-os:14925
TEST=use the new option on a recently generated results directory
Change-Id: I9a962db0696b4f767184d8bd8eede1af0a9a1274
Reviewed-on: http://gerrit.chromium.org/gerrit/3461
Reviewed-by: Mike Truty <truty@chromium.org>
Tested-by: Rajesh Chenna <rchenna@google.com>
Reviewed-by: Rajesh Chenna <rchenna@google.com>
diff --git a/bootperf-bin/perfprinter.py b/bootperf-bin/perfprinter.py
index 95ec4ac..d610714 100644
--- a/bootperf-bin/perfprinter.py
+++ b/bootperf-bin/perfprinter.py
@@ -9,15 +9,14 @@
import os.path
import re
+import resultset
-def PrintRawData(reader, dirlist, use_timestats, keylist):
+
+def PrintRawData(reader, dirlist, keytype, keylist):
"""Print 'bootperf' results in "raw data" format."""
for dir_ in dirlist:
results = reader(dir_)
- if use_timestats:
- keyset = results.TimeKeySet()
- else:
- keyset = results.DiskKeySet()
+ keyset = results.KeySet(keytype)
for i in range(0, keyset.num_iterations):
if len(dirlist) > 1:
line = "%s %3d" % (results.name, i)
@@ -33,23 +32,21 @@
print line
-def PrintStatisticsSummary(reader, dirlist, use_timestats, keylist):
+def PrintStatisticsSummary(reader, dirlist, keytype, keylist):
"""Print 'bootperf' results in "summary of averages" format."""
- if use_timestats:
+ if (keytype == resultset.TestResultSet.BOOTTIME_KEYSET or
+ keytype == resultset.TestResultSet.FIRMWARE_KEYSET):
header = "%5s %3s %5s %3s %s" % (
"time", "s%", "dt", "s%", "event")
format = "%5s %2d%% %5s %2d%% %s"
else:
- header = "%6s %3s %6s %3s %s" % (
+ header = "%7s %3s %7s %3s %s" % (
"diskrd", "s%", "delta", "s%", "event")
- format = "%6s %2d%% %6s %2d%% %s"
+ format = "%7s %2d%% %7s %2d%% %s"
havedata = False
for dir_ in dirlist:
results = reader(dir_)
- if use_timestats:
- keyset = results.TimeKeySet()
- else:
- keyset = results.DiskKeySet()
+ keyset = results.KeySet(keytype)
if keylist is not None:
markers = keylist
else:
diff --git a/bootperf-bin/resultset.py b/bootperf-bin/resultset.py
index 92f29f9..a17fc76 100644
--- a/bootperf-bin/resultset.py
+++ b/bootperf-bin/resultset.py
@@ -5,15 +5,16 @@
"""Classes and functions for managing platform_BootPerf results.
Results from the platform_BootPerf test in the ChromiumOS autotest
-package are stored in as performance 'keyvals', that is, a mapping
+package are stored as performance 'keyvals', that is, a mapping
of names to numeric values. For each iteration of the test, one
set of keyvals is recorded.
-This module currently tracks two kinds of keyval results, the boot
-time results, and the disk read results. These results are stored
-with keyval names such as 'seconds_kernel_to_login' and
-'rdbytes_kernel_to_login'. These keyvals record an accumulated
-total measured from a fixed time in the past (kernel startup), e.g.
+This module currently tracks three kinds of keyval results: the boot
+time results, the disk read results, and firmware time results.
+These results are stored with keyval names such as
+'seconds_kernel_to_login', 'rdbytes_kernel_to_login', and
+'seconds_power_on_to_kernel'. These keyvals record an accumulated
+total measured from a fixed time in the past, e.g.
'seconds_kernel_to_login' records the total seconds from kernel
startup to login screen ready.
@@ -25,6 +26,10 @@
'rdbytes_kernel_to_', and record bytes read from the boot device
since kernel startup.
+The firmware keyval names all start with the prefix
+'seconds_power_on_to_', and record time in seconds since CPU
+power on.
+
"""
import math
@@ -70,36 +75,47 @@
class TestResultSet(object):
"""A set of boot time and disk usage result statistics.
- Objects of this class consist of two sets of result statistics:
- the boot time statistics and the disk statistics.
+ Objects of this class consist of three sets of result statistics:
+ the boot time statistics, the disk statistics, and the firmware
+ time statistics.
Class TestResultsSet does not interpret or store keyval mappings
directly; iteration results are processed by attached _KeySet
- objects, one for boot time (`_timekeys`), one for disk read
- (`_diskkeys`). These attached _KeySet objects can be obtained
- with appropriate methods; various methods on these objects will
- calculate statistics on the results, and provide the raw data.
+ objects, one for each of the three types of result keyval. The
+ _KeySet objects are kept in a dictionary; they can be obtained
+ by calling the KeySet with the name of the keyset desired.
+ Various methods on the KeySet objects will calculate statistics on
+ the results, and provide the raw data.
"""
+ # The names of the available KeySets, to be used as arguments to
+ # KeySet().
+ BOOTTIME_KEYSET = "time"
+ DISK_KEYSET = "disk"
+ FIRMWARE_KEYSET = "firmware"
+
def __init__(self, name):
self.name = name
- self._timekeys = _TimeKeySet()
- self._diskkeys = _DiskKeySet()
+ self._keysets = {
+ self.BOOTTIME_KEYSET : _TimeKeySet(),
+ self.DISK_KEYSET : _DiskKeySet(),
+ self.FIRMWARE_KEYSET : _FirmwareKeySet(),
+ }
def AddIterationResults(self, runkeys):
"""Add keyval results from a single iteration.
A TestResultSet is constructed by repeatedly calling
- AddRunResults(), iteration by iteration. Iteration results are
- passed in as a dictionary mapping keyval attributes to values.
- When all iteration results have been added, FinalizeResults()
- makes the results available for analysis.
+ AddIterationResults(), iteration by iteration. Iteration
+ results are passed in as a dictionary mapping keyval attributes
+ to values. When all iteration results have been added,
+ FinalizeResults() makes the results available for analysis.
"""
- self._timekeys.AddRunResults(runkeys)
- self._diskkeys.AddRunResults(runkeys)
+ for keyset in self._keysets.itervalues():
+ keyset.AddIterationResults(runkeys)
def FinalizeResults(self):
"""Make results available for analysis.
@@ -112,46 +128,40 @@
"""
- self._timekeys.FinalizeResults()
- self._diskkeys.FinalizeResults()
+ for keyset in self._keysets.itervalues():
+ keyset.FinalizeResults()
- def TimeKeySet(self):
+ def KeySet(self, keytype):
"""Return the boot time statistics result set."""
- return self._timekeys
-
- def DiskKeySet(self):
- """Return the disk read statistics result set."""
- return self._diskkeys
+ return self._keysets[keytype]
class _KeySet(object):
"""Container for a set of related statistics.
_KeySet is an abstract superclass for containing collections of
- either boot time or disk read statistics. Statistics are stored
+ a related set of performance statistics. Statistics are stored
as a dictionary (`_keyvals`) mapping keyval names to lists of
- values.
+ values. The lists are indexed by the iteration number.
The mapped keyval names are shortened by stripping the prefix
- that identifies the type of prefix (keyvals that don't start with
+ that identifies the type of keyval (keyvals that don't start with
the proper prefix are ignored). So, for example, with boot time
keyvals, 'seconds_kernel_to_login' becomes 'login' (and
'rdbytes_kernel_to_login' is ignored).
A list of all valid keyval names is stored in the `markers`
instance variable. The list is sorted by the natural ordering of
- the underlying values (see the module comments for more details).
-
- The list of values associated with a given keyval name are indexed
- in the order in which they were added. So, all values for a given
- iteration are stored at the same index.
+ the underlying values. Each iteration is required to contain
+ the same set of keyvals. This is enforced in FinalizeResults()
+ (see below).
"""
def __init__(self):
self._keyvals = {}
- def AddRunResults(self, runkeys):
+ def AddIterationResults(self, runkeys):
"""Add results for one iteration."""
for key, value in runkeys.iteritems():
@@ -200,14 +210,12 @@
between two keys.
"""
-
return _ListStats(self.DeltaData(key0, key1))
class _TimeKeySet(_KeySet):
"""Concrete subclass of _KeySet for boot time statistics."""
- # TIME_KEY_PREFIX = 'seconds_kernel_to_'
PREFIX = 'seconds_kernel_to_'
# Time-based keyvals are reported in seconds and get converted to
@@ -215,15 +223,26 @@
TIME_SCALE = 1000
def _ConvertVal(self, value):
- # We use a "round to nearest int" formula here to make sure we
- # don't lose anything in the conversion from decimal.
- return int(self.TIME_SCALE * float(value) + 0.5)
+ # We want to return the nearest exact integer here. round()
+ # returns a float, and int() truncates its results, so we have
+ # to combine them.
+ return int(round(self.TIME_SCALE * float(value)))
def PrintableStatistic(self, value):
- v = int(value + 0.5)
+ v = int(round(value))
return ("%d" % v, v)
+class _FirmwareKeySet(_TimeKeySet):
+ """Concrete subclass of _KeySet for firmware time statistics."""
+
+ PREFIX = 'seconds_power_on_to_'
+
+ # Time-based keyvals are reported in seconds and get converted to
+ # milliseconds
+ TIME_SCALE = 1000
+
+
class _DiskKeySet(_KeySet):
"""Concrete subclass of _KeySet for disk read statistics."""
diff --git a/bootperf-bin/showbootdata b/bootperf-bin/showbootdata
index e474281..009698a 100755
--- a/bootperf-bin/showbootdata
+++ b/bootperf-bin/showbootdata
@@ -6,26 +6,28 @@
"""A command to display summary statistics from runs of 'bootperf'.
-Command line options allow selecting from one of two sets of
-performance statistics: The boot time statistics (selected by
---timestats) measure time spent from kernel startup in milliseconds.
-The disk statistics (selected by --diskstats) measure total bytes
-read from the boot device since kernel startup.
+Command line options allow selecting from one of three sets of
+performance statistics: boot time statistics (selected by
+--timestats) measure time spent since kernel startup; disk statistics
+(selected by --diskstats) measure total bytes read from the boot
+device since kernel startup; firmware time statistics (selected by
+--firmware) measure time spent since CPU power on.
-Boot time statistics are recorded as cumulative time (or disk read)
-since kernel startup, measured when specific events occur during
-boot. Events include such things as 'startup', the moment when the
-upstart 'startup' job begins running, and 'login', when the
-Chrome OS login screen is displayed. By default, all recorded events
-are included in the output; command line options allow restricting
-the view to a selected subset of events.
+The various statistics are recorded as cumulative time (or disk read)
+since kernel startup (or CPU power on), sampled when specific events
+occur during boot. Events include such things as 'startup', the
+moment when the upstart 'startup' job begins running, and 'login',
+when the Chrome OS login screen is displayed. By default, all
+recorded events are included in the output; command line options
+allow restricting the view to a selected subset of events.
Separate command line options allow selecting from one of two
different display modes. When --averages is selected, the display
shows the average value and sample standard deviation (as a percent
-of the average) for all selected events. The --averages display also
-calculates the time (or bytes) between adjacent events, and shows
-the avearage and sample standard deviation of the differences.
+of the average) for all selected events. The --averages display
+also calculates the difference (in time or bytes) between adjacent
+events, and shows the average and sample standard deviation of the
+differences.
The --rawdata display shows the raw data value associated with each
event for each boot: Each line of output represents the event values
@@ -36,8 +38,9 @@
import sys
import optparse
-import resultsdir
import perfprinter
+import resultsdir
+import resultset
_USAGE = "%prog [options] [results-directory ...]"
@@ -61,9 +64,14 @@
"-d", "--diskstats", action="store_true",
dest="use_diskstats",
help="use statistics for bytes read since kernel startup")
+ optgroup.add_option(
+ "-f", "--firmwarestats", action="store_true",
+ dest="use_firmware",
+ help="use statistics for firmware startup times")
optparser.add_option_group(optgroup)
optparser.set_defaults(use_diskstats=False)
optparser.set_defaults(use_timestats=False)
+ optparser.set_defaults(use_firmware=False)
optgroup = optparse.OptionGroup(optparser, "Event selection")
optgroup.add_option(
@@ -104,11 +112,22 @@
return printfunc
-def _ProcessStatsOptions(options):
- if options.use_timestats and options.use_diskstats:
- print >>sys.stderr, "Can't use -t and -d together.\n"
- return None
- return not options.use_diskstats
+def _ProcessKeysetOptions(options):
+ keyset_count = 0
+ keyset_type = resultset.TestResultSet.BOOTTIME_KEYSET
+ if options.use_timestats:
+ keyset_count += 1
+ keyset_type = resultset.TestResultSet.BOOTTIME_KEYSET
+ if options.use_diskstats:
+ keyset_count += 1
+ keyset_type = resultset.TestResultSet.DISK_KEYSET
+ if options.use_firmware:
+ keyset_count += 1
+ keyset_type = resultset.TestResultSet.FIRMWARE_KEYSET
+ if keyset_count > 1:
+ print >>sys.stderr, "Can use only one of -t, -d, or -f.\n"
+ keyset_type = None
+ return keyset_type
def _ProcessKeylistOptions(options):
@@ -124,15 +143,15 @@
optparser = _SetupOptions()
(options, args) = optparser.parse_args(argv)
printfunc = _ProcessDisplayOptions(options)
- use_timestats = _ProcessStatsOptions(options)
+ keyset_type = _ProcessKeysetOptions(options)
keylist = _ProcessKeylistOptions(options)
- if printfunc is None or use_timestats is None:
+ if printfunc is None or keyset_type is None:
optparser.print_help()
sys.exit(1)
if not args:
args = ["."]
printfunc(resultsdir.ReadResultsDirectory,
- args, use_timestats, keylist)
+ args, keyset_type, keylist)
if __name__ == "__main__":
