Skip to content

Commit 66d8be6

Browse files
chhwangchhwang
committed
Optimized logger
1 parent 060c35f commit 66d8be6

File tree

2 files changed

+93
-148
lines changed

2 files changed

+93
-148
lines changed

‎src/include/logger.hpp‎

Lines changed: 81 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,8 @@
44
#ifndef MSCCLPP_LOGGER_HPP_
55
#define MSCCLPP_LOGGER_HPP_
66

7+
#include <unistd.h>
8+
79
#include <bitset>
810
#include <fstream>
911
#include <iomanip>
@@ -13,26 +15,72 @@
1315
#include <mscclpp/errors.hpp>
1416
#include <sstream>
1517
#include <string>
18+
#include <string_view>
1619

1720
namespace mscclpp {
1821

1922
typedef enum : unsigned int { NONE = 0, DEBUG, INFO, WARN, ERROR } LogLevel;
2023
typedef enum : std::size_t { ENV = 0, NET, CONN, EXEC, NCCL, COUNT } LogSubsys;
2124

2225
namespace detail {
23-
std::string guessRemoveProjectPrefix(const std::string& filePathStr);
26+
27+
constexpr std::string_view filenameFromPath(const char* path) {
28+
if (path == nullptr) return "";
29+
const char* last = path;
30+
for (const char* p = path; *p; ++p) {
31+
if (*p == '/' || *p == '\\') {
32+
last = p + 1; // character after separator
33+
}
34+
}
35+
return std::string_view(last);
36+
}
37+
38+
constexpr std::string_view logLevelToString(LogLevel level) {
39+
switch (level) {
40+
case LogLevel::NONE:
41+
return "NONE";
42+
case LogLevel::DEBUG:
43+
return "DEBUG";
44+
case LogLevel::INFO:
45+
return "INFO";
46+
case LogLevel::WARN:
47+
return "WARN";
48+
case LogLevel::ERROR:
49+
return "ERROR";
50+
default:
51+
return "UNKNOWN";
52+
}
53+
}
54+
55+
constexpr std::string_view logSubsysToString(LogSubsys subsys) {
56+
switch (subsys) {
57+
case LogSubsys::ENV:
58+
return "ENV";
59+
case LogSubsys::NET:
60+
return "NET";
61+
case LogSubsys::CONN:
62+
return "CONN";
63+
case LogSubsys::EXEC:
64+
return "EXEC";
65+
case LogSubsys::NCCL:
66+
return "NCCL";
67+
case LogSubsys::COUNT:
68+
return "ALL";
69+
default:
70+
return "UNKNOWN";
71+
}
72+
}
73+
2474
std::string timestamp(const char* format = "%Y-%m-%d %X");
25-
std::string logLevelToString(LogLevel level);
26-
std::string logSubsysToString(LogSubsys subsys);
27-
int pid();
75+
2876
} // namespace detail
2977

3078
// Bitset holding enabled subsystems.
3179
using LogSubsysSet = std::bitset<static_cast<std::size_t>(LogSubsys::COUNT)>;
3280

3381
class Logger {
3482
private:
35-
// Overload only for string literals: const char(&)[N]
83+
// Overload for string literals: const char(&)[N]
3684
template <std::size_t N>
3785
std::string toStringHelper(const char (&value)[N]) const {
3886
// N includes the terminating '\0'; std::string(value) stops at '\0'
@@ -41,7 +89,9 @@ class Logger {
4189

4290
template <typename T>
4391
std::string toStringHelper(T&& value) const {
44-
if constexpr (std::is_same_v<std::decay_t<T>, std::string>) {
92+
if constexpr (std::is_same_v<std::decay_t<T>, std::string_view>) {
93+
return std::string(value);
94+
} else if constexpr (std::is_same_v<std::decay_t<T>, std::string>) {
4595
return std::forward<T>(value);
4696
} else if constexpr (std::is_arithmetic_v<std::decay_t<T>>) {
4797
return std::to_string(value);
@@ -77,11 +127,12 @@ class Logger {
77127

78128
void setDelimiter(char delimiter) { delimiter_ = delimiter; }
79129

80-
template <bool NewLine, typename... Args>
81-
std::string message(LogLevel level, LogSubsys subsys, Args&&... args) {
82-
if (level < level_) return "";
83-
if (!subsysSet_.test(static_cast<std::size_t>(subsys))) return "";
130+
inline bool shouldLog(LogLevel level, LogSubsys subsys) const {
131+
return level >= level_ && subsysSet_.test(static_cast<std::size_t>(subsys));
132+
}
84133

134+
template <bool NewLine, typename... Args>
135+
std::string message(Args&&... args) {
85136
if (sizeof...(args) == 0) {
86137
if constexpr (NewLine) {
87138
return header_ + "\n";
@@ -121,8 +172,8 @@ class Logger {
121172
}
122173

123174
template <typename... Args>
124-
void log(LogLevel level, LogSubsys subsys, Args&&... args) {
125-
auto msg = message<true>(level, subsys, std::forward<Args>(args)...);
175+
void log(Args&&... args) {
176+
auto msg = message<true>(std::forward<Args>(args)...);
126177
if (msg.empty()) return;
127178
if (logFileStream_.is_open()) {
128179
logFileStream_ << msg;
@@ -138,28 +189,31 @@ Logger& logger(const std::string& header, const std::string& level, char delimit
138189

139190
} // namespace mscclpp
140191

141-
#define LOGGER_LOG(level__, subsys__, ...) \
142-
do { \
143-
::mscclpp::logger("%@ %@ %@ %@ %@ %@:%@ ", ::mscclpp::env()->logLevel, 0) \
144-
.log(level__, subsys__, ::mscclpp::detail::timestamp(), "MSCCLPP", ::mscclpp::detail::pid(), \
145-
::mscclpp::detail::logLevelToString(level__), ::mscclpp::detail::logSubsysToString(subsys__), \
146-
::mscclpp::detail::guessRemoveProjectPrefix(__FILE__), __LINE__, __VA_ARGS__); \
192+
// Helper to build log message arguments
193+
#define LOGGER_BUILD_ARGS(level__, subsys__, ...) \
194+
::mscclpp::detail::timestamp(), "MSCCLPP", ::getpid(), ::mscclpp::detail::logLevelToString(level__), \
195+
::mscclpp::detail::logSubsysToString(subsys__), ::mscclpp::detail::filenameFromPath(__FILE__), __LINE__, \
196+
__VA_ARGS__
197+
198+
#define LOGGER_LOG(level__, subsys__, ...) \
199+
do { \
200+
auto& logger__ = ::mscclpp::logger("%@ %@ %@ %@ %@ %@:%@ ", ::mscclpp::env()->logLevel, 0); \
201+
if (logger__.shouldLog(level__, subsys__)) { \
202+
logger__.log(LOGGER_BUILD_ARGS(level__, subsys__, __VA_ARGS__)); \
203+
} \
147204
} while (0)
148205

149206
#define LOG(level__, subsys__, ...) LOGGER_LOG(level__, subsys__, __VA_ARGS__)
150207
#define DEBUG(subsys__, ...) LOGGER_LOG(::mscclpp::LogLevel::DEBUG, subsys__, __VA_ARGS__)
151208
#define INFO(subsys__, ...) LOGGER_LOG(::mscclpp::LogLevel::INFO, subsys__, __VA_ARGS__)
152209
#define WARN(subsys__, ...) LOGGER_LOG(::mscclpp::LogLevel::WARN, subsys__, __VA_ARGS__)
153210
#define ERROR(subsys__, ...) LOGGER_LOG(::mscclpp::LogLevel::ERROR, subsys__, __VA_ARGS__)
154-
#define THROW(subsys__, exception__, errorCode__, ...) \
155-
do { \
156-
const auto errorCodeCopy__ = errorCode__; \
157-
throw exception__( \
158-
::mscclpp::logger("%@ %@ %@ %@ %@ %@:%@ ", ::mscclpp::env()->logLevel, 0) \
159-
.message<false>(::mscclpp::LogLevel::ERROR, subsys__, ::mscclpp::detail::timestamp(), "MSCCLPP", \
160-
::mscclpp::detail::pid(), "ERROR", ::mscclpp::detail::logSubsysToString(subsys__), \
161-
::mscclpp::detail::guessRemoveProjectPrefix(__FILE__), __LINE__, __VA_ARGS__), \
162-
errorCodeCopy__); \
211+
#define THROW(subsys__, exception__, errorCode__, ...) \
212+
do { \
213+
const auto errorCodeCopy__ = errorCode__; \
214+
throw exception__(::mscclpp::logger("%@ %@ %@ %@ %@ %@:%@ ", ::mscclpp::env()->logLevel, 0) \
215+
.message<false>(LOGGER_BUILD_ARGS(::mscclpp::LogLevel::ERROR, subsys__, __VA_ARGS__)), \
216+
errorCodeCopy__); \
163217
} while (0)
164218

165219
#endif // MSCCLPP_LOGGER_HPP_

‎src/logger.cc‎

Lines changed: 12 additions & 121 deletions
Original file line numberDiff line numberDiff line change
@@ -3,12 +3,9 @@
33

44
#include "logger.hpp"
55

6-
#include <unistd.h>
7-
86
#include <algorithm>
97
#include <chrono>
108
#include <ctime>
11-
#include <filesystem>
129
#include <fstream>
1310
#include <mutex>
1411

@@ -76,141 +73,35 @@ static LogSubsysSet stringToLogSubsysSet(const std::string& subsysStr) {
7673

7774
namespace detail {
7875

79-
// Return the full path of the detected project root directory, or empty string if not found.
80-
static std::filesystem::path guessFindProjectRoot(const std::filesystem::path& filePath) {
81-
const std::string rootIndicators[] = {".git", "VERSION", "README.md"};
82-
83-
// Start from the directory containing the file
84-
std::filesystem::path currentDir = filePath.parent_path();
85-
if (currentDir.empty()) return {};
86-
87-
// Walk up the directory tree towards root
88-
while (!currentDir.empty() && currentDir != currentDir.root_path()) {
89-
bool foundRoot = false;
90-
for (const auto& indicator : rootIndicators) {
91-
std::filesystem::path potential = currentDir / indicator;
92-
std::error_code ec; // non-throwing exists
93-
if (std::filesystem::exists(potential, ec)) {
94-
foundRoot = true;
95-
break;
96-
}
97-
}
98-
if (foundRoot) {
99-
return currentDir; // Found root directory path
100-
}
101-
currentDir = currentDir.parent_path();
102-
}
103-
return {}; // Not found
104-
}
105-
106-
// Remove the project root prefix (including trailing '/') from filePath if present.
107-
static std::string removeProjectRootPrefix(const std::filesystem::path& filePath,
108-
const std::filesystem::path& projectRoot) {
109-
if (projectRoot.empty()) return filePath.generic_string();
110-
111-
std::error_code ec;
112-
std::filesystem::path rel = std::filesystem::relative(filePath, projectRoot, ec);
113-
if (!ec && !rel.empty()) {
114-
std::string relStr = rel.generic_string();
115-
if (!(relStr.size() >= 2 && relStr[0] == '.' && relStr[1] == '.')) {
116-
return relStr; // Within project root.
117-
}
118-
}
119-
120-
// Fallback: not within project root.
121-
return filePath.generic_string();
122-
}
123-
124-
static std::filesystem::path globalProjectRoot;
125-
static std::mutex globalProjectRootMutex;
126-
127-
std::string guessRemoveProjectPrefix(const std::string& filePathStr) {
128-
std::filesystem::path filePath(filePathStr);
129-
if (globalProjectRoot.empty()) {
130-
std::lock_guard<std::mutex> lock(globalProjectRootMutex);
131-
if (globalProjectRoot.empty()) {
132-
auto candidate = guessFindProjectRoot(filePath);
133-
if (!candidate.empty()) {
134-
globalProjectRoot = std::move(candidate);
135-
}
136-
}
137-
}
138-
return removeProjectRootPrefix(filePath, globalProjectRoot);
139-
}
140-
14176
std::string timestamp(const char* format) {
142-
// Thread-safe per-second UTC timestamp cache.
77+
// Thread-local per-second UTC timestamp cache.
14378
struct TimeCache {
144-
time_t second;
145-
std::string str;
79+
time_t second = 0;
80+
char buf[32];
81+
size_t len = 0;
14682
};
147-
static std::shared_ptr<const TimeCache> cachePtr; // guarded by cacheMutex
148-
static std::mutex cacheMutex;
83+
thread_local TimeCache cache;
14984

15085
auto now = std::chrono::system_clock::now();
15186
time_t currentTime = std::chrono::system_clock::to_time_t(now);
15287

153-
{
154-
std::lock_guard<std::mutex> lock(cacheMutex);
155-
if (cachePtr && cachePtr->second == currentTime) {
156-
return cachePtr->str; // Safe stale/current value.
157-
}
88+
// Fast path: return cached string if still in the same second
89+
if (cache.second == currentTime && cache.len > 0) {
90+
return std::string(cache.buf, cache.len);
15891
}
15992

160-
// Build new formatted timestamp (UTC) for this second.
93+
// Slow path: format new timestamp (happens at most once per second per thread)
16194
std::tm tmBuf;
16295
if (::gmtime_r(&currentTime, &tmBuf) == nullptr) {
16396
return ""; // Conversion failure fallback.
16497
}
165-
std::stringstream ss;
166-
ss << std::put_time(&tmBuf, format);
167-
auto newCache = std::make_shared<TimeCache>(TimeCache{currentTime, ss.str()});
168-
169-
{
170-
std::lock_guard<std::mutex> lock(cacheMutex);
171-
cachePtr = std::move(newCache);
172-
return cachePtr->str;
173-
}
174-
}
17598

176-
std::string logLevelToString(LogLevel level) {
177-
switch (level) {
178-
case LogLevel::NONE:
179-
return "NONE";
180-
case LogLevel::DEBUG:
181-
return "DEBUG";
182-
case LogLevel::INFO:
183-
return "INFO";
184-
case LogLevel::WARN:
185-
return "WARN";
186-
case LogLevel::ERROR:
187-
return "ERROR";
188-
default:
189-
return "UNKNOWN";
190-
}
191-
}
99+
cache.len = ::strftime(cache.buf, sizeof(cache.buf), format, &tmBuf);
100+
cache.second = currentTime;
192101

193-
std::string logSubsysToString(LogSubsys subsys) {
194-
switch (subsys) {
195-
case LogSubsys::ENV:
196-
return "ENV";
197-
case LogSubsys::NET:
198-
return "NET";
199-
case LogSubsys::CONN:
200-
return "CONN";
201-
case LogSubsys::EXEC:
202-
return "EXEC";
203-
case LogSubsys::NCCL:
204-
return "NCCL";
205-
case LogSubsys::COUNT:
206-
return "ALL"; // COUNT isn't a subsystem; treat only if misused.
207-
default:
208-
return "UNKNOWN";
209-
}
102+
return std::string(cache.buf, cache.len);
210103
}
211104

212-
int pid() { return static_cast<int>(::getpid()); }
213-
214105
} // namespace detail
215106

216107
static std::once_flag globalLoggerInitFlag;

0 commit comments

Comments
 (0)