blob: afd900337bd6aaa2001f7276ca181a193c0891eb [file] [log] [blame]
# Copyright (c) 2014 The Chromium Authors. All rights reserved.
# Use of this source code is governed by a BSD-style license that can be
# found in the LICENSE file.
import logging
import os
import re
from time import sleep
from autotest_lib.client.bin import test, utils
from autotest_lib.client.common_lib import error
class kernel_Ktime(test.test):
Test to ensure that ktime and the RTC clock are consistent.
version = 1
KERNEL_VER = '3.18'
MODULE_NAME = 'udelay_test'
MODULE_NAME_NEW = 'test_udelay'
UDELAY_PATH = '/sys/kernel/debug/udelay_test'
RTC_PATH = '/sys/class/rtc/rtc0/since_epoch'
# How many iterations to run the test for, each iteration is usally
# a second, but might be more if the skew is too large when retrieving
# the RTC and ktime.
# Allowable drift (as a function of elapsed RTC time): 0.01%
# Maximum skew between ktime readings when aligning RTC and ktime
MAX_SKEW = 0.050
# Diffs to average for the rolling display
def _set_file(self, contents, filename):
Write a string to a file.
@param contents: the contents to write to the file
@param filename: the filename to use
logging.debug('setting %s to %s', filename, contents)
with open(filename, 'w') as f:
def _get_file(self, filename):
Read a string from a file.
@returns: the contents of the file (string)
with open(filename, 'r') as f:
def _get_rtc(self):
Get the current RTC time.
@returns: the current RTC time since epoch (int)
return int(self._get_file(self.RTC_PATH))
def _get_ktime(self):
Get the current ktime.
@returns: the current ktime (float)
# Writing a delay of 0 will return info including the current ktime.
self._set_file('0', self.UDELAY_PATH)
with open(self.UDELAY_PATH, 'r') as f:
for line in f:
line = line.rstrip()
logging.debug('result: %s', line)
m ='kt=(\d+.\d+)', line)
if m:
return float(
return 0.0
def _get_times(self):
Get the rtc and estimated ktime and max potential error.
Returns the RTC and a best guess of the ktime when the RTC actually
ticked over to the current value. Also returns the maximum potential
error of how far they are off by.
RTC ticked in the range of [ktime - max_error, ktime + max_error]
@returns: list of the current rtc, estimated ktime, max error
# Times are read k1, r1, k2, r2, k3. RTC ticks over somewhere between
# r1 and r2, but since we don't know exactly when that is, the best
# guess we have is between k1 and k3.
rtc_older = self._get_rtc()
ktime_older = self._get_ktime()
rtc_old = self._get_rtc()
ktime_old = self._get_ktime()
# Ensure that this function returns in a reasonable number of
# iterations. If excessive skew occurs repeatedly (eg RTC is too
# slow), abort.
bad_skew = 0
while bad_skew < 10:
rtc = self._get_rtc()
ktime = self._get_ktime()
skew = ktime - ktime_older
if skew > self.MAX_SKEW:
# Time between successive calls to ktime was too slow to
# bound the error to a reasonable value. A few occurrences
# isn't anything to be concerned about, but if it's happening
# every second, it's worth investigating and could indicate
# that the RTC is very slow and MAX_SKEW needs to be increased.
'retrying excessive skew: '
'rtc [%d %d %d] ktime [%f %f %f] skew %f'),
rtc_older, rtc_old, rtc, ktime_older, ktime_old, ktime,
bad_skew += 1
elif rtc != rtc_old:
if rtc_older != rtc_old or rtc != rtc_old + 1:
# This could happen if we took more than one second per
# loop and could be changed to a warning if legitimate.
raise error.TestFail('rtc progressed from %u to %u to %u' %
(rtc_older, rtc_old, rtc))
return rtc, ktime_older + skew / 2, skew / 2
rtc_older = rtc_old
ktime_older = ktime_old
rtc_old = rtc
ktime_old = ktime
raise error.TestFail('could not reach skew %f after %d attempts' % (
self.MAX_SKEW, bad_skew))
def run_once(self):
kernel_ver = os.uname()[2]
if utils.compare_versions(kernel_ver, self.MIN_KERNEL_VER) < 0:
'skipping test: old kernel %s (min %s) missing module %s',
kernel_ver, self.MIN_KERNEL_VER, self.MODULE_NAME)
elif utils.compare_versions(kernel_ver, self.KERNEL_VER) < 0:
elif utils.compare_versions(kernel_ver, self.KERNEL_VER) > 0:
start_rtc, start_ktime, start_error = self._get_times()
'start rtc %d ktime %f error %f',
start_rtc, start_ktime, start_error)
recent_diffs = []
max_diff = 0
sum_rtc = 0
sum_diff = 0
sum_rtc_rtc = 0
sum_rtc_diff = 0
sum_diff_diff = 0
for i in xrange(self.TEST_DURATION):
# Sleep some amount of time to avoid busy waiting the entire time
sleep((i % 10) * 0.1)
current_rtc, current_ktime, current_error = self._get_times()
elapsed_rtc = current_rtc - start_rtc
elapsed_ktime = current_ktime - start_ktime
elapsed_diff = float(elapsed_rtc) - elapsed_ktime
# Allow for inaccurate ktime off ALLOWABLE_DRIFT from elapsed RTC,
# and take into account start and current error in times gathering
max_error = start_error + current_error
drift_threshold = elapsed_rtc * self.ALLOWABLE_DRIFT + max_error
# Track rolling average and maximum diff
if len(recent_diffs) > self.DIFFS_TO_AVERAGE:
rolling_diff = sum(recent_diffs) / len(recent_diffs)
if abs(elapsed_diff) > abs(max_diff):
max_diff = elapsed_diff
# Track linear regression
sum_rtc += elapsed_rtc
sum_diff += elapsed_diff
sum_rtc_rtc += elapsed_rtc * elapsed_rtc
sum_rtc_diff += elapsed_rtc * elapsed_diff
sum_diff_diff += elapsed_diff * elapsed_diff
'current rtc %d ktime %f error %f; elapsed rtc %d '
'ktime %f: threshold %f diff %+f rolling %+f'),
current_rtc, current_ktime, current_error, elapsed_rtc,
elapsed_ktime, drift_threshold, elapsed_diff, rolling_diff)
if abs(elapsed_diff) > drift_threshold:
raise error.TestFail((
'elapsed rtc %d and ktime %f diff %f '
'is greater than threshold %f') %
(elapsed_rtc, elapsed_ktime, elapsed_diff,
# Dump final statistics'max_diff %f', max_diff)
mean_rtc = sum_rtc / self.TEST_DURATION
mean_diff = sum_diff / self.TEST_DURATION
slope = ((sum_rtc_diff - sum_rtc * mean_diff) /
(sum_rtc_rtc - sum_rtc * mean_rtc))'drift %.9f', slope)