Skip to content

Commit

Permalink
[#18855] Add functions for formatting a CoarseTimePoint relative to t…
Browse files Browse the repository at this point in the history
…he current time

Summary: Add functions for formatting a CoarseTimePoint relative to the current time. Useful for logging deadlines.

Test Plan: Jenkins

Reviewers: kpopali

Reviewed By: kpopali

Subscribers: ybase, yql

Differential Revision: https://phorge.dev.yugabyte.com/D28085
  • Loading branch information
mbautin committed Aug 29, 2023
1 parent f600580 commit a5ba08f
Show file tree
Hide file tree
Showing 6 changed files with 53 additions and 3 deletions.
3 changes: 2 additions & 1 deletion src/yb/docdb/deadline_info.cc
Original file line number Diff line number Diff line change
Expand Up @@ -43,8 +43,9 @@ Status DeadlineInfo::CheckDeadlinePassed() {
}

std::string DeadlineInfo::ToString() const {
auto now = CoarseMonoClock::now();
return Format("{ now: $0 deadline: $1 counter: $2 }",
CoarseMonoClock::now(), deadline_, counter_);
now, ToStringRelativeToNow(deadline_, now), counter_);
}

void SimulateTimeoutIfTesting(CoarseTimePoint* deadline) {
Expand Down
3 changes: 2 additions & 1 deletion src/yb/rpc/connection.cc
Original file line number Diff line number Diff line change
Expand Up @@ -206,7 +206,8 @@ void Connection::HandleTimeout(ev::timer& watcher, int revents) { // NOLINT
const MonoDelta timeout = FLAGS_rpc_connection_timeout_ms * 1ms;
auto current_last_activity_time = last_activity_time();
deadline = current_last_activity_time + timeout;
DVLOG_WITH_PREFIX(5) << Format("now: $0, deadline: $1, timeout: $2", now, deadline, timeout);
DVLOG_WITH_PREFIX(5) << Format(
"now: $0, deadline: $1, timeout: $2", now, ToStringRelativeToNow(deadline, now), timeout);
if (now > deadline) {
auto passed = reactor_->cur_time() - current_last_activity_time;
reactor_->DestroyConnection(
Expand Down
2 changes: 1 addition & 1 deletion src/yb/rpc/yb_rpc.cc
Original file line number Diff line number Diff line change
Expand Up @@ -230,7 +230,7 @@ void YBInboundConnectionContext::HandleTimeout(ev::timer& watcher, int revents)
// for sending is still in queue due to RPC/networking issues, so no need to queue
// another one.
VLOG(4) << connection->ToString() << ": " << "Sending heartbeat, now: " << AsString(now)
<< ", deadline: " << AsString(deadline)
<< ", deadline: " << ToStringRelativeToNow(deadline, now)
<< ", last_write_time_: " << AsString(last_write_time_)
<< ", last_heartbeat_sending_time_: " << AsString(last_heartbeat_sending_time_);
auto queuing_status = connection->QueueOutboundData(HeartbeatOutboundData::Instance());
Expand Down
16 changes: 16 additions & 0 deletions src/yb/util/monotime-test.cc
Original file line number Diff line number Diff line change
Expand Up @@ -269,4 +269,20 @@ TEST(TestMonoTime, TestSubtractDelta) {
ASSERT_EQ(start_copy + delta, start);
}

TEST(TestMonoTime, ToStringRelativeToNow) {
auto now = CoarseMonoClock::Now();

auto t = now + 2s;
ASSERT_EQ(Format("$0 (2.000s from now)", t), ToStringRelativeToNow(t, now));
ASSERT_EQ("2.000s from now", ToStringRelativeToNowOnly(t, now));

t = now;
ASSERT_EQ(Format("$0 (now)", t), ToStringRelativeToNow(t, now));
ASSERT_EQ("now", ToStringRelativeToNowOnly(t, now));

t = now - 2s;
ASSERT_EQ(Format("$0 (2.000s ago)", t), ToStringRelativeToNow(t, now));
ASSERT_EQ("2.000s ago", ToStringRelativeToNowOnly(t, now));
}

} // namespace yb
20 changes: 20 additions & 0 deletions src/yb/util/monotime.cc
Original file line number Diff line number Diff line change
Expand Up @@ -423,4 +423,24 @@ bool IsInitialized(CoarseTimePoint time_point) {
return MonoDelta(time_point.time_since_epoch()).Initialized();
}

std::string ToStringRelativeToNow(CoarseTimePoint t, CoarseTimePoint now) {
return Format("$0 ($1)", t, ToStringRelativeToNowOnly(t, now));
}

std::string ToStringRelativeToNow(CoarseTimePoint t, std::optional<CoarseTimePoint> now) {
if (now)
return ToStringRelativeToNow(t, *now);
return ToString(t);
}

std::string ToStringRelativeToNowOnly(CoarseTimePoint t, CoarseTimePoint now) {
if (t < now) {
return Format("$0 ago", now - t);
}
if (t > now) {
return Format("$0 from now", t - now);
}
return Format("now");
}

} // namespace yb
12 changes: 12 additions & 0 deletions src/yb/util/monotime.h
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@

#include <chrono>
#include <cstdint>
#include <optional>
#include <string>

#include <gtest/gtest_prod.h>
Expand Down Expand Up @@ -356,4 +357,15 @@ std::chrono::steady_clock::time_point ToSteady(CoarseTimePoint time_point);

bool IsInitialized(CoarseTimePoint time_point);

// Formats the given time point in the form "<time> (<relation_to_now>)" where <relation_to_now>
// is either "<interval> from now" or "<interval> ago", depending on whether the given point in
// time is before or after the current moment, passed in as "now".
std::string ToStringRelativeToNow(CoarseTimePoint t, CoarseTimePoint now);

// The same as above but skips the relative part if `now` is not specified.
std::string ToStringRelativeToNow(CoarseTimePoint t, std::optional<CoarseTimePoint> now);

// The same as above, but only returns the part in parentheses, without the parentheses.
std::string ToStringRelativeToNowOnly(CoarseTimePoint t, CoarseTimePoint now);

} // namespace yb

0 comments on commit a5ba08f

Please sign in to comment.