Skip to content

Commit 9727536

Browse files
fix(scopetimer): SCOPE_TIMER_IF object destructed early
1 parent 64e62df commit 9727536

2 files changed

Lines changed: 131 additions & 10 deletions

File tree

include/ScopeTimer.hpp

Lines changed: 27 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -97,6 +97,7 @@
9797
#include <cstring>
9898
#include <ctime>
9999
#include <mutex>
100+
#include <optional>
100101
#include <string>
101102
#include <string_view>
102103

@@ -553,6 +554,27 @@ namespace ewm::scopetimer {
553554
return v;
554555
}
555556
};
557+
558+
class ConditionalScopeTimer {
559+
public:
560+
template <typename LabelFactory>
561+
ConditionalScopeTimer(bool enabled, std::string_view where, LabelFactory&& labelFactory) noexcept {
562+
if (enabled) {
563+
timer_.emplace(where, labelFactory());
564+
} else {
565+
(void)where;
566+
}
567+
}
568+
569+
~ConditionalScopeTimer() = default;
570+
ConditionalScopeTimer(const ConditionalScopeTimer&) = delete;
571+
ConditionalScopeTimer& operator=(const ConditionalScopeTimer&) = delete;
572+
ConditionalScopeTimer(ConditionalScopeTimer&&) = delete;
573+
ConditionalScopeTimer& operator=(ConditionalScopeTimer&&) = delete;
574+
575+
private:
576+
std::optional<ScopeTimer> timer_;
577+
};
556578
} // namespace detail
557579

558580

