Fix undefined behaviour in `aos/time/time.cc`
We're currently seeing the following undefined behaviour in the code
that converts `realtime_clock::time_point` values into human-readable
strings. The issue is that the computation overflows what we can
represent in 64 bits when stringifying `realtime_clock::min_time`.
$ bazel test --config=ubsan @aos//aos/events/logging:logfile_utils_test --test_filter=PartsMessageReaderDeathTest.TooFarOutOfOrder --test_output=streamed --test_env=UBSAN_SYMBOLIZER_PATH="$(readlink -f external/llvm_k8/bin/llvm-symbolizer)"
...
[ RUN ] PartsMessageReaderDeathTest.TooFarOutOfOrder
external/aos/aos/events/logging/logfile_utils_test.cc:169: Failure
Death test: { reader.ReadMessage(); }
Result: died but not with expected error.
Expected: contains regular expression "-0.000000001sec vs. 0.000000000sec"
Actual msg:
[ DEATH ] external/llvm_k8/include/c++/v1/__chrono/duration.h:102:59: runtime error: signed integer overflow: -9223372037 * 1000000000 cannot be represented in type '_Ct' (aka 'long long')
...
[ DEATH ] #4 0x7f6788f54d9a in aos::operator<<(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, std::__1::chrono::time_point<aos::realtime_clock, std::__1::chrono::duration<long long, std::__1::ratio<1l, 1000000000l>>> const&) external/aos/aos/time/time.cc:189:55
[ DEATH ] #5 0x7f67938da571 in aos::logger::operator<<(std::__1::basic_ostream<char, std::__1::char_traits<char>>&, aos::logger::LogParts const&) external/aos/aos/events/logging/logfile_sorting.cc:2163:50
[ DEATH ] #6 0x7f6793aeec53 in aos::logger::PartsMessageReader::ReadMessage() external/aos/aos/events/logging/logfile_utils.cc:1679:32
[ DEATH ] #7 0x55ed45105cb0 in aos::logger::testing::PartsMessageReaderDeathTest_TooFarOutOfOrder_Test::TestBody() external/aos/aos/events/logging/logfile_utils_test.cc:169:3
...
[ DEATH ]
[ DEATH ] SUMMARY: UndefinedBehaviorSanitizer: undefined-behavior external/llvm_k8/include/c++/v1/__chrono/duration.h:102:59 in
[ DEATH ]
[ FAILED ] PartsMessageReaderDeathTest.TooFarOutOfOrder (200 ms)
[----------] 1 test from PartsMessageReaderDeathTest (200 ms total)
This patch fixes the issue by detecting potential overflow and return
a mostly non-human-readable string version of the time stamp.
Change-Id: I4bff6272ac6f4d48c646face2c13fbc7dd3bb0ed
Signed-off-by: James Kuszmaul <james.kuszmaul@bluerivertech.com>
diff --git a/aos/time/time.cc b/aos/time/time.cc
index 6a25aa9..db71379 100644
--- a/aos/time/time.cc
+++ b/aos/time/time.cc
@@ -170,6 +170,16 @@
: std::chrono::duration_cast<std::chrono::seconds>(
now.time_since_epoch());
+ // We can run into some corner cases where the seconds value is large enough
+ // to cause the conversion to nanoseconds to overflow. That is undefined
+ // behaviour so we prevent it with this check here.
+ if (int64_t result;
+ __builtin_mul_overflow(seconds.count(), 1'000'000'000, &result)) {
+ stream << "(unrepresentable realtime " << now.time_since_epoch().count()
+ << ")";
+ return stream;
+ }
+
std::time_t seconds_t = seconds.count();
stream << std::put_time(localtime_r(&seconds_t, &tm), "%Y-%m-%d_%H-%M-%S.")
<< std::setfill('0') << std::setw(9)
diff --git a/aos/time/time_test.cc b/aos/time/time_test.cc
index 63a145b..e8b7153 100644
--- a/aos/time/time_test.cc
+++ b/aos/time/time_test.cc
@@ -208,8 +208,9 @@
std::stringstream s;
s << t;
- EXPECT_EQ(s.str(), "1677-09-21_00-12-43.145224192");
- EXPECT_EQ(realtime_clock::FromString(s.str()).value(), t);
+ // min_time happens to be unrepresentable because of rounding and signed
+ // integer overflow.
+ EXPECT_EQ(s.str(), "(unrepresentable realtime -9223372036854775808)");
}
{