From 756aafd0f865dd5a4f05d80895d68d095c909062 Mon Sep 17 00:00:00 2001 From: nnshah1 Date: Fri, 19 Apr 2024 01:48:43 -0700 Subject: [PATCH 1/6] added initial json logging format --- include/triton/common/logging.h | 51 ++++++++- src/logging.cc | 194 ++++++++++++++++++++------------ 2 files changed, 172 insertions(+), 73 deletions(-) diff --git a/include/triton/common/logging.h b/include/triton/common/logging.h index 0be8df4..8ffbe50 100644 --- a/include/triton/common/logging.h +++ b/include/triton/common/logging.h @@ -32,6 +32,17 @@ #include #include #include +#ifdef _WIN32 +// suppress the min and max definitions in Windef.h. +#define NOMINMAX +#include +#else +#include +#include +#include +#include +#endif + namespace triton { namespace common { @@ -41,20 +52,52 @@ class LogMessage { // Log levels. enum Level { kERROR = 0, kWARNING = 1, kINFO = 2 }; - LogMessage(const char* file, int line, uint32_t level); + LogMessage(const char* file, int line, uint32_t level) + : path_(file), line_(line), + level_(std::min(level, (uint32_t)Level::kINFO)), pid_(GetProcessId()) + { + SetTimestamp(); + size_t path_start = path_.rfind('/'); + if (path_start != std::string::npos) { + path_ = path_.substr(path_start + 1, std::string::npos); + } + } + + ~LogMessage(); - std::stringstream& stream() { return stream_; } + std::stringstream& stream() { return message_; } private: + static const std::array LEVEL_NAMES_; static const std::vector level_name_; - std::stringstream stream_; + std::string path_; + const int line_; + const uint32_t level_; + const uint32_t pid_; + void LogPreamble(std::stringstream& stream); + void LogTimestamp(std::stringstream& stream); + +#ifdef _WIN32 + SYSTEMTIME timestamp_; + void SetTimestamp() { GetSystemTime(×tamp_); } + static uint32_t GetProcessId() + { + return static_cast(GetCurrentProcessId()); + }; +#else + struct timeval timestamp_; + void SetTimestamp() { gettimeofday(×tamp_, NULL); } + static uint32_t GetProcessId() { return static_cast(getpid()); }; +#endif + + std::stringstream message_; }; // Global logger for messages. Controls how log messages are reported. class Logger { public: - enum class Format { kDEFAULT, kISO8601 }; + enum class Format { kDEFAULT, kISO8601, kJSONL }; Logger(); diff --git a/src/logging.cc b/src/logging.cc index 67b01ba..a1000b6 100644 --- a/src/logging.cc +++ b/src/logging.cc @@ -26,20 +26,28 @@ #include "triton/common/logging.h" -#ifdef _WIN32 -// suppress the min and max definitions in Windef.h. -#define NOMINMAX -#include -#else -#include -#include -#include -#include -#endif #include #include #include +#include "triton/common/error.h" + +static const uint8_t INTERNAL_ERROR = + static_cast(triton::common::Error::Code::INTERNAL); + +static const uint8_t SUCCESS = + static_cast(triton::common::Error::Code::SUCCESS); + +#define TRITONJSON_STATUSTYPE uint8_t +#define TRITONJSON_STATUSRETURN(M) \ + do { \ + LOG_ERROR << (M) << ": " << INTERNAL_ERROR; \ + return INTERNAL_ERROR; \ + } while (false) + +#define TRITONJSON_STATUSSUCCESS SUCCESS +#include "triton/common/triton_json.h" + namespace triton { namespace common { Logger gLogger_; @@ -66,82 +74,130 @@ Logger::Flush() std::cerr << std::flush; } - +const std::array + LogMessage::LEVEL_NAMES_{"Error", "Warning", "Info"}; const std::vector LogMessage::level_name_{'E', 'W', 'I'}; -LogMessage::LogMessage(const char* file, int line, uint32_t level) +#ifdef _WIN32 + +void +LogMessage::LogTimestamp(std::stringstream& stream) { - std::string path(file); - size_t pos = path.rfind('/'); - if (pos != std::string::npos) { - path = path.substr(pos + 1, std::string::npos); + switch (gLogger_.LogFormat()) { + case Logger::Format::kDEFAULT: { + stream << std::setfill('0') << std::setw(2) << timestamp_.wMonth + << std::setw(2) << timestamp_.wDay << ' ' << std::setw(2) + << timestamp_.wHour << ':' << std::setw(2) << timestamp_.wMinute + << ':' << std::setw(2) << timestamp_.wSecond << '.' << std::setw(6) + << timestamp_.wMilliseconds * 1000; + break; + } + case Logger::Format::kISO8601: { + stream << timestamp_.wYear << '-' << std::setfill('0') << std::setw(2) + << timestamp_.wMonth << '-' << std::setw(2) << timestamp_.wDay + << 'T' << std::setw(2) << timestamp_.wHour << ':' << std::setw(2) + << timestamp_.wMinute << ':' << std::setw(2) << timestamp_.wSecond + << "Z"; + break; + } + case Logger::Format::JSONL: { + stream << timestamp_.wYear << '-' << std::setfill('0') << std::setw(2) + << timestamp_.wMonth << '-' << std::setw(2) << timestamp_.wDay + << 'T' << std::setw(2) << timestamp_.wHour << ':' << std::setw(2) + << timestamp_.wMinute << ':' << std::setw(2) << timestamp_.wSecond + << '.' << std::setw(6) << timestamp_.wMilliseconds * 1000 << "Z"; + break; + } } +} +#else +void +LogMessage::LogTimestamp(std::stringstream& stream) +{ + struct tm tm_time; + gmtime_r(((time_t*)&(timestamp_.tv_sec)), &tm_time); - // 'L' below is placeholder for showing log level switch (gLogger_.LogFormat()) { case Logger::Format::kDEFAULT: { - // LMMDD hh:mm:ss.ssssss -#ifdef _WIN32 - SYSTEMTIME system_time; - GetSystemTime(&system_time); - stream_ << level_name_[std::min(level, (uint32_t)Level::kINFO)] - << std::setfill('0') << std::setw(2) << system_time.wMonth - << std::setw(2) << system_time.wDay << ' ' << std::setw(2) - << system_time.wHour << ':' << std::setw(2) << system_time.wMinute - << ':' << std::setw(2) << system_time.wSecond << '.' - << std::setw(6) << system_time.wMilliseconds * 1000 << ' ' - << static_cast(GetCurrentProcessId()) << ' ' << path - << ':' << line << "] "; -#else - struct timeval tv; - gettimeofday(&tv, NULL); - struct tm tm_time; - gmtime_r(((time_t*)&(tv.tv_sec)), &tm_time); - stream_ << level_name_[std::min(level, (uint32_t)Level::kINFO)] - << std::setfill('0') << std::setw(2) << (tm_time.tm_mon + 1) - << std::setw(2) << tm_time.tm_mday << ' ' << std::setw(2) - << tm_time.tm_hour << ':' << std::setw(2) << tm_time.tm_min << ':' - << std::setw(2) << tm_time.tm_sec << '.' << std::setw(6) - << tv.tv_usec << ' ' << static_cast(getpid()) << ' ' - << path << ':' << line << "] "; -#endif + stream << std::setfill('0') << std::setw(2) << (tm_time.tm_mon + 1) + << std::setw(2) << tm_time.tm_mday << ' ' << std::setw(2) + << tm_time.tm_hour << ':' << std::setw(2) << tm_time.tm_min << ':' + << std::setw(2) << tm_time.tm_sec << '.' << std::setw(6) + << timestamp_.tv_usec; break; } case Logger::Format::kISO8601: { - // YYYY-MM-DDThh:mm:ssZ L -#ifdef _WIN32 - SYSTEMTIME system_time; - GetSystemTime(&system_time); - stream_ << system_time.wYear << '-' << std::setfill('0') << std::setw(2) - << system_time.wMonth << '-' << std::setw(2) << system_time.wDay - << 'T' << std::setw(2) << system_time.wHour << ':' << std::setw(2) - << system_time.wMinute << ':' << std::setw(2) - << system_time.wSecond << "Z " - << level_name_[std::min(level, (uint32_t)Level::kINFO)] << ' ' - << static_cast(GetCurrentProcessId()) << ' ' << path - << ':' << line << "] "; -#else - struct timeval tv; - gettimeofday(&tv, NULL); - struct tm tm_time; - gmtime_r(((time_t*)&(tv.tv_sec)), &tm_time); - stream_ << (tm_time.tm_year + 1900) << '-' << std::setfill('0') - << std::setw(2) << (tm_time.tm_mon + 1) << '-' << std::setw(2) - << tm_time.tm_mday << 'T' << std::setw(2) << tm_time.tm_hour - << ':' << std::setw(2) << tm_time.tm_min << ':' << std::setw(2) - << tm_time.tm_sec << "Z " - << level_name_[std::min(level, (uint32_t)Level::kINFO)] << ' ' - << static_cast(getpid()) << ' ' << path << ':' << line - << "] "; + stream << (tm_time.tm_year + 1900) << '-' << std::setfill('0') + << std::setw(2) << (tm_time.tm_mon + 1) << '-' << std::setw(2) + << tm_time.tm_mday << 'T' << std::setw(2) << tm_time.tm_hour << ':' + << std::setw(2) << tm_time.tm_min << ':' << std::setw(2) + << tm_time.tm_sec << "Z"; + break; + } + case Logger::Format::kJSONL: { + stream << (tm_time.tm_year + 1900) << '-' << std::setfill('0') + << std::setw(2) << (tm_time.tm_mon + 1) << '-' << std::setw(2) + << tm_time.tm_mday << 'T' << std::setw(2) << tm_time.tm_hour << ':' + << std::setw(2) << tm_time.tm_min << ':' << std::setw(2) + << tm_time.tm_sec << '.' << std::setw(6) << timestamp_.tv_usec + << "Z"; + break; + } + } +} + #endif + +void +LogMessage::LogPreamble(std::stringstream& stream) +{ + switch (gLogger_.LogFormat()) { + case Logger::Format::kDEFAULT: { + stream << LEVEL_NAMES_[level_][0]; + LogTimestamp(stream); + stream << ' ' << pid_ << ' ' << path_ << ':' << line_ << "] "; + + break; + } + case Logger::Format::kISO8601: { + LogTimestamp(stream); + stream << " " << LEVEL_NAMES_[level_][0] << ' ' << pid_ << ' ' << path_ + << ':' << line_ << "] "; + break; + } + case Logger::Format::kJSONL: { break; } } } + LogMessage::~LogMessage() { - gLogger_.Log(stream_.str()); -} + gLogger_.SetLogFormat(Logger::Format::kJSONL); + switch (gLogger_.LogFormat()) { + case Logger::Format::kDEFAULT: + case Logger::Format::kISO8601: { + std::stringstream preamble; + LogPreamble(preamble); + preamble << message_.rdbuf(); + message_.str(""); + gLogger_.Log(preamble.str()); + break; + } + case Logger::Format::kJSONL: { + TritonJson::Value logMessage(TritonJson::ValueType::OBJECT); + TritonJson::WriteBuffer buffer; + logMessage.AddString("file", path_); + logMessage.AddInt("line", line_); + logMessage.AddString("level", LEVEL_NAMES_[level_]); + logMessage.AddInt("pid", pid_); + logMessage.AddString("message", message_.str()); + logMessage.Write(&buffer); + gLogger_.Log(buffer.Contents()); + break; + } + } +} }} // namespace triton::common From c5eb21f81d86809dd1e3b9efcd5921760b4d6de3 Mon Sep 17 00:00:00 2001 From: nnshah1 Date: Fri, 19 Apr 2024 01:49:03 -0700 Subject: [PATCH 2/6] force error to be uint8_t storage type --- include/triton/common/error.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/include/triton/common/error.h b/include/triton/common/error.h index 5c22c19..45841a7 100644 --- a/include/triton/common/error.h +++ b/include/triton/common/error.h @@ -36,7 +36,7 @@ namespace triton { namespace common { // class Error { public: - enum class Code { + enum class Code : uint8_t { SUCCESS, UNKNOWN, INTERNAL, From e5a682ea637caf861689f2e04c9eb9b5e93e1f8a Mon Sep 17 00:00:00 2001 From: nnshah1 Date: Fri, 19 Apr 2024 07:34:21 -0700 Subject: [PATCH 3/6] updated --- include/triton/common/logging.h | 1 - src/logging.cc | 7 +++++-- 2 files changed, 5 insertions(+), 3 deletions(-) diff --git a/include/triton/common/logging.h b/include/triton/common/logging.h index 8ffbe50..2b59e55 100644 --- a/include/triton/common/logging.h +++ b/include/triton/common/logging.h @@ -70,7 +70,6 @@ class LogMessage { private: static const std::array LEVEL_NAMES_; - static const std::vector level_name_; std::string path_; const int line_; const uint32_t level_; diff --git a/src/logging.cc b/src/logging.cc index a1000b6..bad4d5a 100644 --- a/src/logging.cc +++ b/src/logging.cc @@ -75,7 +75,7 @@ Logger::Flush() } const std::array - LogMessage::LEVEL_NAMES_{"Error", "Warning", "Info"}; + LogMessage::LEVEL_NAMES_{"ERROR", "WARNING", "INFO"}; const std::vector LogMessage::level_name_{'E', 'W', 'I'}; #ifdef _WIN32 @@ -189,11 +189,14 @@ LogMessage::~LogMessage() case Logger::Format::kJSONL: { TritonJson::Value logMessage(TritonJson::ValueType::OBJECT); TritonJson::WriteBuffer buffer; + std::stringstream timestamp; + LogTimestamp(timestamp); logMessage.AddString("file", path_); logMessage.AddInt("line", line_); logMessage.AddString("level", LEVEL_NAMES_[level_]); - logMessage.AddInt("pid", pid_); + logMessage.AddInt("process_id", pid_); logMessage.AddString("message", message_.str()); + logMessage.AddString("timestamp", timestamp.str()); logMessage.Write(&buffer); gLogger_.Log(buffer.Contents()); break; From 16ecd882d9f5dfe277d206541d368939ea988685 Mon Sep 17 00:00:00 2001 From: nnshah1 Date: Fri, 19 Apr 2024 17:08:16 -0700 Subject: [PATCH 4/6] updating to allow escaping in current log formats --- include/triton/common/triton_json.h | 14 ++++++++++++++ src/logging.cc | 8 ++++---- 2 files changed, 18 insertions(+), 4 deletions(-) diff --git a/include/triton/common/triton_json.h b/include/triton/common/triton_json.h index 7a1b052..855ea39 100644 --- a/include/triton/common/triton_json.h +++ b/include/triton/common/triton_json.h @@ -25,6 +25,7 @@ // OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. #pragma once + #ifdef _WIN32 // Remove GetObject definition from windows.h, which prevents calls to // RapidJSON's GetObject. @@ -109,6 +110,19 @@ class TritonJson { std::string buffer_; }; + static std::string EscapeString(const std::string& input) + { + WriteBuffer writebuffer; + const unsigned int writeFlags = rapidjson::kWriteNanAndInfFlag; + // Provide default template arguments to pass writeFlags + rapidjson::Writer< + WriteBuffer, rapidjson::UTF8<>, rapidjson::UTF8<>, + rapidjson::CrtAllocator, writeFlags> + writer(writebuffer); + writer.String(input.c_str()); + return writebuffer.Contents(); + } + // // Value representing the entire document or an element within a // document. diff --git a/src/logging.cc b/src/logging.cc index bad4d5a..03ef238 100644 --- a/src/logging.cc +++ b/src/logging.cc @@ -76,7 +76,6 @@ Logger::Flush() const std::array LogMessage::LEVEL_NAMES_{"ERROR", "WARNING", "INFO"}; -const std::vector LogMessage::level_name_{'E', 'W', 'I'}; #ifdef _WIN32 @@ -174,15 +173,16 @@ LogMessage::LogPreamble(std::stringstream& stream) LogMessage::~LogMessage() { - gLogger_.SetLogFormat(Logger::Format::kJSONL); + // gLogger_.SetLogFormat(Logger::Format::kJSONL); switch (gLogger_.LogFormat()) { case Logger::Format::kDEFAULT: case Logger::Format::kISO8601: { std::stringstream preamble; LogPreamble(preamble); - preamble << message_.rdbuf(); - message_.str(""); + // std::string escaped(message_.str()); + std::string escaped = TritonJson::EscapeString(message_.str()); + preamble << escaped; gLogger_.Log(preamble.str()); break; } From f812f8ea067bad49c396178ea43872267674f920 Mon Sep 17 00:00:00 2001 From: nnshah1 Date: Sat, 11 May 2024 08:40:42 -0700 Subject: [PATCH 5/6] adding support for escaping log messages --- include/triton/common/logging.h | 190 ++++++++++++++++------------ include/triton/common/triton_json.h | 9 +- src/logging.cc | 86 +++---------- 3 files changed, 139 insertions(+), 146 deletions(-) diff --git a/include/triton/common/logging.h b/include/triton/common/logging.h index 2b59e55..5e80f6b 100644 --- a/include/triton/common/logging.h +++ b/include/triton/common/logging.h @@ -32,6 +32,8 @@ #include #include #include + +#include "table_printer.h" #ifdef _WIN32 // suppress the min and max definitions in Windef.h. #define NOMINMAX @@ -46,68 +48,22 @@ namespace triton { namespace common { -// A log message. -class LogMessage { - public: - // Log levels. - enum Level { kERROR = 0, kWARNING = 1, kINFO = 2 }; - - LogMessage(const char* file, int line, uint32_t level) - : path_(file), line_(line), - level_(std::min(level, (uint32_t)Level::kINFO)), pid_(GetProcessId()) - { - SetTimestamp(); - size_t path_start = path_.rfind('/'); - if (path_start != std::string::npos) { - path_ = path_.substr(path_start + 1, std::string::npos); - } - } - - - ~LogMessage(); - - std::stringstream& stream() { return message_; } - - private: - static const std::array LEVEL_NAMES_; - std::string path_; - const int line_; - const uint32_t level_; - const uint32_t pid_; - void LogPreamble(std::stringstream& stream); - void LogTimestamp(std::stringstream& stream); - -#ifdef _WIN32 - SYSTEMTIME timestamp_; - void SetTimestamp() { GetSystemTime(×tamp_); } - static uint32_t GetProcessId() - { - return static_cast(GetCurrentProcessId()); - }; -#else - struct timeval timestamp_; - void SetTimestamp() { gettimeofday(×tamp_, NULL); } - static uint32_t GetProcessId() { return static_cast(getpid()); }; -#endif - - std::stringstream message_; -}; - // Global logger for messages. Controls how log messages are reported. class Logger { public: - enum class Format { kDEFAULT, kISO8601, kJSONL }; + // Log Formats. + enum class Format { kDEFAULT, kISO8601 }; + + // Log levels. + enum Level { kERROR = 0, kWARNING = 1, kINFO = 2 }; Logger(); // Is a log level enabled. - bool IsEnabled(LogMessage::Level level) const { return enables_[level]; } + bool IsEnabled(Level level) const { return enables_[level]; } // Set enable for a log Level. - void SetEnabled(LogMessage::Level level, bool enable) - { - enables_[level] = enable; - } + void SetEnabled(Level level, bool enable) { enables_[level] = enable; } // Get the current verbose logging level. uint32_t VerboseLevel() const { return vlevel_; } @@ -115,6 +71,12 @@ class Logger { // Set the current verbose logging level. void SetVerboseLevel(uint32_t vlevel) { vlevel_ = vlevel; } + // Whether to escape log messages + // using JSON string escaping rules. + // Default is true but can be disabled via an environment variable + // TRITONSERVER_ESCAPE_LOG_MESSAGES + bool EscapeLogMessages() const { return escape_log_messages_; }; + // Get the logging format. Format LogFormat() { return format_; } @@ -167,7 +129,10 @@ class Logger { // Flush the log. void Flush(); + static const std::array LEVEL_NAMES; + private: + bool escape_log_messages_; std::vector enables_; uint32_t vlevel_; Format format_; @@ -178,15 +143,64 @@ class Logger { extern Logger gLogger_; -#define LOG_ENABLE_INFO(E) \ - triton::common::gLogger_.SetEnabled( \ - triton::common::LogMessage::Level::kINFO, (E)) +// A log message. +class LogMessage { + public: + LogMessage(const char* file, int line, uint32_t level) + : path_(file), line_(line), + level_(std::min(level, (uint32_t)Logger::Level::kINFO)), + pid_(GetProcessId()), escape_log_messages_(gLogger_.EscapeLogMessages()) + { + SetTimestamp(); + size_t path_start = path_.rfind('/'); + if (path_start != std::string::npos) { + path_ = path_.substr(path_start + 1, std::string::npos); + } + } + + LogMessage( + const char* file, int line, uint32_t level, bool escape_log_messages) + : LogMessage(file, line, level) + { + escape_log_messages_ = escape_log_messages; + } + + ~LogMessage(); + + std::stringstream& stream() { return message_; } + + private: + std::string path_; + const int line_; + const uint32_t level_; + const uint32_t pid_; + void LogPreamble(std::stringstream& stream); + void LogTimestamp(std::stringstream& stream); + +#ifdef _WIN32 + SYSTEMTIME timestamp_; + void SetTimestamp() { GetSystemTime(×tamp_); } + static uint32_t GetProcessId() + { + return static_cast(GetCurrentProcessId()); + }; +#else + struct timeval timestamp_; + void SetTimestamp() { gettimeofday(×tamp_, NULL); } + static uint32_t GetProcessId() { return static_cast(getpid()); }; +#endif + std::stringstream message_; + bool escape_log_messages_; +}; + +#define LOG_ENABLE_INFO(E) \ + triton::common::gLogger_.SetEnabled(triton::common::Logger::Level::kINFO, (E)) #define LOG_ENABLE_WARNING(E) \ triton::common::gLogger_.SetEnabled( \ - triton::common::LogMessage::Level::kWARNING, (E)) + triton::common::Logger::Level::kWARNING, (E)) #define LOG_ENABLE_ERROR(E) \ triton::common::gLogger_.SetEnabled( \ - triton::common::LogMessage::Level::kERROR, (E)) + triton::common::Logger::Level::kERROR, (E)) #define LOG_SET_VERBOSE(L) \ triton::common::gLogger_.SetVerboseLevel( \ static_cast(std::max(0, (L)))) @@ -201,12 +215,11 @@ extern Logger gLogger_; #ifdef TRITON_ENABLE_LOGGING #define LOG_INFO_IS_ON \ - triton::common::gLogger_.IsEnabled(triton::common::LogMessage::Level::kINFO) -#define LOG_WARNING_IS_ON \ - triton::common::gLogger_.IsEnabled( \ - triton::common::LogMessage::Level::kWARNING) + triton::common::gLogger_.IsEnabled(triton::common::Logger::Level::kINFO) +#define LOG_WARNING_IS_ON \ + triton::common::gLogger_.IsEnabled(triton::common::Logger::Level::kWARNING) #define LOG_ERROR_IS_ON \ - triton::common::gLogger_.IsEnabled(triton::common::LogMessage::Level::kERROR) + triton::common::gLogger_.IsEnabled(triton::common::Logger::Level::kERROR) #define LOG_VERBOSE_IS_ON(L) (triton::common::gLogger_.VerboseLevel() >= (L)) #else @@ -220,25 +233,25 @@ extern Logger gLogger_; #endif // TRITON_ENABLE_LOGGING // Macros that use explicitly given filename and line number. -#define LOG_INFO_FL(FN, LN) \ - if (LOG_INFO_IS_ON) \ - triton::common::LogMessage( \ - (char*)(FN), LN, triton::common::LogMessage::Level::kINFO) \ +#define LOG_INFO_FL(FN, LN) \ + if (LOG_INFO_IS_ON) \ + triton::common::LogMessage( \ + (char*)(FN), LN, triton::common::Logger::Level::kINFO) \ .stream() -#define LOG_WARNING_FL(FN, LN) \ - if (LOG_WARNING_IS_ON) \ - triton::common::LogMessage( \ - (char*)(FN), LN, triton::common::LogMessage::Level::kWARNING) \ +#define LOG_WARNING_FL(FN, LN) \ + if (LOG_WARNING_IS_ON) \ + triton::common::LogMessage( \ + (char*)(FN), LN, triton::common::Logger::Level::kWARNING) \ .stream() -#define LOG_ERROR_FL(FN, LN) \ - if (LOG_ERROR_IS_ON) \ - triton::common::LogMessage( \ - (char*)(FN), LN, triton::common::LogMessage::Level::kERROR) \ +#define LOG_ERROR_FL(FN, LN) \ + if (LOG_ERROR_IS_ON) \ + triton::common::LogMessage( \ + (char*)(FN), LN, triton::common::Logger::Level::kERROR) \ .stream() -#define LOG_VERBOSE_FL(L, FN, LN) \ - if (LOG_VERBOSE_IS_ON(L)) \ - triton::common::LogMessage( \ - (char*)(FN), LN, triton::common::LogMessage::Level::kINFO) \ +#define LOG_VERBOSE_FL(L, FN, LN) \ + if (LOG_VERBOSE_IS_ON(L)) \ + triton::common::LogMessage( \ + (char*)(FN), LN, triton::common::Logger::Level::kINFO) \ .stream() // Macros that use current filename and line number. @@ -247,6 +260,25 @@ extern Logger gLogger_; #define LOG_ERROR LOG_ERROR_FL(__FILE__, __LINE__) #define LOG_VERBOSE(L) LOG_VERBOSE_FL(L, __FILE__, __LINE__) +#define LOG_TABLE_VERBOSE(L, TABLE) \ + \ + do { \ + if (LOG_VERBOSE_IS_ON(L)) \ + triton::common::LogMessage( \ + __FILE__, __LINE__, triton::common::Logger::Level::kINFO, false) \ + .stream() \ + << TABLE.PrintTable(); \ + } while (false) + + +#define LOG_TABLE_INFO(TABLE) \ + do { \ + if (LOG_INFO_IS_ON) \ + triton::common::LogMessage( \ + __FILE__, __LINE__, triton::common::Logger::Level::kINFO, false) \ + .stream() \ + << TABLE.PrintTable(); \ + } while (false) #define LOG_STATUS_ERROR(X, MSG) \ do { \ diff --git a/include/triton/common/triton_json.h b/include/triton/common/triton_json.h index 855ea39..9680b7a 100644 --- a/include/triton/common/triton_json.h +++ b/include/triton/common/triton_json.h @@ -110,6 +110,11 @@ class TritonJson { std::string buffer_; }; + // + // Utility to return an escaped version of the + // input string + // + static std::string EscapeString(const std::string& input) { WriteBuffer writebuffer; @@ -119,7 +124,9 @@ class TritonJson { WriteBuffer, rapidjson::UTF8<>, rapidjson::UTF8<>, rapidjson::CrtAllocator, writeFlags> writer(writebuffer); - writer.String(input.c_str()); + if (RAPIDJSON_UNLIKELY(!writer.String(input.c_str()))) { + return "Error Escaping String"; + } return writebuffer.Contents(); } diff --git a/src/logging.cc b/src/logging.cc index 03ef238..9c67138 100644 --- a/src/logging.cc +++ b/src/logging.cc @@ -32,20 +32,11 @@ #include "triton/common/error.h" -static const uint8_t INTERNAL_ERROR = - static_cast(triton::common::Error::Code::INTERNAL); - -static const uint8_t SUCCESS = - static_cast(triton::common::Error::Code::SUCCESS); - +// Defined but not used #define TRITONJSON_STATUSTYPE uint8_t -#define TRITONJSON_STATUSRETURN(M) \ - do { \ - LOG_ERROR << (M) << ": " << INTERNAL_ERROR; \ - return INTERNAL_ERROR; \ - } while (false) +#define TRITONJSON_STATUSRETURN(M) +#define TRITONJSON_STATUSSUCCESS 0 -#define TRITONJSON_STATUSSUCCESS SUCCESS #include "triton/common/triton_json.h" namespace triton { namespace common { @@ -55,6 +46,9 @@ Logger gLogger_; Logger::Logger() : enables_{true, true, true}, vlevel_(0), format_(Format::kDEFAULT) { + const char* value = std::getenv("TRITONSERVER_ESCAPE_LOG_MESSAGES"); + escape_log_messages_ = + (value && std::strcmp(value, "FALSE") == 0) ? false : true; } void @@ -74,8 +68,8 @@ Logger::Flush() std::cerr << std::flush; } -const std::array - LogMessage::LEVEL_NAMES_{"ERROR", "WARNING", "INFO"}; +const std::array Logger::LEVEL_NAMES{ + "E", "W", "I"}; #ifdef _WIN32 @@ -92,14 +86,6 @@ LogMessage::LogTimestamp(std::stringstream& stream) break; } case Logger::Format::kISO8601: { - stream << timestamp_.wYear << '-' << std::setfill('0') << std::setw(2) - << timestamp_.wMonth << '-' << std::setw(2) << timestamp_.wDay - << 'T' << std::setw(2) << timestamp_.wHour << ':' << std::setw(2) - << timestamp_.wMinute << ':' << std::setw(2) << timestamp_.wSecond - << "Z"; - break; - } - case Logger::Format::JSONL: { stream << timestamp_.wYear << '-' << std::setfill('0') << std::setw(2) << timestamp_.wMonth << '-' << std::setw(2) << timestamp_.wDay << 'T' << std::setw(2) << timestamp_.wHour << ':' << std::setw(2) @@ -126,14 +112,6 @@ LogMessage::LogTimestamp(std::stringstream& stream) break; } case Logger::Format::kISO8601: { - stream << (tm_time.tm_year + 1900) << '-' << std::setfill('0') - << std::setw(2) << (tm_time.tm_mon + 1) << '-' << std::setw(2) - << tm_time.tm_mday << 'T' << std::setw(2) << tm_time.tm_hour << ':' - << std::setw(2) << tm_time.tm_min << ':' << std::setw(2) - << tm_time.tm_sec << "Z"; - break; - } - case Logger::Format::kJSONL: { stream << (tm_time.tm_year + 1900) << '-' << std::setfill('0') << std::setw(2) << (tm_time.tm_mon + 1) << '-' << std::setw(2) << tm_time.tm_mday << 'T' << std::setw(2) << tm_time.tm_hour << ':' @@ -152,19 +130,16 @@ LogMessage::LogPreamble(std::stringstream& stream) { switch (gLogger_.LogFormat()) { case Logger::Format::kDEFAULT: { - stream << LEVEL_NAMES_[level_][0]; + stream << Logger::LEVEL_NAMES[level_]; LogTimestamp(stream); - stream << ' ' << pid_ << ' ' << path_ << ':' << line_ << "] "; + stream << ' ' << pid_ << " [" << path_ << ':' << line_ << "] "; break; } case Logger::Format::kISO8601: { LogTimestamp(stream); - stream << " " << LEVEL_NAMES_[level_][0] << ' ' << pid_ << ' ' << path_ - << ':' << line_ << "] "; - break; - } - case Logger::Format::kJSONL: { + stream << " " << Logger::LEVEL_NAMES[level_] << ' ' << pid_ << " [" + << path_ << ':' << line_ << "] "; break; } } @@ -173,34 +148,13 @@ LogMessage::LogPreamble(std::stringstream& stream) LogMessage::~LogMessage() { - // gLogger_.SetLogFormat(Logger::Format::kJSONL); - - switch (gLogger_.LogFormat()) { - case Logger::Format::kDEFAULT: - case Logger::Format::kISO8601: { - std::stringstream preamble; - LogPreamble(preamble); - // std::string escaped(message_.str()); - std::string escaped = TritonJson::EscapeString(message_.str()); - preamble << escaped; - gLogger_.Log(preamble.str()); - break; - } - case Logger::Format::kJSONL: { - TritonJson::Value logMessage(TritonJson::ValueType::OBJECT); - TritonJson::WriteBuffer buffer; - std::stringstream timestamp; - LogTimestamp(timestamp); - logMessage.AddString("file", path_); - logMessage.AddInt("line", line_); - logMessage.AddString("level", LEVEL_NAMES_[level_]); - logMessage.AddInt("process_id", pid_); - logMessage.AddString("message", message_.str()); - logMessage.AddString("timestamp", timestamp.str()); - logMessage.Write(&buffer); - gLogger_.Log(buffer.Contents()); - break; - } - } + std::stringstream preamble; + LogPreamble(preamble); + std::string escaped_message = escape_log_messages_ + ? TritonJson::EscapeString(message_.str()) + : message_.str(); + preamble << escaped_message; + gLogger_.Log(preamble.str()); } + }} // namespace triton::common From 1714c903a8e17a0300fd1b184fa09c9f02778cfc Mon Sep 17 00:00:00 2001 From: nnshah1 Date: Tue, 14 May 2024 16:14:19 -0700 Subject: [PATCH 6/6] adding logging macros for JSON --- include/triton/common/logging.h | 57 ++++++++++++++++++++++++++++++++- src/logging.cc | 4 +-- 2 files changed, 58 insertions(+), 3 deletions(-) diff --git a/include/triton/common/logging.h b/include/triton/common/logging.h index 5e80f6b..e5907ad 100644 --- a/include/triton/common/logging.h +++ b/include/triton/common/logging.h @@ -55,7 +55,7 @@ class Logger { enum class Format { kDEFAULT, kISO8601 }; // Log levels. - enum Level { kERROR = 0, kWARNING = 1, kINFO = 2 }; + enum Level { kERROR = 0, kWARNING = 1, kINFO = 2, kEND }; Logger(); @@ -254,6 +254,51 @@ class LogMessage { (char*)(FN), LN, triton::common::Logger::Level::kINFO) \ .stream() +#define LOG_JSON_INFO_FL(FN, LN, PREAMBLE, JSON_CHAR_PTR, SIZE) \ + \ + do { \ + if (LOG_INFO_IS_ON) \ + triton::common::LogMessage( \ + (char*)(FN), LN, triton::common::Logger::Level::kINFO, false) \ + .stream() \ + << PREAMBLE << '\n' \ + << std::string({JSON_CHAR_PTR, SIZE}); \ + } while (false) + +#define LOG_JSON_WARNING_FL(FN, LN, PREAMBLE, JSON_CHAR_PTR, SIZE) \ + \ + do { \ + if (LOG_WARNING_IS_ON) \ + triton::common::LogMessage( \ + (char*)(FN), LN, triton::common::Logger::Level::kWARNING, false) \ + .stream() \ + << PREAMBLE << '\n' \ + << std::string({JSON_CHAR_PTR, SIZE}); \ + } while (false) + +#define LOG_JSON_ERROR_FL(FN, LN, PREAMBLE, JSON_CHAR_PTR, SIZE) \ + \ + do { \ + if (LOG_ERROR_IS_ON) \ + triton::common::LogMessage( \ + (char*)(FN), LN, triton::common::Logger::Level::kERROR, false) \ + .stream() \ + << PREAMBLE << '\n' \ + << std::string({JSON_CHAR_PTR, SIZE}); \ + } while (false) + +#define LOG_JSON_VERBOSE_FL(L, FN, LN, PREAMBLE, JSON_CHAR_PTR, SIZE) \ + \ + do { \ + if (LOG_VERBOSE_IS_ON(L)) \ + triton::common::LogMessage( \ + (char*)(FN), LN, triton::common::Logger::Level::kINFO, false) \ + .stream() \ + << PREAMBLE << '\n' \ + << std::string({JSON_CHAR_PTR, SIZE}); \ + } while (false) + + // Macros that use current filename and line number. #define LOG_INFO LOG_INFO_FL(__FILE__, __LINE__) #define LOG_WARNING LOG_WARNING_FL(__FILE__, __LINE__) @@ -270,6 +315,16 @@ class LogMessage { << TABLE.PrintTable(); \ } while (false) +#define LOG_PROTOBUF_VERBOSE(L, PREAMBLE, PB_MESSAGE) \ + \ + do { \ + if (LOG_VERBOSE_IS_ON(L)) \ + triton::common::LogMessage( \ + __FILE__, __LINE__, triton::common::Logger::Level::kINFO, false) \ + .stream() \ + << PREAMBLE << '\n' \ + << PB_MESSAGE.DebugString(); \ + } while (false) #define LOG_TABLE_INFO(TABLE) \ do { \ diff --git a/src/logging.cc b/src/logging.cc index 9c67138..df1fa27 100644 --- a/src/logging.cc +++ b/src/logging.cc @@ -46,7 +46,7 @@ Logger gLogger_; Logger::Logger() : enables_{true, true, true}, vlevel_(0), format_(Format::kDEFAULT) { - const char* value = std::getenv("TRITONSERVER_ESCAPE_LOG_MESSAGES"); + const char* value = std::getenv("TRITON_SERVER_ESCAPE_LOG_MESSAGES"); escape_log_messages_ = (value && std::strcmp(value, "FALSE") == 0) ? false : true; } @@ -68,7 +68,7 @@ Logger::Flush() std::cerr << std::flush; } -const std::array Logger::LEVEL_NAMES{ +const std::array Logger::LEVEL_NAMES{ "E", "W", "I"}; #ifdef _WIN32