@@ -605,8 +627,11 @@ namespace ewm::scopetimer {
605627
* @endcode
606628
*/
607629
#ifndef SCOPE_TIMER_IF
608-
#define SCOPE_TIMER_IF(cond, ...) \
609-
if (cond) SCOPE_TIMER(__VA_ARGS__)
630+
#define SCOPE_TIMER_IF(cond, ...) \
631+
::ewm::scopetimer::detail::ConditionalScopeTimer \
632+
ST_CAT(scopeTimerConditional__, ST_UNIQ)((cond), SCOPE_FUNCTION, [&]() noexcept { \
633+
return ::ewm::scopetimer::detail::LabelArg{ __VA_ARGS__ }.toStringView(); \
634+
})
610635
#endif
611636

612637
#else // Release build -> no-op

test/ScopeTimerTest.cpp

Lines changed: 104 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,8 @@
88
#include <sys/stat.h>
99
#include <unistd.h>
1010
#include <dirent.h>
11+
#include <fstream>
12+
#include <cerrno>
1113

1214
using namespace std::chrono_literals;
1315

@@ -27,6 +29,7 @@ class ScopeTimer_TestFriend {
2729
test_simple_scope();
2830
test_nested_scopes();
2931
test_conditional_timer();
32+
test_conditional_timer_spans_scope();
3033
test_looped_work();
3134
test_threaded();
3235
test_env_format_variants();
@@ -63,6 +66,47 @@ class ScopeTimer_TestFriend {
6366
std::this_thread::sleep_for(us);
6467
}
6568

69+
static double parseElapsedMillis(const std::string& line) {
70+
const std::string needle = "elapsed=";
71+
const auto pos = line.find(needle);
72+
if (pos == std::string::npos) {
73+
return -1.0;
74+
}
75+
const auto valuePos = pos + needle.size();
76+
const auto endPos = line.find_first_of(" \t\r\n", valuePos);
77+
const std::string token = line.substr(valuePos, endPos == std::string::npos ? std::string::npos : endPos - valuePos);
78+
79+
if (token.size() < 2 || token.substr(token.size() - 2) != "ms") {
80+
return -1.0;
81+
}
82+
83+
std::string numeric = token.substr(0, token.size() - 2);
84+
char* endPtr = nullptr;
85+
const double value = std::strtod(numeric.c_str(), &endPtr);
86+
if (!endPtr || *endPtr != '\0') {
87+
return -1.0;
88+
}
89+
return value;
90+
}
91+
92+
static double readElapsedMillisFromLog(const std::string& path, const std::string& label) {
93+
std::ifstream in(path);
94+
if (!in) {
95+
return -1.0;
96+
}
97+
std::string line;
98+
double latest = -1.0;
99+
while (std::getline(in, line)) {
100+
if (line.find(label) != std::string::npos) {
101+
const double candidate = parseElapsedMillis(line);
102+
if (candidate >= 0.0) {
103+
latest = candidate;
104+
}
105+
}
106+
}
107+
return latest;
108+
}
109+
66110
static std::string shellEscape(const std::string& s) {
67111
std::string out = "'";
68112
for (char c : s) {
@@ -108,6 +152,41 @@ class ScopeTimer_TestFriend {
108152
expect(true, "conditional timer executed");
109153
}
110154

155+
static void test_conditional_timer_spans_scope() {
156+
char templ[] = "/tmp/scopetimer_ifXXXXXX";
157+
char* dir = ::mkdtemp(templ);
158+
std::string tmpdir;
159+
bool cleanupDir = false;
160+
if (dir) {
161+
tmpdir = dir;
162+
cleanupDir = true;
163+
} else {
164+
tmpdir = "/tmp/scopetimer_if_fallback";
165+
if (::mkdir(tmpdir.c_str(), 0700) == 0 || errno == EEXIST) {
166+
cleanupDir = false; // do not remove shared fallback
167+
}
168+
}
169+
170+
const std::string logfile = tmpdir + "/ScopeTimer.log";
171+
std::remove(logfile.c_str());
172+
173+
int rc = run_child_with_env({
174+
{"SCOPETIMER_PROBE", "if_scope"},
175+
{"SCOPE_TIMER_DIR", tmpdir},
176+
{"SCOPE_TIMER_FORMAT", "MILLIS"},
177+
{"SCOPE_TIMER_FLUSH_N", "1"}
178+
});
179+
expect(rc == 0, "child process for conditional timer probe exited cleanly");
180+
181+
const double elapsedMs = readElapsedMillisFromLog(logfile, "tests:conditional:lifetime");
182+
expect(elapsedMs >= 5.0, "SCOPE_TIMER_IF spans enclosing scope");
183+
184+
std::remove(logfile.c_str());
185+
if (cleanupDir) {
186+
::rmdir(tmpdir.c_str());
187+
}
188+
}
189+
111190
static void test_looped_work() {
112191
SCOPE_TIMER("tests:looped:total");
113192
for (int i = 0; i < 1000; ++i) {
@@ -206,17 +285,34 @@ class ScopeTimer_TestFriend {
206285
// --- child process helpers (probe mode) ---
207286
static int child_probe_main_if_requested() {
208287
const char* probe = ::getenv("SCOPETIMER_PROBE");
209-
if (!probe || std::string(probe) != "1") return -1;
210-
SCOPE_TIMER("tests:child:probe");
211-
busyFor(100us);
212-
return 0;
288+
if (!probe) return -1;
289+
const std::string mode = probe;
290+
if (mode == "1") {
291+
SCOPE_TIMER("tests:child:probe");
292+
busyFor(100us);
293+
return 0;
294+
}
295+
if (mode == "if_scope") {
296+
SCOPE_TIMER_IF(true, "tests:conditional:lifetime");
297+
busyFor(20000us);
298+
return 0;
299+
}
300+
return -1;
213301
}
214302

215303
static int run_child_with_env(const std::vector<std::pair<std::string,std::string>>& envs) {
216-
std::string cmd;
217-
for (const auto& kv : envs) cmd += kv.first + "=" + kv.second + " ";
218-
cmd += shellEscape(s_exe_path);
219-
cmd = std::string("SCOPETIMER_PROBE=1 ") + cmd;
304+
std::string envBlock;
305+
bool probeSet = false;
306+
for (const auto& kv : envs) {
307+
if (kv.first == "SCOPETIMER_PROBE") {
308+
probeSet = true;
309+
}
310+
envBlock += kv.first + "=" + kv.second + " ";
311+
}
312+
if (!probeSet) {
313+
envBlock = std::string("SCOPETIMER_PROBE=1 ") + envBlock;
314+
}
315+
std::string cmd = envBlock + shellEscape(s_exe_path);
220316
cmd += " >/dev/null 2>&1";
221317
return std::system(cmd.c_str());
222318
}

0 commit comments

Comments
 (0)