From 6dadd492b890f11f236d71b493a084e30e78f358 Mon Sep 17 00:00:00 2001 From: Joshua Peraza Date: Wed, 6 Nov 2019 10:00:13 -0800 Subject: [PATCH] linux: fix proc stat reader flakiness ProcStatReader.Threads is flaky because it relies on an internal, imprecise measurement of boot time. The flaky test asserts that a thread started after the main thread should have a start time >= the main thread. The start time is returned in a timeval, with microsecond precision, but the measurement of boot time requires two system calls and the time between those system calls can be approximately a microsecond. An unlucky event such as a change in system time could make this imprecision arbitrarily bad. This patch lets the caller of ProcStatReader.StartTime() inject the boot time, allowing ProcStatReader to guarantee that threads have correctly ordered time, given the same input boot time. Bug: 1016765 Change-Id: I6e4a944a1d58c3916090bab6a4b99573e71a89fc Reviewed-on: https://chromium-review.googlesource.com/c/crashpad/crashpad/+/1891588 Reviewed-by: Mark Mentovai Commit-Queue: Joshua Peraza --- util/BUILD.gn | 1 + util/linux/proc_stat_reader.cc | 22 +++-------------- util/linux/proc_stat_reader.h | 3 ++- util/linux/proc_stat_reader_test.cc | 30 +++++++++++++++++------ util/misc/time.h | 8 ++++++ util/misc/time_linux.cc | 38 +++++++++++++++++++++++++++++ util/posix/process_info_linux.cc | 9 ++++++- util/util.gyp | 1 + 8 files changed, 83 insertions(+), 29 deletions(-) create mode 100644 util/misc/time_linux.cc diff --git a/util/BUILD.gn b/util/BUILD.gn index d225f1dc..02558909 100644 --- a/util/BUILD.gn +++ b/util/BUILD.gn @@ -332,6 +332,7 @@ static_library("util") { "linux/traits.h", "misc/capture_context_linux.S", "misc/paths_linux.cc", + "misc/time_linux.cc", "posix/process_info_linux.cc", "process/process_memory_linux.cc", "process/process_memory_linux.h", diff --git a/util/linux/proc_stat_reader.cc b/util/linux/proc_stat_reader.cc index 88658f58..dd663d6c 100644 --- a/util/linux/proc_stat_reader.cc +++ b/util/linux/proc_stat_reader.cc @@ -85,7 +85,8 @@ bool ProcStatReader::SystemCPUTime(timeval* system_time) const { return ReadTimeAtIndex(14, system_time); } -bool ProcStatReader::StartTime(timeval* start_time) const { +bool ProcStatReader::StartTime(const timeval& boot_time, + timeval* start_time) const { INITIALIZATION_STATE_DCHECK_VALID(initialized_); timeval time_after_boot; @@ -93,24 +94,7 @@ bool ProcStatReader::StartTime(timeval* start_time) const { return false; } - timespec uptime; - if (clock_gettime(CLOCK_BOOTTIME, &uptime) != 0) { - PLOG(ERROR) << "clock_gettime"; - return false; - } - - timespec current_time; - if (clock_gettime(CLOCK_REALTIME, ¤t_time) != 0) { - PLOG(ERROR) << "clock_gettime"; - return false; - } - - timespec boot_time_ts; - SubtractTimespec(current_time, uptime, &boot_time_ts); - timeval boot_time_tv; - TimespecToTimeval(boot_time_ts, &boot_time_tv); - timeradd(&boot_time_tv, &time_after_boot, start_time); - + timeradd(&boot_time, &time_after_boot, start_time); return true; } diff --git a/util/linux/proc_stat_reader.h b/util/linux/proc_stat_reader.h index c0b30520..6eae8fbb 100644 --- a/util/linux/proc_stat_reader.h +++ b/util/linux/proc_stat_reader.h @@ -60,11 +60,12 @@ class ProcStatReader { //! \brief Determines the target thread’s start time. //! + //! \param[in] boot_time The kernel boot time. //! \param[out] start_time The time that the thread started. //! //! \return `true` on success, with \a start_time set. Otherwise, `false` with //! a message logged. - bool StartTime(timeval* start_time) const; + bool StartTime(const timeval& boot_time, timeval* start_time) const; private: bool FindColumn(int index, const char** column) const; diff --git a/util/linux/proc_stat_reader_test.cc b/util/linux/proc_stat_reader_test.cc index bc0d65bc..01b9afd7 100644 --- a/util/linux/proc_stat_reader_test.cc +++ b/util/linux/proc_stat_reader_test.cc @@ -21,6 +21,7 @@ #include "base/logging.h" #include "gtest/gtest.h" #include "test/linux/fake_ptrace_connection.h" +#include "util/misc/time.h" #include "util/thread/thread.h" namespace crashpad { @@ -34,8 +35,13 @@ TEST(ProcStatReader, Basic) { ProcStatReader stat; ASSERT_TRUE(stat.Initialize(&connection, getpid())); + timespec boot_time_ts; + ASSERT_TRUE(GetBootTime(&boot_time_ts)); + timeval boot_time; + TimespecToTimeval(boot_time_ts, &boot_time); + timeval start_time; - ASSERT_TRUE(stat.StartTime(&start_time)); + ASSERT_TRUE(stat.StartTime(boot_time, &start_time)); time_t now; time(&now); @@ -56,30 +62,38 @@ pid_t gettid() { return syscall(SYS_gettid); } -void GetStartTime(timeval* start_time) { +void GetStartTime(const timeval& boot_time, timeval* start_time) { FakePtraceConnection connection; ASSERT_TRUE(connection.Initialize(getpid())); ProcStatReader stat; ASSERT_TRUE(stat.Initialize(&connection, gettid())); - ASSERT_TRUE(stat.StartTime(start_time)); + ASSERT_TRUE(stat.StartTime(boot_time, start_time)); } class StatTimeThread : public Thread { public: - StatTimeThread(timeval* start_time) : start_time_(start_time) {} + StatTimeThread(const timeval& boot_time, timeval* start_time) + : boot_time_(boot_time), start_time_(start_time) {} private: - void ThreadMain() override { GetStartTime(start_time_); } + void ThreadMain() override { GetStartTime(boot_time_, start_time_); } + + const timeval& boot_time_; timeval* start_time_; }; TEST(ProcStatReader, Threads) { + timespec boot_time_ts; + ASSERT_TRUE(GetBootTime(&boot_time_ts)); + timeval boot_time; + TimespecToTimeval(boot_time_ts, &boot_time); + timeval main_time; - ASSERT_NO_FATAL_FAILURE(GetStartTime(&main_time)); + ASSERT_NO_FATAL_FAILURE(GetStartTime(boot_time, &main_time)); timeval thread_time; - StatTimeThread thread(&thread_time); + StatTimeThread thread(boot_time, &thread_time); thread.Start(); ASSERT_NO_FATAL_FAILURE(thread.Join()); @@ -89,7 +103,7 @@ TEST(ProcStatReader, Threads) { time_t thread_sec, suseconds_t thread_usec) { return (thread_sec > main_sec) || - (thread_sec == main_sec && thread_usec > main_usec); + (thread_sec == main_sec && thread_usec >= main_usec); }, main_time.tv_sec, main_time.tv_usec, diff --git a/util/misc/time.h b/util/misc/time.h index aabe8e64..dffe1a8a 100644 --- a/util/misc/time.h +++ b/util/misc/time.h @@ -69,6 +69,14 @@ void GetTimeOfDay(timeval* tv); #endif // OS_WIN +#if defined(OS_LINUX) || defined(OS_ANDROID) || DOXYGEN +//! \brief Get the kernel boot time. Subsequent calls to this function may +//! return different results due to the system clock being changed or +//! imprecision in measuring the boot time. +//! \return `true` on success. Otherwise, `false` with a message logged. +bool GetBootTime(timespec* ts); +#endif // OS_LINUX || OS_ANDROID || DOXYGEN + } // namespace crashpad #endif // CRASHPAD_UTIL_MISC_TIME_H_ diff --git a/util/misc/time_linux.cc b/util/misc/time_linux.cc new file mode 100644 index 00000000..bc73533c --- /dev/null +++ b/util/misc/time_linux.cc @@ -0,0 +1,38 @@ +// Copyright 2019 The Crashpad Authors. All rights reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +#include "util/misc/time.h" + +#include "base/logging.h" + +namespace crashpad { + +bool GetBootTime(timespec* boot_time) { + timespec uptime; + if (clock_gettime(CLOCK_BOOTTIME, &uptime) != 0) { + PLOG(ERROR) << "clock_gettime"; + return false; + } + + timespec current_time; + if (clock_gettime(CLOCK_REALTIME, ¤t_time) != 0) { + PLOG(ERROR) << "clock_gettime"; + return false; + } + + SubtractTimespec(current_time, uptime, boot_time); + return true; +} + +} // namespace crashpad diff --git a/util/posix/process_info_linux.cc b/util/posix/process_info_linux.cc index 72a2bd70..3ffd96ab 100644 --- a/util/posix/process_info_linux.cc +++ b/util/posix/process_info_linux.cc @@ -23,6 +23,7 @@ #include "util/file/string_file.h" #include "util/linux/proc_stat_reader.h" #include "util/misc/lexing.h" +#include "util/misc/time.h" namespace crashpad { @@ -238,7 +239,13 @@ bool ProcessInfo::StartTime(timeval* start_time) const { if (!reader.Initialize(connection_, pid_)) { return false; } - if (!reader.StartTime(&start_time_)) { + timespec boot_time_ts; + if (!GetBootTime(&boot_time_ts)) { + return false; + } + timeval boot_time; + TimespecToTimeval(boot_time_ts, &boot_time); + if (!reader.StartTime(boot_time, &start_time_)) { return false; } start_time_initialized_.set_valid(); diff --git a/util/util.gyp b/util/util.gyp index b9da2324..82ba3938 100644 --- a/util/util.gyp +++ b/util/util.gyp @@ -168,6 +168,7 @@ 'misc/symbolic_constants_common.h', 'misc/time.cc', 'misc/time.h', + 'misc/time_linux.cc', 'misc/time_win.cc', 'misc/tri_state.h', 'misc/uuid.cc',