Follow-up to #27233
The current FormatISO8601DateTime function will return an empty string if it encounters an error when converting the int64_t seconds-since-epoch to a formatted date time. In the unlikely case that happens, here strStamped.pop_back() would be undefined behavior.
<!--e57a25ab6845829454e8d69fc972939a-->
The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.
<!--021abf342d371248e50ceaed478a90ca-->
See the guideline for information on the review process.
| Type | Reviewers |
|---|---|
| ACK | stickies-v, MarcoFalke |
If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.
The current `FormatISO8601DateTime` function will
return an empty string if it encounters an error
when converting the `int64_t` seconds since epoch
to a formatted date time. In the unlikely case that happens,
`strStamped.pop_back()` would be undefined behavior.
351 | @@ -352,9 +352,13 @@ std::string BCLog::Logger::LogTimestampStr(const std::string& str) 352 | const auto now{SystemClock::now()}; 353 | const auto now_seconds{std::chrono::time_point_cast<std::chrono::seconds>(now)}; 354 | strStamped = FormatISO8601DateTime(TicksSinceEpoch<std::chrono::seconds>(now_seconds)); 355 | - if (m_log_time_micros) { 356 | - strStamped.pop_back(); 357 | - strStamped += strprintf(".%06dZ", Ticks<std::chrono::microseconds>(now - now_seconds)); 358 | + if (strStamped.empty()) { 359 | + strStamped = "Error obtaining current timestamp";
This should never happen, so instead of adding dead code, what about simply combining the two if conditions?
My thinking was that if it never happens, then this PR is unnecessary. If it could happen, then I'd rather have an explicit message rather than output that entirely lacks timestamps, which someone may not notice is bizarre.
Happy to change it, though, if people prefer your approach.
Assuming it can happen, maybe wrap the message in, say, square brackets ("[Error obtaining current timestamp]") to be clearer in the log.
I think I've already come around to the view that it's so unlikely as to be not worth the additional LoC, so I'll switch to the simpler version.
Thanks!
I've seen this happening to computers before, but never when bitcoind was running. Usually that happens when time synchronization goes wrong for whatever reason.
If there are steps to reproduce this, it would be good to write a detection for it at Bitcoin Core init time and refuse to start the program (if this isn't already done).
351 | @@ -352,7 +352,7 @@ std::string BCLog::Logger::LogTimestampStr(const std::string& str) 352 | const auto now{SystemClock::now()}; 353 | const auto now_seconds{std::chrono::time_point_cast<std::chrono::seconds>(now)}; 354 | strStamped = FormatISO8601DateTime(TicksSinceEpoch<std::chrono::seconds>(now_seconds)); 355 | - if (m_log_time_micros) { 356 | + if (m_log_time_micros && !strStamped.empty()) {
Could wrap this in an Assume() to both make it clear to the reader that it's not supposed to happen and easier to catch any (very unexpected) bugs without crashing non-development builds?
if (m_log_time_micros && Assume(!strStamped.empty())) {
ACK 73f4eb511cf80cf52b78627347727ca02774b731
lgtm ACK 73f4eb511cf80cf52b78627347727ca02774b731
