Skip to content

Commit

Permalink
Fixit: Fork base::TimeTicks --> TimeTicks + ThreadTicks + TraceTicks
Browse files Browse the repository at this point in the history 
TimeTicks was being overused for time values from three different clock
sources.  This change splits the class into three separate classes: The
general-purpose monotonic time (TimeTicks), the thread-local run time
(ThreadTicks), and the global system trace time (TraceTicks).  With this
change, the compiler is now able to use type-checking to guarantee
values from different clocks are not being mixed when doing time math.

This is the 2nd in a two-part change.  Part 1 factored-out the
comparison and math operator overloads common to base::Time and
base::TimeTicks into a templated base class.  The new ThreadTicks and
TraceTicks time classes also inherit from that base class.

Updated base/trace_event/* and a handful of outside-of-base uses of
ThreadNow() and NowFromSystemTraceTime() to use the new classes.  A bug
was identified and fixed, in src/ui/gl/angle_platform_impl.cc, where
values from TimeTicks::Now() were being erroneously provided to
base::TraceEvent instead of values from NowFromSystemTraceTime().

BUG=467417
CQ_INCLUDE_TRYBOTS=tryserver.blink:linux_blink_rel
NOTRY=true

Review URL: https://codereview.chromium.org/1122153002

Cr-Commit-Position: refs/heads/master@{#332080}
  • Loading branch information
@miu-chromium
miu-chromium authored and Commit bot committed May 29, 2015
1 parent 6cccd7e commit 1ab506a
Show file tree
Hide file tree
Showing 38 changed files with 402 additions and 285 deletions.
12 changes: 6 additions & 6 deletions base/message_loop/message_pump_perftest.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -29,9 +29,9 @@ class ScheduleWorkTest : public testing::Test {

void Schedule(int index) {
base::TimeTicks start = base::TimeTicks::Now();
base::TimeTicks thread_start;
if (TimeTicks::IsThreadNowSupported())
thread_start = base::TimeTicks::ThreadNow();
base::ThreadTicks thread_start;
if (ThreadTicks::IsSupported())
thread_start = base::ThreadTicks::Now();
base::TimeDelta minimum = base::TimeDelta::Max();
base::TimeDelta maximum = base::TimeDelta();
base::TimeTicks now, lastnow = start;
Expand All @@ -49,9 +49,9 @@ class ScheduleWorkTest : public testing::Test {
} while (now - start < base::TimeDelta::FromSeconds(kTargetTimeSec));

scheduling_times_[index] = now - start;
if (TimeTicks::IsThreadNowSupported())
if (ThreadTicks::IsSupported())
scheduling_thread_times_[index] =
base::TimeTicks::ThreadNow() - thread_start;
base::ThreadTicks::Now() - thread_start;
min_batch_times_[index] = minimum;
max_batch_times_[index] = maximum;
target_message_loop()->PostTask(FROM_HERE,
Expand Down Expand Up @@ -139,7 +139,7 @@ class ScheduleWorkTest : public testing::Test {
max_batch_time.InMicroseconds() / static_cast<double>(kBatchSize),
"us/task",
false);
if (TimeTicks::IsThreadNowSupported()) {
if (ThreadTicks::IsSupported()) {
perf_test::PrintResult(
"task",
"_thread_time",
Expand Down
16 changes: 8 additions & 8 deletions base/threading/thread_perftest.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -48,14 +48,14 @@ class ThreadPerfTest : public testing::Test {
virtual void PingPong(int hops) = 0;
virtual void Reset() {}

void TimeOnThread(base::TimeTicks* ticks, base::WaitableEvent* done) {
*ticks = base::TimeTicks::ThreadNow();
void TimeOnThread(base::ThreadTicks* ticks, base::WaitableEvent* done) {
*ticks = base::ThreadTicks::Now();
done->Signal();
}

base::TimeTicks ThreadNow(base::Thread* thread) {
base::ThreadTicks ThreadNow(base::Thread* thread) {
base::WaitableEvent done(false, false);
base::TimeTicks ticks;
base::ThreadTicks ticks;
thread->task_runner()->PostTask(
FROM_HERE, base::Bind(&ThreadPerfTest::TimeOnThread,
base::Unretained(this), &ticks, &done));
Expand All @@ -65,11 +65,11 @@ class ThreadPerfTest : public testing::Test {

void RunPingPongTest(const std::string& name, unsigned num_threads) {
// Create threads and collect starting cpu-time for each thread.
std::vector<base::TimeTicks> thread_starts;
std::vector<base::ThreadTicks> thread_starts;
while (threads_.size() < num_threads) {
threads_.push_back(new base::Thread("PingPonger"));
threads_.back()->Start();
if (base::TimeTicks::IsThreadNowSupported())
if (base::ThreadTicks::IsSupported())
thread_starts.push_back(ThreadNow(threads_.back()));
}

Expand All @@ -84,7 +84,7 @@ class ThreadPerfTest : public testing::Test {
// but that should be in the noise given enough runs.
base::TimeDelta thread_time;
while (threads_.size()) {
if (base::TimeTicks::IsThreadNowSupported()) {
if (base::ThreadTicks::IsSupported()) {
thread_time += ThreadNow(threads_.back()) - thread_starts.back();
thread_starts.pop_back();
}
Expand All @@ -102,7 +102,7 @@ class ThreadPerfTest : public testing::Test {
"task", "", name + "_time ", us_per_task_clock, "us/hop", true);

// Total utilization across threads if available (likely higher).
if (base::TimeTicks::IsThreadNowSupported()) {
if (base::ThreadTicks::IsSupported()) {
perf_test::PrintResult(
"task", "", name + "_cpu ", us_per_task_cpu, "us/hop", true);
}
Expand Down
10 changes: 10 additions & 0 deletions base/time/time.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -327,6 +327,16 @@ std::ostream& operator<<(std::ostream& os, TimeTicks time_ticks) {
return os << as_time_delta.InMicroseconds() << " bogo-microseconds";
}

std::ostream& operator<<(std::ostream& os, ThreadTicks thread_ticks) {
const TimeDelta as_time_delta = thread_ticks - ThreadTicks();
return os << as_time_delta.InMicroseconds() << " bogo-thread-microseconds";
}

std::ostream& operator<<(std::ostream& os, TraceTicks trace_ticks) {
const TimeDelta as_time_delta = trace_ticks - TraceTicks();
return os << as_time_delta.InMicroseconds() << " bogo-trace-microseconds";
}

// Time::Exploded -------------------------------------------------------------

inline bool is_in_range(int value, int lo, int hi) {
Expand Down
177 changes: 122 additions & 55 deletions base/time/time.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,25 +4,53 @@

// Time represents an absolute point in coordinated universal time (UTC),
// internally represented as microseconds (s/1,000,000) since the Windows epoch
// (1601-01-01 00:00:00 UTC) (See http://crbug.com/14734). System-dependent
// clock interface routines are defined in time_PLATFORM.cc.
// (1601-01-01 00:00:00 UTC). System-dependent clock interface routines are
// defined in time_PLATFORM.cc. Note that values for Time may skew and jump
// around as the operating system makes adjustments to synchronize (e.g., with
// NTP servers). Thus, client code that uses the Time class must account for
// this.
//
// TimeDelta represents a duration of time, internally represented in
// microseconds.
//
// TimeTicks represents an abstract time that is most of the time incrementing
// for use in measuring time durations. It is internally represented in
// microseconds. It can not be converted to a human-readable time, but is
// guaranteed not to decrease (if the user changes the computer clock,
// Time::Now() may actually decrease or jump). But note that TimeTicks may
// "stand still", for example if the computer suspended.
// TimeTicks, ThreadTicks, and TraceTicks represent an abstract time that is
// most of the time incrementing, for use in measuring time durations.
// Internally, they are represented in microseconds. They can not be converted
// to a human-readable time, but are guaranteed not to decrease (unlike the Time
// class). Note that TimeTicks may "stand still" (e.g., if the computer is
// suspended), and ThreadTicks will "stand still" whenever the thread has been
// de-scheduled by the operating system.
//
// These classes are represented as only a 64-bit value, so they can be
// efficiently passed by value.
// All time classes are copyable, assignable, and occupy 64-bits per
// instance. Thus, they can be efficiently passed by-value (as opposed to
// by-reference).
//
// Definitions of operator<< are provided to make these types work with
// DCHECK_EQ() and other log macros. For human-readable formatting, see
// "base/i18n/time_formatting.h".
//
// So many choices! Which time class should you use? Examples:
//
// Time: Interpreting the wall-clock time provided by a remote
// system. Detecting whether cached resources have
// expired. Providing the user with a display of the current date
// and time. Determining the amount of time between events across
// re-boots of the machine.
//
// TimeTicks: Tracking the amount of time a task runs. Executing delayed
// tasks at the right time. Computing presentation timestamps.
// Synchronizing audio and video using TimeTicks as a common
// reference clock (lip-sync). Measuring network round-trip
// latency.
//
// ThreadTicks: Benchmarking how long the current thread has been doing actual
// work.
//
// TraceTicks: This is only meant to be used by the event tracing
// infrastructure, and by outside code modules in special
// circumstances. Please be sure to consult a
// base/trace_event/OWNER before committing any new code that
// uses this.

#ifndef BASE_TIME_TIME_H_
#define BASE_TIME_TIME_H_
Expand Down Expand Up @@ -639,14 +667,6 @@ BASE_EXPORT std::ostream& operator<<(std::ostream& os, Time time);
// Represents monotonically non-decreasing clock time.
class BASE_EXPORT TimeTicks : public time_internal::TimeBase<TimeTicks> {
public:
// We define this even without OS_CHROMEOS for seccomp sandbox testing.
#if defined(OS_LINUX)
// Force definition of the system trace clock; it is a chromeos-only api
// at the moment and surfacing it in the right place requires mucking
// with glibc et al.
static const clockid_t kClockSystemTrace = 11;
#endif

TimeTicks() : TimeBase(0) {
}

Expand All @@ -662,43 +682,6 @@ class BASE_EXPORT TimeTicks : public time_internal::TimeBase<TimeTicks> {
// clock will be used instead.
static bool IsHighResolution();

// Returns true if ThreadNow() is supported on this system.
static bool IsThreadNowSupported() {
#if (defined(_POSIX_THREAD_CPUTIME) && (_POSIX_THREAD_CPUTIME >= 0)) || \
(defined(OS_MACOSX) && !defined(OS_IOS)) || defined(OS_ANDROID)
return true;
#else
return false;
#endif
}

// Returns thread-specific CPU-time on systems that support this feature.
// Needs to be guarded with a call to IsThreadNowSupported(). Use this timer
// to (approximately) measure how much time the calling thread spent doing
// actual work vs. being de-scheduled. May return bogus results if the thread
// migrates to another CPU between two calls.
//
// WARNING: The returned value might NOT have the same origin as Now(). Do not
// perform math between TimeTicks values returned by Now() and ThreadNow() and
// expect meaningful results.
// TODO(miu): Since the timeline of these values is different, the values
// should be of a different type.
static TimeTicks ThreadNow();

// Returns the current system trace time or, if not available on this
// platform, a high-resolution time value; or a low-resolution time value if
// neither are avalable. On systems where a global trace clock is defined,
// timestamping TraceEvents's with this value guarantees synchronization
// between events collected inside chrome and events collected outside
// (e.g. kernel, X server).
//
// WARNING: The returned value might NOT have the same origin as Now(). Do not
// perform math between TimeTicks values returned by Now() and
// NowFromSystemTraceTime() and expect meaningful results.
// TODO(miu): Since the timeline of these values is different, the values
// should be of a different type.
static TimeTicks NowFromSystemTraceTime();

#if defined(OS_WIN)
// Translates an absolute QPC timestamp into a TimeTicks value. The returned
// value has the same origin as Now(). Do NOT attempt to use this if
Expand Down Expand Up @@ -738,6 +721,90 @@ class BASE_EXPORT TimeTicks : public time_internal::TimeBase<TimeTicks> {
// For logging use only.
BASE_EXPORT std::ostream& operator<<(std::ostream& os, TimeTicks time_ticks);

// ThreadTicks ----------------------------------------------------------------

// Represents a clock, specific to a particular thread, than runs only while the
// thread is running.
class BASE_EXPORT ThreadTicks : public time_internal::TimeBase<ThreadTicks> {
public:
ThreadTicks() : TimeBase(0) {
}

// Returns true if ThreadTicks::Now() is supported on this system.
static bool IsSupported() {
#if (defined(_POSIX_THREAD_CPUTIME) && (_POSIX_THREAD_CPUTIME >= 0)) || \
(defined(OS_MACOSX) && !defined(OS_IOS)) || defined(OS_ANDROID)
return true;
#else
return false;
#endif
}

// Returns thread-specific CPU-time on systems that support this feature.
// Needs to be guarded with a call to IsSupported(). Use this timer
// to (approximately) measure how much time the calling thread spent doing
// actual work vs. being de-scheduled. May return bogus results if the thread
// migrates to another CPU between two calls.
static ThreadTicks Now();

private:
friend class time_internal::TimeBase<ThreadTicks>;

// Please use Now() to create a new object. This is for internal use
// and testing.
explicit ThreadTicks(int64 us) : TimeBase(us) {
}
};

// For logging use only.
BASE_EXPORT std::ostream& operator<<(std::ostream& os, ThreadTicks time_ticks);

// TraceTicks ----------------------------------------------------------------

// Represents high-resolution system trace clock time.
class BASE_EXPORT TraceTicks : public time_internal::TimeBase<TraceTicks> {
public:
// We define this even without OS_CHROMEOS for seccomp sandbox testing.
#if defined(OS_LINUX)
// Force definition of the system trace clock; it is a chromeos-only api
// at the moment and surfacing it in the right place requires mucking
// with glibc et al.
static const clockid_t kClockSystemTrace = 11;
#endif

TraceTicks() : TimeBase(0) {
}

// Returns the current system trace time or, if not available on this
// platform, a high-resolution time value; or a low-resolution time value if
// neither are avalable. On systems where a global trace clock is defined,
// timestamping TraceEvents's with this value guarantees synchronization
// between events collected inside chrome and events collected outside
// (e.g. kernel, X server).
//
// On some platforms, the clock source used for tracing can vary depending on
// hardware and/or kernel support. Do not make any assumptions without
// consulting the documentation for this functionality in the time_win.cc,
// time_posix.cc, etc. files.
//
// NOTE: This is only meant to be used by the event tracing infrastructure,
// and by outside code modules in special circumstances. Please be sure to
// consult a base/trace_event/OWNER before committing any new code that uses
// this.
static TraceTicks Now();

private:
friend class time_internal::TimeBase<TraceTicks>;

// Please use Now() to create a new object. This is for internal use
// and testing.
explicit TraceTicks(int64 us) : TimeBase(us) {
}
};

// For logging use only.
BASE_EXPORT std::ostream& operator<<(std::ostream& os, TraceTicks time_ticks);

} // namespace base

#endif // BASE_TIME_TIME_H_
32 changes: 17 additions & 15 deletions base/time/time_mac.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -19,10 +19,11 @@
#include "base/mac/mach_logging.h"
#include "base/mac/scoped_cftyperef.h"
#include "base/mac/scoped_mach_port.h"
#include "base/numerics/safe_conversions.h"

namespace {

uint64_t ComputeCurrentTicks() {
int64_t ComputeCurrentTicks() {
#if defined(OS_IOS)
// On iOS mach_absolute_time stops while the device is sleeping. Instead use
// now - KERN_BOOTTIME to get a time difference that is not impacted by clock
Expand All @@ -38,8 +39,6 @@ uint64_t ComputeCurrentTicks() {
base::TimeDelta::FromMicroseconds(boottime.tv_usec));
return time_difference.InMicroseconds();
#else
uint64_t absolute_micro;

static mach_timebase_info_data_t timebase_info;
if (timebase_info.denom == 0) {
// Zero-initialization of statics guarantees that denom will be 0 before
Expand All @@ -57,18 +56,19 @@ uint64_t ComputeCurrentTicks() {

// timebase_info converts absolute time tick units into nanoseconds. Convert
// to microseconds up front to stave off overflows.
absolute_micro =
mach_absolute_time() / base::Time::kNanosecondsPerMicrosecond *
timebase_info.numer / timebase_info.denom;
base::CheckedNumeric<uint64_t> result(
mach_absolute_time() / base::Time::kNanosecondsPerMicrosecond);
result *= timebase_info.numer;
result /= timebase_info.denom;

// Don't bother with the rollover handling that the Windows version does.
// With numer and denom = 1 (the expected case), the 64-bit absolute time
// reported in nanoseconds is enough to last nearly 585 years.
return absolute_micro;
return base::checked_cast<int64_t>(result.ValueOrDie());
#endif // defined(OS_IOS)
}

uint64_t ComputeThreadTicks() {
int64_t ComputeThreadTicks() {
#if defined(OS_IOS)
NOTREACHED();
return 0;
Expand All @@ -89,9 +89,11 @@ uint64_t ComputeThreadTicks() {
&thread_info_count);
MACH_DCHECK(kr == KERN_SUCCESS, kr) << "thread_info";

return (thread_info_data.user_time.seconds *
base::Time::kMicrosecondsPerSecond) +
thread_info_data.user_time.microseconds;
base::CheckedNumeric<int64_t> absolute_micros(
thread_info_data.user_time.seconds);
absolute_micros *= base::Time::kMicrosecondsPerSecond;
absolute_micros += thread_info_data.user_time.microseconds;
return absolute_micros.ValueOrDie();
#endif // defined(OS_IOS)
}

Expand Down Expand Up @@ -225,13 +227,13 @@ bool TimeTicks::IsHighResolution() {
}

// static
TimeTicks TimeTicks::ThreadNow() {
return TimeTicks(ComputeThreadTicks());
ThreadTicks ThreadTicks::Now() {
return ThreadTicks(ComputeThreadTicks());
}

// static
TimeTicks TimeTicks::NowFromSystemTraceTime() {
return Now();
TraceTicks TraceTicks::Now() {
return TraceTicks(ComputeCurrentTicks());
}

} // namespace base
Loading

0 comments on commit 1ab506a

Please sign in to comment.