From 57101c62793aeeaf295d619ca642c045bdff66fb Mon Sep 17 00:00:00 2001 From: Christopher Erb Date: Thu, 30 Oct 2025 20:46:29 +0000 Subject: [PATCH 1/5] add timestamp option for logger --- projects/miopen/src/logger.cpp | 18 ++++++++++++++++++ 1 file changed, 18 insertions(+) diff --git a/projects/miopen/src/logger.cpp b/projects/miopen/src/logger.cpp index 5d75abad8d00..e057b3ee761f 100644 --- a/projects/miopen/src/logger.cpp +++ b/projects/miopen/src/logger.cpp @@ -56,6 +56,8 @@ MIOPEN_DECLARE_ENV_VAR_BOOL(MIOPEN_ENABLE_LOGGING_MPMT) /// Add timestamps to each log line. /// Not useful with multi-process/multi-threaded apps. MIOPEN_DECLARE_ENV_VAR_BOOL(MIOPEN_ENABLE_LOGGING_ELAPSED_TIME) +/// Add timestamps to each log line. +MIOPEN_DECLARE_ENV_VAR_BOOL(MIOPEN_ENABLE_LOGGING_DATE_TIME) /// See LoggingLevel in the header. MIOPEN_DECLARE_ENV_VAR_UINT64(MIOPEN_LOG_LEVEL) @@ -117,6 +119,18 @@ inline float GetTimeDiff() return rv; } +inline std::string GetDateTimeMs() +{ + auto now = std::chrono::system_clock::now(); + auto ms = std::chrono::duration_cast(now.time_since_epoch()) % 1000; + auto now_t = std::chrono::system_clock::to_time_t(now); + std::tm local_time = *std::localtime(&now_t); + std::ostringstream time_s; + time_s << std::put_time(&local_time, "%Y-%m-%d %H:%M:%S"); + time_s << ":"<< std::setfill('0') << std::setw(3) << ms.count(); + return time_s.str(); +} + } // namespace bool IsLoggingDebugQuiet() @@ -195,6 +209,10 @@ std::string LoggingPrefix() { ss << std::fixed << std::setprecision(3) << std::setw(8) << GetTimeDiff(); } + if(env::enabled(MIOPEN_ENABLE_LOGGING_DATE_TIME)) + { + ss << " (" << GetDateTimeMs() << ")"; + } ss << ": "; return ss.str(); } From a449939cd85af5c8315919c7dc710198015e849a Mon Sep 17 00:00:00 2001 From: Christopher Erb Date: Thu, 30 Oct 2025 23:45:15 +0000 Subject: [PATCH 2/5] update time to ISO 8601 format --- projects/miopen/src/logger.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/projects/miopen/src/logger.cpp b/projects/miopen/src/logger.cpp index e057b3ee761f..67d351b2e4cd 100644 --- a/projects/miopen/src/logger.cpp +++ b/projects/miopen/src/logger.cpp @@ -126,8 +126,8 @@ inline std::string GetDateTimeMs() auto now_t = std::chrono::system_clock::to_time_t(now); std::tm local_time = *std::localtime(&now_t); std::ostringstream time_s; - time_s << std::put_time(&local_time, "%Y-%m-%d %H:%M:%S"); - time_s << ":"<< std::setfill('0') << std::setw(3) << ms.count(); + time_s << std::put_time(&local_time, "%Y-%m-%dT%H:%M:%S"); + time_s << "." << std::setfill('0') << std::setw(3) << ms.count() << "Z"; return time_s.str(); } From 83134c82dcd702f00567ed8286facf8c1cd9e50b Mon Sep 17 00:00:00 2001 From: Christopher Erb Date: Thu, 30 Oct 2025 23:58:35 +0000 Subject: [PATCH 3/5] add env note to docs --- projects/miopen/docs/how-to/debug-log.rst | 3 +++ 1 file changed, 3 insertions(+) diff --git a/projects/miopen/docs/how-to/debug-log.rst b/projects/miopen/docs/how-to/debug-log.rst index d128302ee44a..898a86b87bdf 100644 --- a/projects/miopen/docs/how-to/debug-log.rst +++ b/projects/miopen/docs/how-to/debug-log.rst @@ -43,6 +43,9 @@ environmental variables to control logging. Both variables are disabled by defau * ``MIOPEN_ENABLE_LOGGING_ELAPSED_TIME``: Adds a timestamp to each log line that indicates the time elapsed (in milliseconds) since the previous log message. +* ``MIOPEN_ENABLE_LOGGING_DATE_TIME``: Adds a timestamp to each log line that indicates the + system time (with milliseconds). + .. note:: If you require technical support, include the console log that is produced from these settings: From b46b2868e214c40eee1c53a1ce3940921430685a Mon Sep 17 00:00:00 2001 From: Christopher Erb Date: Fri, 31 Oct 2025 18:36:14 +0000 Subject: [PATCH 4/5] clang format --- projects/miopen/src/logger.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/projects/miopen/src/logger.cpp b/projects/miopen/src/logger.cpp index 67d351b2e4cd..2e735344684a 100644 --- a/projects/miopen/src/logger.cpp +++ b/projects/miopen/src/logger.cpp @@ -122,8 +122,8 @@ inline float GetTimeDiff() inline std::string GetDateTimeMs() { auto now = std::chrono::system_clock::now(); - auto ms = std::chrono::duration_cast(now.time_since_epoch()) % 1000; - auto now_t = std::chrono::system_clock::to_time_t(now); + auto ms = std::chrono::duration_cast(now.time_since_epoch()) % 1000; + auto now_t = std::chrono::system_clock::to_time_t(now); std::tm local_time = *std::localtime(&now_t); std::ostringstream time_s; time_s << std::put_time(&local_time, "%Y-%m-%dT%H:%M:%S"); From e00ba411f401b3d9c838d24c83d925836129bc4d Mon Sep 17 00:00:00 2001 From: Christopher Erb Date: Fri, 31 Oct 2025 19:55:53 +0000 Subject: [PATCH 5/5] update timer for thread safety --- projects/miopen/src/logger.cpp | 13 +++++++++++-- 1 file changed, 11 insertions(+), 2 deletions(-) diff --git a/projects/miopen/src/logger.cpp b/projects/miopen/src/logger.cpp index 2e735344684a..d7b5ba5be159 100644 --- a/projects/miopen/src/logger.cpp +++ b/projects/miopen/src/logger.cpp @@ -123,8 +123,17 @@ inline std::string GetDateTimeMs() { auto now = std::chrono::system_clock::now(); auto ms = std::chrono::duration_cast(now.time_since_epoch()) % 1000; - auto now_t = std::chrono::system_clock::to_time_t(now); - std::tm local_time = *std::localtime(&now_t); + auto now_t = std::chrono::system_clock::to_time_t(now); + + std::tm local_time{}; +#if defined(_WIN32) + if(localtime_s(&local_time, &now_t) != 0) + return std::string{}; +#else + if(localtime_r(&now_t, &local_time) == nullptr) + return std::string{}; +#endif + std::ostringstream time_s; time_s << std::put_time(&local_time, "%Y-%m-%dT%H:%M:%S"); time_s << "." << std::setfill('0') << std::setw(3) << ms.count() << "Z";