Skip to content

Commit cf4bc0b

Browse files
yangwang201911as-suvorovCopilot
authored
Complete GenAI Logger (#2879)
Complete the logging mechanism with a thread-safe singleton Logger that honors OPENVINO_LOG_LEVEL before printing. Added macros-based functions. (GENAI_DEBUG_LOG, GENAI_INFO_LOG, etc.) Tickets: CVS-176017 --------- Co-authored-by: Alexander Suvorov <[email protected]> Co-authored-by: Copilot <[email protected]>
1 parent 42ce4a3 commit cf4bc0b

File tree

6 files changed

+366
-18
lines changed

6 files changed

+366
-18
lines changed

‎src/cpp/src/logger.cpp‎

Lines changed: 164 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,164 @@
1+
// Copyright (C) 2025 Intel Corporation
2+
// SPDX-License-Identifier: Apache-2.0
3+
4+
#include "logger.hpp"
5+
6+
#include <cctype>
7+
#include <chrono>
8+
#include <cstdio>
9+
#include <cstdlib>
10+
#include <cstring>
11+
#include <ctime>
12+
#include <iostream>
13+
#include <memory>
14+
#include <stdexcept>
15+
#include <string>
16+
#include <string_view>
17+
#include <utility>
18+
#include <vector>
19+
20+
namespace ov::genai {
21+
22+
ov::log::Level get_openvino_env_log_level() {
23+
const char* env = std::getenv("OPENVINO_LOG_LEVEL");
24+
if (!env) {
25+
return ov::log::Level::ERR;
26+
}
27+
try {
28+
std::string env_str(env);
29+
size_t idx = 0;
30+
const auto env_var_value = std::stoi(env_str, &idx);
31+
if (idx != env_str.size()) {
32+
return ov::log::Level::ERR;
33+
}
34+
return static_cast<ov::log::Level>(env_var_value);
35+
} catch (...) {
36+
return ov::log::Level::ERR;
37+
}
38+
}
39+
40+
ov::log::Level get_cur_log_level() {
41+
static ov::log::Level cur_log_level = get_openvino_env_log_level();
42+
return cur_log_level;
43+
}
44+
45+
Logger::Logger() {
46+
log_level.store(get_cur_log_level(), std::memory_order_relaxed);
47+
}
48+
49+
void Logger::do_log(ov::log::Level level, const char* file, int line, const std::string& msg) {
50+
write_message(level, file, line, msg);
51+
}
52+
53+
void Logger::log_format(ov::log::Level level, const char* file, int line, const char* format, ...) {
54+
va_list args;
55+
va_start(args, format);
56+
try {
57+
log_format_impl(level, file, line, format, args);
58+
} catch (const std::exception& ex) {
59+
va_end(args);
60+
throw std::runtime_error(std::string{"Logger format error: "} + ex.what());
61+
} catch (...) {
62+
va_end(args);
63+
throw std::runtime_error("Logger format error: unknown exception");
64+
}
65+
va_end(args);
66+
}
67+
68+
void Logger::set_log_level(ov::log::Level level) {
69+
log_level.store(level, std::memory_order_relaxed);
70+
}
71+
72+
bool Logger::should_log(ov::log::Level level) const {
73+
const auto current_level = log_level.load(std::memory_order_relaxed);
74+
return current_level != ov::log::Level::NO && level != ov::log::Level::NO && level <= current_level;
75+
}
76+
77+
void Logger::write_message(ov::log::Level level, const char* file, int line, const std::string& msg) {
78+
std::lock_guard<std::mutex> lock(log_mutex);
79+
std::ostream& out = (level == ov::log::Level::ERR) ? std::cerr : std::cout;
80+
format_prefix(out, level, file, line);
81+
out << msg;
82+
if (msg.empty() || msg.back() != '\n') {
83+
if (level == ov::log::Level::ERR) {
84+
out << std::endl;
85+
} else {
86+
out << '\n';
87+
}
88+
}
89+
}
90+
91+
void Logger::log_format_impl(ov::log::Level level, const char* file, int line, const char* format, va_list args) {
92+
std::string formatted = format_from_variadic(format, args);
93+
write_message(level, file, line, formatted);
94+
}
95+
96+
std::string Logger::format_from_variadic(const char* format, va_list args) const {
97+
if (!format) {
98+
return {};
99+
}
100+
va_list args_copy;
101+
va_copy(args_copy, args);
102+
int required = std::vsnprintf(nullptr, 0, format, args_copy);
103+
va_end(args_copy);
104+
if (required < 0) {
105+
throw std::runtime_error("Logger format error: invalid format string or arguments");
106+
}
107+
if (required == 0) {
108+
return {};
109+
}
110+
std::vector<char> buffer(static_cast<size_t>(required) + 1u);
111+
int result = std::vsnprintf(buffer.data(), buffer.size(), format, args);
112+
if (result < 0) {
113+
throw std::runtime_error("Logger format error: failed to format message");
114+
}
115+
return std::string(buffer.data(), static_cast<size_t>(required));
116+
}
117+
118+
std::string_view Logger::get_filename(std::string_view file_path) const {
119+
const auto index = file_path.find_last_of("/\\");
120+
if (index == std::string_view::npos) {
121+
return file_path;
122+
}
123+
return file_path.substr(index + 1);
124+
}
125+
126+
std::ostream& Logger::format_prefix(std::ostream& out, ov::log::Level level, const char* file, int line) const {
127+
switch (level) {
128+
case ov::log::Level::DEBUG:
129+
out << "[DEBUG] ";
130+
break;
131+
case ov::log::Level::INFO:
132+
out << "[INFO] ";
133+
break;
134+
case ov::log::Level::WARNING:
135+
out << "[WARNING] ";
136+
break;
137+
case ov::log::Level::ERR:
138+
out << "[ERROR] ";
139+
break;
140+
default:
141+
out << "[LOG] ";
142+
break;
143+
}
144+
145+
// Add timestamp and file info only for DEBUG level
146+
if (level == ov::log::Level::DEBUG) {
147+
{
148+
static std::mutex m;
149+
time_t tt = std::chrono::system_clock::to_time_t(std::chrono::system_clock::now());
150+
std::lock_guard<std::mutex> lock(m);
151+
auto tm = gmtime(&tt);
152+
if (tm) {
153+
char buffer[256];
154+
strftime(buffer, sizeof(buffer), "%Y-%m-%dT%H:%M:%Sz", tm);
155+
out << buffer << " ";
156+
}
157+
}
158+
out << get_filename(file) << ":" << line << "\t";
159+
}
160+
161+
return out;
162+
}
163+
164+
} // namespace ov::genai

‎src/cpp/src/logger.hpp‎

Lines changed: 74 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -2,16 +2,86 @@
22
// SPDX-License-Identifier: Apache-2.0
33

44
#pragma once
5-
#include <iostream>
5+
#include <atomic>
6+
#include <cstdarg>
7+
#include <memory>
8+
#include <mutex>
9+
#include <ostream>
610
#include <string>
11+
#include <string_view>
12+
#include <type_traits>
13+
#include <utility>
14+
15+
#include "openvino/openvino.hpp"
716

817
namespace ov::genai {
18+
ov::log::Level get_openvino_env_log_level();
19+
ov::log::Level get_cur_log_level();
920

1021
class Logger {
1122
public:
12-
static void warn(const std::string& message) {
13-
std::cout << "[WARN] " << message << '\n';
14-
};
23+
Logger(const Logger&) = delete;
24+
Logger& operator=(const Logger&) = delete;
25+
Logger(Logger&&) = delete;
26+
Logger& operator=(Logger&&) = delete;
27+
static Logger& get_instance() {
28+
static Logger instance;
29+
return instance;
30+
}
31+
~Logger() = default;
32+
void do_log(ov::log::Level level, const char* file, int line, const std::string& msg);
33+
34+
#if defined(__GNUC__) || defined(__clang__)
35+
__attribute__((format(printf, 5, 6)))
36+
#endif
37+
void log_format(ov::log::Level level, const char* file, int line, const char* format, ...);
38+
39+
void set_log_level(ov::log::Level level);
40+
41+
bool should_log(ov::log::Level level) const;
42+
43+
private:
44+
Logger();
45+
std::atomic<ov::log::Level> log_level{ov::log::Level::NO};
46+
std::mutex log_mutex;
47+
void write_message(ov::log::Level level, const char* file, int line, const std::string& msg);
48+
void log_format_impl(ov::log::Level level, const char* file, int line, const char* format, va_list args);
49+
std::string format_from_variadic(const char* format, va_list args) const;
50+
std::string_view get_filename(std::string_view file_path) const;
51+
std::ostream& format_prefix(std::ostream& out, ov::log::Level level, const char* file, int line) const;
1552
};
53+
namespace detail {
54+
55+
inline void log_message(ov::log::Level level, const char* file, int line, const std::string& msg) {
56+
auto& logger = Logger::get_instance();
57+
if (!logger.should_log(level)) {
58+
return;
59+
}
60+
logger.do_log(level, file, line, msg);
61+
}
62+
63+
inline void log_message(ov::log::Level level, const char* file, int line, const char* msg) {
64+
auto& logger = Logger::get_instance();
65+
if (!logger.should_log(level)) {
66+
return;
67+
}
68+
logger.do_log(level, file, line, msg ? std::string(msg) : std::string());
69+
}
70+
71+
template <typename... Args, typename = std::enable_if_t<(sizeof...(Args) > 0)>>
72+
inline void log_message(ov::log::Level level, const char* file, int line, const char* format, Args&&... args) {
73+
auto& logger = Logger::get_instance();
74+
if (!logger.should_log(level)) {
75+
return;
76+
}
77+
logger.log_format(level, file, line, format, std::forward<Args>(args)...);
78+
}
79+
80+
} // namespace detail
81+
82+
#define GENAI_DEBUG(...) ::ov::genai::detail::log_message(ov::log::Level::DEBUG, __FILE__, __LINE__, __VA_ARGS__)
83+
#define GENAI_INFO(...) ::ov::genai::detail::log_message(ov::log::Level::INFO, __FILE__, __LINE__, __VA_ARGS__)
84+
#define GENAI_WARN(...) ::ov::genai::detail::log_message(ov::log::Level::WARNING, __FILE__, __LINE__, __VA_ARGS__)
85+
#define GENAI_ERR(...) ::ov::genai::detail::log_message(ov::log::Level::ERR, __FILE__, __LINE__, __VA_ARGS__)
1686

1787
} // namespace ov::genai

‎src/cpp/src/rag/text_embedding_pipeline.cpp‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -300,7 +300,7 @@ class TextEmbeddingPipeline::TextEmbeddingPipelineImpl {
300300
<< ")."
301301
<< " Some models may fail with such configuration."
302302
<< " Remove max_position_embeddings from config.json to silence this warning.";
303-
Logger::warn(message.str());
303+
GENAI_WARN(message.str());
304304
}
305305

306306
if (m_config.pad_to_max_length.has_value() && *m_config.pad_to_max_length) {

‎src/cpp/src/sampling/structured_output/xgrammar_backend.cpp‎

Lines changed: 6 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -72,11 +72,10 @@ xgrammar::Grammar XGrammarStructuredOutput::create_grammar(const std::optional<S
7272
using ConfigType = std::decay_t<decltype(config)>;
7373
if constexpr (std::is_same_v<ConfigType, StructuralTagsConfig>) {
7474
// Old format: StructuralTagsConfig
75-
Logger::warn(
76-
"The use of \"structural_tags_config\" with StructuralTagsConfig instance is deprecated and will be removed in future releases. "
77-
"Use TriggeredTags instead."
78-
);
79-
75+
GENAI_WARN("The use of \"structural_tags_config\" with StructuralTagsConfig instance is "
76+
"deprecated and will be removed in future releases. "
77+
"Use TriggeredTags instead.");
78+
8079
std::ostringstream oss;
8180
oss << "{\"type\": \"structural_tag\", \"format\": " << config.to_json() << "}";
8281
auto result = xgrammar::Grammar::FromStructuralTag(oss.str());
@@ -100,10 +99,8 @@ xgrammar::Grammar XGrammarStructuredOutput::create_grammar(const std::optional<S
10099
}
101100
}, structured_output_config.value().structural_tags_config.value());
102101
} else if (structured_output_config.value().compound_grammar.has_value()) {
103-
Logger::warn(
104-
"The use of \"compound_grammar\" is deprecated and will be removed in future releases.\n"
105-
"Pass the same input to \"structural_tags_config\" instead."
106-
);
102+
GENAI_WARN("The use of \"compound_grammar\" is deprecated and will be removed in future releases.\n"
103+
"Pass the same input to \"structural_tags_config\" instead.");
107104
return parse_structural_tag(structured_output_config.value().compound_grammar.value());
108105
}
109106

‎src/cpp/src/whisper/models/with_past_decoder.cpp‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -82,10 +82,10 @@ namespace ov::genai {
8282
WhisperWithPastDecoder::WhisperWithPastDecoder(const std::filesystem::path& models_path,
8383
const std::string& device,
8484
const ov::AnyMap& properties) {
85-
Logger::warn("Whisper decoder models with past is deprecated. Support will be removed in 2026.0.0 release.\n"
86-
"To obtain stateful decoder model use latest `optimum-intel` package:\n"
87-
"pip install optimum-intel@git+https://github.com/huggingface/optimum-intel.git@main\n"
88-
"optimum-cli export openvino --trust-remote-code --model openai/whisper-tiny whisper-tiny");
85+
GENAI_WARN("Whisper decoder models with past is deprecated. Support will be removed in 2026.0.0 release.\n"
86+
"To obtain stateful decoder model use latest `optimum-intel` package:\n"
87+
"pip install optimum-intel@git+https://github.com/huggingface/optimum-intel.git@main\n"
88+
"optimum-cli export openvino --trust-remote-code --model openai/whisper-tiny whisper-tiny");
8989

9090
ov::Core core = utils::singleton_core();
9191

0 commit comments

Comments
 (0)