Skip to content

Commit dd2bdcd

Browse files
Fix/logging snprintf negative time 4556 (#4593)
Closes #4556 ## What's new? 1. Updated input_timestamp() to correctly handle future timestamps. 2. Replaced the buggy modulo logic—which produced confusing "double negative" strings like -100.-500ms ago—with absolute duration calculations. 3. Added a contextual suffix (ago vs in future) to make the logs human-readable regardless of clock drift or event timing. (No negative sign would be printed for future timestamps). Past values will be printed like - `500 ms ago` Future values will be printed like - `100 ms in future` ## How to test Added unit tests for the function, run `./bin/mir_unit_tests --gtest_filter=TimestampTest.*` and verify. ## Checklist - [ ✅] Tests added and pass - [ ✅] Adequate documentation added
2 parents 5204e94 + 7084aee commit dd2bdcd

File tree

3 files changed

+61
-2
lines changed

3 files changed

+61
-2
lines changed

src/common/logging/input_timestamp.cpp

Lines changed: 9 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@
1616

1717
#include <mir/logging/input_timestamp.h>
1818
#include <cstdio>
19+
#include <cstdlib>
1920

2021
using namespace std::chrono;
2122
std::string mir::logging::input_timestamp(nanoseconds when)
@@ -26,9 +27,15 @@ std::string mir::logging::input_timestamp(nanoseconds when)
2627
long long const now_ns = duration_cast<nanoseconds>(now).count();
2728
long long const age_ns = now_ns - when_ns;
2829

30+
long long const abs_age_ns = std::llabs(age_ns);
31+
long long const milliseconds = abs_age_ns / 1000000LL;
32+
long long const sub_milliseconds = abs_age_ns % 1000000LL;
33+
34+
char const* sign_suffix = (age_ns < 0) ? "in the future" : "ago";
35+
2936
char str[64];
30-
snprintf(str, sizeof str, "%lld (%lld.%06lldms ago)",
31-
when_ns, age_ns / 1000000LL, age_ns % 1000000LL);
37+
snprintf(str, sizeof str, "%lld (%lld.%06lldms %s)",
38+
when_ns, milliseconds, sub_milliseconds, sign_suffix);
3239

3340
return std::string(str);
3441
}
Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
list(APPEND UNIT_TEST_SOURCES
22
${CMAKE_CURRENT_SOURCE_DIR}/test_display_report.cpp
33
${CMAKE_CURRENT_SOURCE_DIR}/test_compositor_report.cpp
4+
${CMAKE_CURRENT_SOURCE_DIR}/test_input_timestamp.cpp
45
)
56

67
set(UNIT_TEST_SOURCES ${UNIT_TEST_SOURCES} PARENT_SCOPE)
Lines changed: 51 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,51 @@
1+
/*
2+
* Copyright © Canonical Ltd.
3+
*
4+
* This program is free software: you can redistribute it and/or modify it
5+
* under the terms of the GNU General Public License version 2 or 3,
6+
* as published by the Free Software Foundation.
7+
*
8+
* This program is distributed in the hope that it will be useful,
9+
* but WITHOUT ANY WARRANTY; without even the implied warranty of
10+
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
11+
* GNU General Public License for more details.
12+
*
13+
* You should have received a copy of the GNU General Public License
14+
* along with this program. If not, see <http://www.gnu.org/licenses/>.
15+
*/
16+
17+
#include <mir/logging/input_timestamp.h>
18+
19+
#include <gtest/gtest.h>
20+
#include <gmock/gmock.h>
21+
#include <chrono>
22+
#include <string>
23+
24+
using namespace std::chrono;
25+
using namespace std::chrono_literals;
26+
using namespace testing;
27+
namespace ml = mir::logging;
28+
29+
TEST(TimestampTest, past_time_is_correctly_formatted)
30+
{
31+
auto const past_event = steady_clock::now().time_since_epoch() - 500ms;
32+
33+
std::string out = ml::input_timestamp(past_event);
34+
35+
EXPECT_THAT(out, Not(HasSubstr(".-")));
36+
EXPECT_THAT(out, HasSubstr("500.0"));
37+
EXPECT_THAT(out, HasSubstr("ms ago"));
38+
}
39+
40+
TEST(TimestampTest, future_time_is_correctly_formatted)
41+
{
42+
auto const future_event = steady_clock::now().time_since_epoch() + 1000ms + 10us;
43+
44+
std::string out = ml::input_timestamp(future_event);
45+
46+
EXPECT_THAT(out, Not(HasSubstr(".-")));
47+
EXPECT_THAT(out, HasSubstr("in the future"));
48+
EXPECT_THAT(out, HasSubstr("1000.0"));
49+
EXPECT_THAT(out, HasSubstr("ms"));
50+
51+
}

0 commit comments

Comments
 (0)