From 48a8441dab4580fa2a6cf91e723af17810df0b96 Mon Sep 17 00:00:00 2001 From: JaySon-Huang Date: Mon, 27 Dec 2021 14:36:05 +0800 Subject: [PATCH 1/8] temp save Signed-off-by: JaySon-Huang --- libs/libcommon/include/common/logger_useful.h | 109 +++++++++--------- libs/libcommon/src/tests/gtest_logger.cpp | 20 ++++ 2 files changed, 72 insertions(+), 57 deletions(-) diff --git a/libs/libcommon/include/common/logger_useful.h b/libs/libcommon/include/common/logger_useful.h index 0cb1592c43e..e6270cb97f6 100644 --- a/libs/libcommon/include/common/logger_useful.h +++ b/libs/libcommon/include/common/logger_useful.h @@ -19,69 +19,15 @@ #include #include +#define KEEP_STRINGSTREAM_FOR_LOG 1 // TODO: Disable it after we cleanup all stringstream in logging +#if KEEP_STRINGSTREAM_FOR_LOG #include +#endif #ifndef QUERY_PREVIEW_LENGTH #define QUERY_PREVIEW_LENGTH 160 #endif -/// Logs a message to a specified logger with that level. - -#define LOG_TRACE(logger, message) \ - do \ - { \ - if ((logger)->trace()) \ - { \ - std::stringstream oss_internal_rare; \ - oss_internal_rare << message; \ - (logger)->trace(oss_internal_rare.str()); \ - } \ - } while (false) - -#define LOG_DEBUG(logger, message) \ - do \ - { \ - if ((logger)->debug()) \ - { \ - std::stringstream oss_internal_rare; \ - oss_internal_rare << message; \ - (logger)->debug(oss_internal_rare.str()); \ - } \ - } while (false) - -#define LOG_INFO(logger, message) \ - do \ - { \ - if ((logger)->information()) \ - { \ - std::stringstream oss_internal_rare; \ - oss_internal_rare << message; \ - (logger)->information(oss_internal_rare.str()); \ - } \ - } while (false) - -#define LOG_WARNING(logger, message) \ - do \ - { \ - if ((logger)->warning()) \ - { \ - std::stringstream oss_internal_rare; \ - oss_internal_rare << message; \ - (logger)->warning(oss_internal_rare.str()); \ - } \ - } while (false) - -#define LOG_ERROR(logger, message) \ - do \ - { \ - if ((logger)->error()) \ - { \ - std::stringstream oss_internal_rare; \ - oss_internal_rare << message; \ - (logger)->error(oss_internal_rare.str()); \ - } \ - } while (false) - namespace LogFmtDetails { template @@ -118,6 +64,55 @@ std::string toCheckedFmtStr(const S & format, const Ignored &, Args &&... args) } } // namespace LogFmtDetails +/// Logs a message to a specified logger with that level. + +#if KEEP_STRINGSTREAM_FOR_LOG + +#define LOG_IMPL(logger, PRIORITY, message) \ + do \ + { \ + if ((logger)->is((PRIORITY))) \ + { \ + std::stringstream oss_internal_rare; \ + oss_internal_rare << message; /* NOLINT */ \ + Poco::Message poco_message( \ + /*source*/ (logger)->name(), \ + /*text*/ oss_internal_rare.str(), \ + /*prio*/ (PRIORITY), \ + /*file*/ &__FILE__[LogFmtDetails::getFileNameOffset(__FILE__)], \ + /*line*/ __LINE__); \ + (logger)->log(poco_message); \ + } \ + } while (false) + +#define LOG_TRACE(logger, ...) LOG_IMPL(logger, Poco::Message::PRIO_TRACE, __VA_ARGS__) +#define LOG_DEBUG(logger, ...) LOG_IMPL(logger, Poco::Message::PRIO_DEBUG, __VA_ARGS__) +#define LOG_INFO(logger, ...) LOG_IMPL(logger, Poco::Message::PRIO_INFORMATION, __VA_ARGS__) +#define LOG_WARNING(logger, ...) LOG_IMPL(logger, Poco::Message::PRIO_WARNING, __VA_ARGS__) +#define LOG_ERROR(logger, ...) LOG_IMPL(logger, Poco::Message::PRIO_ERROR, __VA_ARGS__) +#else +#define LOG_IMPL(logger, PRIORITY, message) \ + do \ + { \ + if ((logger)->is((PRIORITY))) \ + { \ + Poco::Message poco_message( \ + /*source*/ (logger)->name(), \ + /*text*/ message, \ + /*prio*/ (PRIORITY), \ + /*file*/ &__FILE__[LogFmtDetails::getFileNameOffset(__FILE__)], \ + /*line*/ __LINE__); \ + (logger)->log(poco_message); \ + } \ + } while (false) + +#define LOG_TRACE(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_TRACE, message) +#define LOG_DEBUG(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_DEBUG, message) +#define LOG_INFO(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_INFORMATION, message) +#define LOG_WARNING(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_WARNING, message) +#define LOG_ERROR(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_ERROR, message) +#endif // KEEP_STRINGSTREAM_FOR_LOG + /// Logs a message to a specified logger with that level. /// If more than one argument is provided, diff --git a/libs/libcommon/src/tests/gtest_logger.cpp b/libs/libcommon/src/tests/gtest_logger.cpp index feeef7ef429..576c7a500a1 100644 --- a/libs/libcommon/src/tests/gtest_logger.cpp +++ b/libs/libcommon/src/tests/gtest_logger.cpp @@ -54,11 +54,26 @@ class LoggerUsefulTest : public ::testing::Test TEST_F(LoggerUsefulTest, Log) { auto * log = getLogger(); +#if KEEP_STRINGSTREAM_FOR_LOG + LOG_TRACE(log, "Trace log, num: " << 1); + LOG_DEBUG(log, "Debug log, num: " << 1); + LOG_INFO(log, "Info log, num: " << 1); + LOG_WARNING(log, "Warning log, num: " << 1); + LOG_ERROR(log, "Error log, num: " << 1); +#else LOG_TRACE(log, "Trace log"); LOG_DEBUG(log, "Debug log"); LOG_INFO(log, "Info log"); LOG_WARNING(log, "Warning log"); LOG_ERROR(log, "Error log"); + + // Do not accept more than one parameter + // LOG_ERROR(log, "Error log, num: ", 1); +#endif + + std::string msg_in_log; + msg_in_log = "hello tiflash"; + LOG_DEBUG(log, msg_in_log); } TEST_F(LoggerUsefulTest, LogFmt) @@ -69,6 +84,11 @@ TEST_F(LoggerUsefulTest, LogFmt) LOG_FMT_INFO(log, "Info log"); LOG_FMT_WARNING(log, "Warning log"); LOG_FMT_ERROR(log, "Error log"); + + // Error! Do not accept a variable as format string. + // std::string msg_in_log; + // msg_in_log = "hello tiflash"; + // LOG_FMT_DEBUG(log, msg_in_log); } } // namespace tests From 56354b864adc6069553c25f30eca2a8a62a998cb Mon Sep 17 00:00:00 2001 From: JaySon-Huang Date: Thu, 24 Mar 2022 13:51:08 +0800 Subject: [PATCH 2/8] Remove KEEP_STRINGSTREAM_FOR_LOG --- libs/libcommon/include/common/logger_useful.h | 31 ------------------- libs/libcommon/src/tests/gtest_logger.cpp | 8 ----- 2 files changed, 39 deletions(-) diff --git a/libs/libcommon/include/common/logger_useful.h b/libs/libcommon/include/common/logger_useful.h index e6270cb97f6..0693698d504 100644 --- a/libs/libcommon/include/common/logger_useful.h +++ b/libs/libcommon/include/common/logger_useful.h @@ -19,11 +19,6 @@ #include #include -#define KEEP_STRINGSTREAM_FOR_LOG 1 // TODO: Disable it after we cleanup all stringstream in logging -#if KEEP_STRINGSTREAM_FOR_LOG -#include -#endif - #ifndef QUERY_PREVIEW_LENGTH #define QUERY_PREVIEW_LENGTH 160 #endif @@ -66,31 +61,6 @@ std::string toCheckedFmtStr(const S & format, const Ignored &, Args &&... args) /// Logs a message to a specified logger with that level. -#if KEEP_STRINGSTREAM_FOR_LOG - -#define LOG_IMPL(logger, PRIORITY, message) \ - do \ - { \ - if ((logger)->is((PRIORITY))) \ - { \ - std::stringstream oss_internal_rare; \ - oss_internal_rare << message; /* NOLINT */ \ - Poco::Message poco_message( \ - /*source*/ (logger)->name(), \ - /*text*/ oss_internal_rare.str(), \ - /*prio*/ (PRIORITY), \ - /*file*/ &__FILE__[LogFmtDetails::getFileNameOffset(__FILE__)], \ - /*line*/ __LINE__); \ - (logger)->log(poco_message); \ - } \ - } while (false) - -#define LOG_TRACE(logger, ...) LOG_IMPL(logger, Poco::Message::PRIO_TRACE, __VA_ARGS__) -#define LOG_DEBUG(logger, ...) LOG_IMPL(logger, Poco::Message::PRIO_DEBUG, __VA_ARGS__) -#define LOG_INFO(logger, ...) LOG_IMPL(logger, Poco::Message::PRIO_INFORMATION, __VA_ARGS__) -#define LOG_WARNING(logger, ...) LOG_IMPL(logger, Poco::Message::PRIO_WARNING, __VA_ARGS__) -#define LOG_ERROR(logger, ...) LOG_IMPL(logger, Poco::Message::PRIO_ERROR, __VA_ARGS__) -#else #define LOG_IMPL(logger, PRIORITY, message) \ do \ { \ @@ -111,7 +81,6 @@ std::string toCheckedFmtStr(const S & format, const Ignored &, Args &&... args) #define LOG_INFO(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_INFORMATION, message) #define LOG_WARNING(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_WARNING, message) #define LOG_ERROR(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_ERROR, message) -#endif // KEEP_STRINGSTREAM_FOR_LOG /// Logs a message to a specified logger with that level. diff --git a/libs/libcommon/src/tests/gtest_logger.cpp b/libs/libcommon/src/tests/gtest_logger.cpp index 576c7a500a1..ba67e65821e 100644 --- a/libs/libcommon/src/tests/gtest_logger.cpp +++ b/libs/libcommon/src/tests/gtest_logger.cpp @@ -54,13 +54,6 @@ class LoggerUsefulTest : public ::testing::Test TEST_F(LoggerUsefulTest, Log) { auto * log = getLogger(); -#if KEEP_STRINGSTREAM_FOR_LOG - LOG_TRACE(log, "Trace log, num: " << 1); - LOG_DEBUG(log, "Debug log, num: " << 1); - LOG_INFO(log, "Info log, num: " << 1); - LOG_WARNING(log, "Warning log, num: " << 1); - LOG_ERROR(log, "Error log, num: " << 1); -#else LOG_TRACE(log, "Trace log"); LOG_DEBUG(log, "Debug log"); LOG_INFO(log, "Info log"); @@ -69,7 +62,6 @@ TEST_F(LoggerUsefulTest, Log) // Do not accept more than one parameter // LOG_ERROR(log, "Error log, num: ", 1); -#endif std::string msg_in_log; msg_in_log = "hello tiflash"; From 084a977272713579bd2b836ce277c399f224eeb8 Mon Sep 17 00:00:00 2001 From: JaySon-Huang Date: Mon, 28 Mar 2022 13:17:34 +0800 Subject: [PATCH 3/8] Fix log && some comment --- dbms/src/Client/Connection.cpp | 27 +++--- dbms/src/Storages/DeltaMerge/WriteBatches.h | 8 +- libs/libdaemon/include/daemon/BaseDaemon.h | 91 ++++++++----------- .../libdaemon/include/daemon/GraphiteWriter.h | 48 ++++++---- .../include/daemon/OwnPatternFormatter.h | 24 +++-- libs/libdaemon/src/BaseDaemon.cpp | 26 +++--- 6 files changed, 114 insertions(+), 110 deletions(-) diff --git a/dbms/src/Client/Connection.cpp b/dbms/src/Client/Connection.cpp index ec31782452a..1758e0e57fb 100644 --- a/dbms/src/Client/Connection.cpp +++ b/dbms/src/Client/Connection.cpp @@ -17,6 +17,7 @@ #include #include #include +#include #include #include #include @@ -451,21 +452,25 @@ void Connection::sendExternalTablesData(ExternalTablesData & data) out_bytes = out->count() - out_bytes; maybe_compressed_out_bytes = maybe_compressed_out->count() - maybe_compressed_out_bytes; - double elapsed = watch.elapsedSeconds(); - - std::stringstream msg; - msg << std::fixed << std::setprecision(3); - msg << "Sent data for " << data.size() << " external tables, total " << rows << " rows in " << elapsed << " sec., " - << static_cast(rows / watch.elapsedSeconds()) << " rows/sec., " - << maybe_compressed_out_bytes / 1048576.0 << " MiB (" << maybe_compressed_out_bytes / 1048576.0 / watch.elapsedSeconds() << " MiB/sec.)"; + const double elapsed_seconds = watch.elapsedSeconds(); + + FmtBuffer fmt_buf; + fmt_buf.fmtAppend( + "Sent data for {} external tables, total {} rows in {:.3f} sec., {:.3f} rows/sec., " + "{:.3f} MiB ({:.3f} MiB/sec.)", + data.size(), + rows, + elapsed_seconds, + 1.0 * rows / elapsed_seconds, + maybe_compressed_out_bytes / 1048576.0, + maybe_compressed_out_bytes / 1048576.0 / elapsed_seconds); if (compression == Protocol::Compression::Enable) - msg << ", compressed " << static_cast(maybe_compressed_out_bytes) / out_bytes << " times to " - << out_bytes / 1048576.0 << " MiB (" << out_bytes / 1048576.0 / watch.elapsedSeconds() << " MiB/sec.)"; + fmt_buf.fmtAppend(", compressed {:.3f} times to {:.3f} MiB ({:.3f} MiB/sec.)", 1.0 * maybe_compressed_out_bytes / out_bytes, out_bytes / 1048576.0, out_bytes / 1048576.0 / elapsed_seconds); else - msg << ", no compression."; + fmt_buf.append(", no compression."); - LOG_DEBUG(log_wrapper.get(), msg.rdbuf()); + LOG_DEBUG(log_wrapper.get(), fmt_buf.toString()); } diff --git a/dbms/src/Storages/DeltaMerge/WriteBatches.h b/dbms/src/Storages/DeltaMerge/WriteBatches.h index 67eb5c0c43d..222bc021ce4 100644 --- a/dbms/src/Storages/DeltaMerge/WriteBatches.h +++ b/dbms/src/Storages/DeltaMerge/WriteBatches.h @@ -62,10 +62,10 @@ struct WriteBatches : private boost::noncopyable if (!wb.empty()) { StackTrace trace; - LOG_ERROR(logger, - "!!!=========================Modifications in " + name - + " haven't persisted=========================!!! Stack trace: " - << trace.toString()); + LOG_FMT_ERROR(logger, + "!!!=========================Modifications in {} haven't persisted=========================!!! Stack trace: {}", + name, + trace.toString()); } }; check_empty(log, "log"); diff --git a/libs/libdaemon/include/daemon/BaseDaemon.h b/libs/libdaemon/include/daemon/BaseDaemon.h index 20d432efe14..5831bf5857e 100644 --- a/libs/libdaemon/include/daemon/BaseDaemon.h +++ b/libs/libdaemon/include/daemon/BaseDaemon.h @@ -40,28 +40,19 @@ #include #include -/// \brief Базовый класс для демонов +/// \brief Base class for applications that can run as daemons. /// /// \code -/// # Список возможных опций командной строки обрабатываемых демоном: -/// # --config-file или --config - имя файла конфигурации. По умолчанию - config.xml -/// # --pid-file - имя PID файла. По умолчанию - pid -/// # --log-file - имя лог файла -/// # --error-file - имя лог файла, в который будут помещаться только ошибки -/// # --daemon - запустить в режиме демона; если не указан - логгирование будет вестись на консоль -/// --daemon --config-file=localfile.xml --pid-file=pid.pid --log-file=log.log --errorlog-file=error.log +/// # Some possible command line options: +/// # --config-file, -C or --config - path to configuration file. By default - config.xml in the current directory. +/// # --log-file +/// # --errorlog-file +/// # --daemon - run as daemon; without this option, the program will be attached to the terminal and also output logs to stderr. +/// --daemon --config-file=localfile.xml --log-file=log.log --errorlog-file=error.log /// \endcode /// -/// Если неперехваченное исключение выкинуто в других потоках (не Task-и), то по-умолчанию -/// используется KillingErrorHandler, который вызывает std::terminate. -/// -/// Кроме того, класс позволяет достаточно гибко управлять журналированием. В методе initialize() вызывается метод -/// buildLoggers() который и строит нужные логгеры. Эта функция ожидает увидеть в конфигурации определённые теги -/// заключённые в секции "logger". -/// Если нужно журналирование на консоль, нужно просто не использовать тег "log" или использовать --console. -/// Теги уровней вывода использовать можно в любом случае - - +/// You can configure different log options for different loggers used inside program +/// by providing subsections to "logger" in configuration file. class BaseDaemon : public Poco::Util::ServerApplication { friend class SignalListener; @@ -72,31 +63,30 @@ class BaseDaemon : public Poco::Util::ServerApplication BaseDaemon(); ~BaseDaemon(); - /// Загружает конфигурацию и "строит" логгеры на запись в файлы + /// Load configuration, prepare loggers, etc. void initialize(Poco::Util::Application &) override; - /// Читает конфигурацию + /// Reads the configuration void reloadConfiguration(); - /// Строит необходимые логгеры + /// Builds the necessary loggers void buildLoggers(Poco::Util::AbstractConfiguration & config); - /// Определяет параметр командной строки + /// Process command line parameters void defineOptions(Poco::Util::OptionSet & _options) override; - /// Завершение демона ("мягкое") + /// Graceful shutdown void terminate(); - /// Завершение демона ("жёсткое") + /// Forceful shutdown void kill(); - /// Получен ли сигнал на завершение? + /// Cancellation request has been received. bool isCancelled() const { return is_cancelled; } - /// Получение ссылки на экземпляр демона static BaseDaemon & instance() { return dynamic_cast(Poco::Util::Application::instance()); @@ -105,23 +95,22 @@ class BaseDaemon : public Poco::Util::ServerApplication /// return none if daemon doesn't exist, reference to the daemon otherwise static std::optional> tryGetInstance() { return tryGetInstance(); } - /// Спит заданное количество секунд или до события wakeup + /// Sleeps for the set number of seconds or until wakeup event void sleep(double seconds); - /// Разбудить void wakeup(); - /// Закрыть файлы с логами. При следующей записи, будут созданы новые файлы. + /// Close the log files. The next time you write, new files will be created. void closeLogs(); - /// В Graphite компоненты пути(папки) разделяются точкой. - /// У нас принят путь формата root_path.hostname_yandex_ru.key - /// root_path по умолчанию one_min - /// key - лучше группировать по смыслу. Например "meminfo.cached" или "meminfo.free", "meminfo.total" + /// In Graphite, path(folder) components are separated by a dot. + /// We have adopted the format root_path.hostname_yandex_ru.key + /// root_path is by default one_min + /// key - better to group by meaning. For example "meminfo.cached" or "meminfo.free", "meminfo.total" template void writeToGraphite(const std::string & key, const T & value, const std::string & config_name = DEFAULT_GRAPHITE_CONFIG_NAME, time_t timestamp = 0, const std::string & custom_root_path = "") { - auto writer = getGraphiteWriter(config_name); + auto * writer = getGraphiteWriter(config_name); if (writer) writer->write(key, value, timestamp, custom_root_path); } @@ -129,7 +118,7 @@ class BaseDaemon : public Poco::Util::ServerApplication template void writeToGraphite(const GraphiteWriter::KeyValueVector & key_vals, const std::string & config_name = DEFAULT_GRAPHITE_CONFIG_NAME, time_t timestamp = 0, const std::string & custom_root_path = "") { - auto writer = getGraphiteWriter(config_name); + auto * writer = getGraphiteWriter(config_name); if (writer) writer->write(key_vals, timestamp, custom_root_path); } @@ -137,7 +126,7 @@ class BaseDaemon : public Poco::Util::ServerApplication template void writeToGraphite(const GraphiteWriter::KeyValueVector & key_vals, const std::chrono::system_clock::time_point & current_time, const std::string & custom_root_path) { - auto writer = getGraphiteWriter(); + auto * writer = getGraphiteWriter(); if (writer) writer->write(key_vals, std::chrono::system_clock::to_time_t(current_time), custom_root_path); } @@ -151,21 +140,21 @@ class BaseDaemon : public Poco::Util::ServerApplication std::optional getLayer() const { - return layer; /// layer выставляется в классе-наследнике BaseDaemonApplication. + return layer; } protected: virtual void logRevision() const; - /// Используется при exitOnTaskError() + /// Used when exitOnTaskError() void handleNotification(Poco::TaskFailedNotification *); /// thread safe virtual void handleSignal(int signal_id); - /// реализация обработки сигналов завершения через pipe не требует блокировки сигнала с помощью sigprocmask во всех потоках + /// implementation of pipe termination signal handling does not require blocking the signal with sigprocmask in all threads void waitForTerminationRequest() -#if POCO_CLICKHOUSE_PATCH || POCO_VERSION >= 0x02000000 // in old upstream poco not vitrual +#if POCO_CLICKHOUSE_PATCH || POCO_VERSION >= 0x02000000 // in old upstream poco not virtual override #endif ; @@ -177,21 +166,21 @@ class BaseDaemon : public Poco::Util::ServerApplication virtual std::string getDefaultCorePath() const; - /// Создание и автоматическое удаление pid файла. + /// Creation and automatic deletion of a pid file. struct PID { std::string file; - /// Создать объект, не создавая PID файл - PID() {} + /// Create an object without creating a PID file + PID() = default; - /// Создать объект, создать PID файл - PID(const std::string & file_) { seed(file_); } + /// Create object, create PID file + explicit PID(const std::string & file_) { seed(file_); } - /// Создать PID файл + /// Create a PID file void seed(const std::string & file_); - /// Удалить PID файл + /// Delete PID file void clear(); ~PID() { clear(); } @@ -201,19 +190,19 @@ class BaseDaemon : public Poco::Util::ServerApplication std::atomic_bool is_cancelled{false}; - /// Флаг устанавливается по сообщению из Task (при аварийном завершении). + /// The flag is set by a message from Task (in case of an emergency stop). bool task_failed = false; bool log_to_console = false; - /// Событие, чтобы проснуться во время ожидания + /// An event to wake up to while waiting Poco::Event wakeup_event; - /// Поток, в котором принимается сигнал HUP/USR1 для закрытия логов. + /// The stream in which the HUP/USR1 signal is received to close the logs. Poco::Thread signal_listener_thread; std::unique_ptr signal_listener; - /// Файлы с логами. + /// Log files. Poco::AutoPtr log_file; Poco::AutoPtr error_log_file; Poco::AutoPtr tracing_log_file; diff --git a/libs/libdaemon/include/daemon/GraphiteWriter.h b/libs/libdaemon/include/daemon/GraphiteWriter.h index 06f07c7a107..452fd693acf 100644 --- a/libs/libdaemon/include/daemon/GraphiteWriter.h +++ b/libs/libdaemon/include/daemon/GraphiteWriter.h @@ -14,46 +14,51 @@ #pragma once -#include -#include -#include #include +#include #include #include +#include + +#include -/// пишет в Graphite данные в формате +/// Writes to Graphite in the following format /// path value timestamp\n -/// path может иметь любую вложенность. Директории разделяются с помощью "." -/// у нас принят следующий формат path - root_path.server_name.sub_path.key +/// path can be arbitrary nested. Elements are separated by '.' +/// Example: root_path.server_name.sub_path.key class GraphiteWriter { public: - GraphiteWriter(const std::string & config_name, const std::string & sub_path = ""); + explicit GraphiteWriter(const std::string & config_name, const std::string & sub_path = ""); - template using KeyValuePair = std::pair; - template using KeyValueVector = std::vector>; + template + using KeyValuePair = std::pair; + template + using KeyValueVector = std::vector>; - template void write(const std::string & key, const T & value, - time_t timestamp = 0, const std::string & custom_root_path = "") + template + void write(const std::string & key, const T & value, time_t timestamp = 0, const std::string & custom_root_path = "") { - writeImpl(KeyValuePair{ key, value }, timestamp, custom_root_path); + writeImpl(KeyValuePair{key, value}, timestamp, custom_root_path); } - template void write(const KeyValueVector & key_val_vec, - time_t timestamp = 0, const std::string & custom_root_path = "") + template + void write(const KeyValueVector & key_val_vec, + time_t timestamp = 0, + const std::string & custom_root_path = "") { writeImpl(key_val_vec, timestamp, custom_root_path); } - /// возвращает путь root_path.server_name static std::string getPerServerPath(const std::string & server_name, const std::string & root_path = "one_min"); + private: template void writeImpl(const T & data, time_t timestamp, const std::string & custom_root_path) { if (!timestamp) - timestamp = time(0); + timestamp = time(nullptr); try { @@ -66,16 +71,19 @@ class GraphiteWriter } catch (const Poco::Exception & e) { - LOG_WARNING(&Poco::Util::Application::instance().logger(), - "Fail to write to Graphite " << host << ":" << port << ". e.what() = " << e.what() << ", e.message() = " << e.message()); + LOG_FMT_WARNING(&Poco::Util::Application::instance().logger(), + "Fail to write to Graphite {}:{}. e.what() = {}, e.message() = {}", + host, + port, + e.what(), + e.message()); } } template void out(std::ostream & os, const KeyValuePair & key_val, time_t timestamp, const std::string & custom_root_path) { - os << (custom_root_path.empty() ? root_path : custom_root_path) << - '.' << key_val.first << ' ' << key_val.second << ' ' << timestamp << '\n'; + os << (custom_root_path.empty() ? root_path : custom_root_path) << '.' << key_val.first << ' ' << key_val.second << ' ' << timestamp << '\n'; } template diff --git a/libs/libdaemon/include/daemon/OwnPatternFormatter.h b/libs/libdaemon/include/daemon/OwnPatternFormatter.h index 4ebadcb5ad3..c2b1bd17210 100644 --- a/libs/libdaemon/include/daemon/OwnPatternFormatter.h +++ b/libs/libdaemon/include/daemon/OwnPatternFormatter.h @@ -18,18 +18,18 @@ #include -/** Форматирует по своему. - * Некоторые детали невозможно получить, используя только Poco::PatternFormatter. +/** Format log messages own way. + * We can't obtain some details using Poco::PatternFormatter. * - * Во-первых, используется номер потока не среди потоков Poco::Thread, - * а среди всех потоков, для которых был получен номер (см. ThreadNumber.h) + * Firstly, the thread number here is peaked not from Poco::Thread + * threads only, but from all threads with number assigned (see ThreadNumber.h) * - * Во-вторых, корректно выводится локальная дата и время. - * Poco::PatternFormatter плохо работает с локальным временем, - * в ситуациях, когда в ближайшем будущем намечается отмена или введение daylight saving time. - * - см. исходники Poco и http://thread.gmane.org/gmane.comp.time.tz/8883 + * Secondly, the local date and time are correctly displayed. + * Poco::PatternFormatter does not work well with local time, + * when timestamps are close to DST timeshift moments. + * - see Poco sources and http://thread.gmane.org/gmane.comp.time.tz/8883 * - * Также сделан чуть более эффективным (что имеет мало значения). + * Also it's made a bit more efficient (unimportant). */ class BaseDaemon; @@ -44,7 +44,11 @@ class OwnPatternFormatter : public Poco::PatternFormatter ADD_LAYER_TAG = 1 << 0 }; - OwnPatternFormatter(const BaseDaemon * daemon_, Options options_ = ADD_NOTHING) : Poco::PatternFormatter(""), daemon(daemon_), options(options_) {} + explicit OwnPatternFormatter(const BaseDaemon * daemon_, Options options_ = ADD_NOTHING) + : Poco::PatternFormatter("") + , daemon(daemon_) + , options(options_) + {} void format(const Poco::Message & msg, std::string & text) override; diff --git a/libs/libdaemon/src/BaseDaemon.cpp b/libs/libdaemon/src/BaseDaemon.cpp index cbd264668a2..af8fe42417d 100644 --- a/libs/libdaemon/src/BaseDaemon.cpp +++ b/libs/libdaemon/src/BaseDaemon.cpp @@ -366,7 +366,7 @@ class SignalListener : public Poco::Runnable private: void onTerminate(const std::string & message, ThreadNumber thread_num) const { - LOG_ERROR(log, "(from thread " << thread_num << ") " << message); + LOG_FMT_ERROR(log, "(from thread {}) {}", thread_num, message); } #if USE_UNWIND void onFault(int sig, siginfo_t & info, ucontext_t & context, unw_context_t & unw_context, ThreadNumber thread_num) const @@ -374,10 +374,8 @@ class SignalListener : public Poco::Runnable void onFault(int sig, siginfo_t & info, ucontext_t & context, ThreadNumber thread_num) const #endif { - LOG_ERROR(log, "########################################"); - LOG_ERROR(log, "(from thread " << thread_num << ") " - << "Received signal " << strsignal(sig) << " (" << sig << ")" - << "."); + LOG_FMT_ERROR(log, "########################################"); + LOG_FMT_ERROR(log, "(from thread {}) Received signal {}({}).", thread_num, strsignal(sig), sig); void * caller_address = nullptr; @@ -407,7 +405,7 @@ class SignalListener : public Poco::Runnable if (nullptr == info.si_addr) LOG_ERROR(log, "Address: NULL pointer."); else - LOG_ERROR(log, "Address: " << info.si_addr); + LOG_FMT_ERROR(log, "Address: {}", info.si_addr); #if defined(__x86_64__) && !defined(__FreeBSD__) && !defined(__APPLE__) if ((err_mask & 0x02)) @@ -601,7 +599,7 @@ static void terminate_handler() int status = -1; char * dem = nullptr; - dem = abi::__cxa_demangle(name, 0, 0, &status); + dem = abi::__cxa_demangle(name, nullptr, nullptr, &status); log << "Terminate called after throwing an instance of " << (status == 0 ? dem : name) << std::endl; @@ -676,7 +674,7 @@ static bool tryCreateDirectories(Poco::Logger * logger, const std::string & path } catch (...) { - LOG_WARNING(logger, __PRETTY_FUNCTION__ << ": when creating " << path << ", " << DB::getCurrentExceptionMessage(true)); + LOG_FMT_WARNING(logger, "when creating {}, {}", path, DB::getCurrentExceptionMessage(true)); } return false; } @@ -899,8 +897,8 @@ void BaseDaemon::buildLoggers(Poco::Util::AbstractConfiguration & config) config.keys("logger.levels", levels); if (!levels.empty()) - for (AbstractConfiguration::Keys::iterator it = levels.begin(); it != levels.end(); ++it) - Logger::get(*it).setLevel(config.getString("logger.levels." + *it, "trace")); + for (auto & level : levels) + Logger::get(level).setLevel(config.getString("logger.levels." + level, "trace")); } @@ -931,7 +929,7 @@ void BaseDaemon::initialize(Application & self) /// Test: -- --1=1 --1=2 --3 5 7 8 -9 10 -11=12 14= 15== --16==17 --=18 --19= --20 21 22 --23 --24 25 --26 -27 28 ---29=30 -- ----31 32 --33 3-4 Poco::AutoPtr map_config = new Poco::Util::MapConfiguration; std::string key; - for (auto & arg : argv()) + for (const auto & arg : argv()) { auto key_start = arg.find_first_not_of('-'); auto pos_minus = arg.find('-'); @@ -1132,7 +1130,7 @@ void BaseDaemon::initialize(Application & self) throw Poco::Exception("Cannot set signal handler."); for (auto signal : signals) - if (sigaction(signal, &sa, 0)) + if (sigaction(signal, &sa, nullptr)) throw Poco::Exception("Cannot set signal handler."); } }; @@ -1171,7 +1169,7 @@ void BaseDaemon::handleNotification(Poco::TaskFailedNotification * _tfn) task_failed = true; AutoPtr fn(_tfn); Logger * lg = &(logger()); - LOG_ERROR(lg, "Task '" << fn->task()->name() << "' failed. Daemon is shutting down. Reason - " << fn->reason().displayText()); + LOG_FMT_ERROR(lg, "Task '{}' failed. Daemon is shutting down. Reason - {}", fn->task()->name(), fn->reason().displayText()); ServerApplication::terminate(); } @@ -1298,7 +1296,7 @@ void BaseDaemon::handleSignal(int signal_id) void BaseDaemon::onInterruptSignals(int signal_id) { is_cancelled = true; - LOG_INFO(&logger(), "Received termination signal (" << strsignal(signal_id) << ")"); + LOG_FMT_INFO(&logger(), "Received termination signal ({})", strsignal(signal_id)); if (sigint_signals_counter >= 2) { From 0504b75fa7028a4437854b592288354c2504a2ea Mon Sep 17 00:00:00 2001 From: JaySon-Huang Date: Tue, 29 Mar 2022 18:16:52 +0800 Subject: [PATCH 4/8] Use lambda for generating log msg when we actually need it --- dbms/src/Client/Connection.cpp | 40 +++++++++++++++++++--------------- 1 file changed, 22 insertions(+), 18 deletions(-) diff --git a/dbms/src/Client/Connection.cpp b/dbms/src/Client/Connection.cpp index 1758e0e57fb..61a2843ac59 100644 --- a/dbms/src/Client/Connection.cpp +++ b/dbms/src/Client/Connection.cpp @@ -452,25 +452,29 @@ void Connection::sendExternalTablesData(ExternalTablesData & data) out_bytes = out->count() - out_bytes; maybe_compressed_out_bytes = maybe_compressed_out->count() - maybe_compressed_out_bytes; - const double elapsed_seconds = watch.elapsedSeconds(); - - FmtBuffer fmt_buf; - fmt_buf.fmtAppend( - "Sent data for {} external tables, total {} rows in {:.3f} sec., {:.3f} rows/sec., " - "{:.3f} MiB ({:.3f} MiB/sec.)", - data.size(), - rows, - elapsed_seconds, - 1.0 * rows / elapsed_seconds, - maybe_compressed_out_bytes / 1048576.0, - maybe_compressed_out_bytes / 1048576.0 / elapsed_seconds); - - if (compression == Protocol::Compression::Enable) - fmt_buf.fmtAppend(", compressed {:.3f} times to {:.3f} MiB ({:.3f} MiB/sec.)", 1.0 * maybe_compressed_out_bytes / out_bytes, out_bytes / 1048576.0, out_bytes / 1048576.0 / elapsed_seconds); - else - fmt_buf.append(", no compression."); - LOG_DEBUG(log_wrapper.get(), fmt_buf.toString()); + auto get_logging_msg = [&]() -> String { + const double elapsed_seconds = watch.elapsedSeconds(); + + FmtBuffer fmt_buf; + fmt_buf.fmtAppend( + "Sent data for {} external tables, total {} rows in {:.3f} sec., {:.3f} rows/sec., " + "{:.3f} MiB ({:.3f} MiB/sec.)", + data.size(), + rows, + elapsed_seconds, + 1.0 * rows / elapsed_seconds, + maybe_compressed_out_bytes / 1048576.0, + maybe_compressed_out_bytes / 1048576.0 / elapsed_seconds); + + if (compression == Protocol::Compression::Enable) + fmt_buf.fmtAppend(", compressed {:.3f} times to {:.3f} MiB ({:.3f} MiB/sec.)", 1.0 * maybe_compressed_out_bytes / out_bytes, out_bytes / 1048576.0, out_bytes / 1048576.0 / elapsed_seconds); + else + fmt_buf.append(", no compression."); + return fmt_buf.toString(); + }; + + LOG_DEBUG(log_wrapper.get(), get_logging_msg()); } From 3d378ae2fd9d5b9623f77815610f11faecf8e7c5 Mon Sep 17 00:00:00 2001 From: JaySon-Huang Date: Tue, 29 Mar 2022 18:34:55 +0800 Subject: [PATCH 5/8] Fix compile error --- .../src/tests/gtest_daemon_config.cpp | 20 +++++++++---------- 1 file changed, 10 insertions(+), 10 deletions(-) diff --git a/libs/libdaemon/src/tests/gtest_daemon_config.cpp b/libs/libdaemon/src/tests/gtest_daemon_config.cpp index d9eee8dd8c0..1fefad2c497 100644 --- a/libs/libdaemon/src/tests/gtest_daemon_config.cpp +++ b/libs/libdaemon/src/tests/gtest_daemon_config.cpp @@ -29,11 +29,11 @@ #include #include -class DaemonConfig_test : public ::testing::Test +class DaemonConfigTest : public ::testing::Test { public: - DaemonConfig_test() - : log(&Poco::Logger::get("DaemonConfig_test")) + DaemonConfigTest() + : log(&Poco::Logger::get("DaemonConfigTest")) { } @@ -41,7 +41,7 @@ class DaemonConfig_test : public ::testing::Test protected: Poco::Logger * log; - void clearFiles(String path) + static void clearFiles(String path) { Poco::File file(path); if (file.exists()) @@ -127,7 +127,7 @@ struct TestDaemon : public BaseDaemon } }; -TEST_F(DaemonConfig_test, ReloadLoggerConfig) +TEST_F(DaemonConfigTest, ReloadLoggerConfig) try { DB::Strings tests = { @@ -188,7 +188,7 @@ size = "1" }; BaseDaemon app; - auto verifyLoggersConfig = [](size_t logger_num, Poco::Util::AbstractConfiguration & config) { + auto verify_loggers_config = [](size_t logger_num, Poco::Util::AbstractConfiguration & config) { for (size_t j = 0; j < logger_num; j++) { Poco::Logger & cur_logger = Poco::Logger::get(fmt::format("ReloadLoggerConfig_test{}", j)); @@ -207,8 +207,8 @@ size = "1" auto config = loadConfigFromString(test_case); app.buildLoggers(*config); Poco::Logger::get(fmt::format("ReloadLoggerConfig_test{}", i)); - LOG_INFO(log, "parsing [index=" << i << "] [content=" << test_case << "]"); - verifyLoggersConfig(i + 1, *config); + LOG_FMT_INFO(log, "parsing [index={}] [content={}]", i, test_case); + verify_loggers_config(i + 1, *config); } clearFiles("./tmp/log"); } @@ -219,7 +219,7 @@ extern "C" char ** environ; #if USE_UNWIND TEST(BaseDaemon, StackUnwind) { - auto conf = R"( + const auto * conf = R"( [application] runAsDaemon = false [profiles] @@ -248,7 +248,7 @@ level = "debug" return; } char abs_path[PATH_MAX]{}; - ::readlink("/proc/self/exe", abs_path, sizeof(abs_path)); + (void)::readlink("/proc/self/exe", abs_path, sizeof(abs_path)); auto stdout_name = fmt::format("/tmp/{}-{}.stdout", reinterpret_cast(&abs_path), ::time(nullptr)); auto stderr_name = fmt::format("/tmp/{}-{}.stderr", reinterpret_cast(&abs_path), ::time(nullptr)); auto stdout_fd = ::open(stdout_name.c_str(), O_CREAT | O_TRUNC | O_RDWR, S_IRUSR | S_IWUSR); From 56fb9d89e75ce354af1cc5dea9e0153825968eb4 Mon Sep 17 00:00:00 2001 From: JaySon-Huang Date: Wed, 30 Mar 2022 11:07:59 +0800 Subject: [PATCH 6/8] Add LOG_FATAL --- libs/libcommon/include/common/logger_useful.h | 1 + 1 file changed, 1 insertion(+) diff --git a/libs/libcommon/include/common/logger_useful.h b/libs/libcommon/include/common/logger_useful.h index 0693698d504..21604dd5470 100644 --- a/libs/libcommon/include/common/logger_useful.h +++ b/libs/libcommon/include/common/logger_useful.h @@ -81,6 +81,7 @@ std::string toCheckedFmtStr(const S & format, const Ignored &, Args &&... args) #define LOG_INFO(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_INFORMATION, message) #define LOG_WARNING(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_WARNING, message) #define LOG_ERROR(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_ERROR, message) +#define LOG_FATAL(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_FATAL, message) /// Logs a message to a specified logger with that level. From 825f387a4671ae574319c7dd3561327637029bc9 Mon Sep 17 00:00:00 2001 From: JaySon-Huang Date: Wed, 30 Mar 2022 11:09:52 +0800 Subject: [PATCH 7/8] Add missed comment --- libs/libdaemon/include/daemon/BaseDaemon.h | 1 + 1 file changed, 1 insertion(+) diff --git a/libs/libdaemon/include/daemon/BaseDaemon.h b/libs/libdaemon/include/daemon/BaseDaemon.h index 5831bf5857e..6934feb4a90 100644 --- a/libs/libdaemon/include/daemon/BaseDaemon.h +++ b/libs/libdaemon/include/daemon/BaseDaemon.h @@ -45,6 +45,7 @@ /// \code /// # Some possible command line options: /// # --config-file, -C or --config - path to configuration file. By default - config.xml in the current directory. +/// # --pid-file - PID file name. Default is pid /// # --log-file /// # --errorlog-file /// # --daemon - run as daemon; without this option, the program will be attached to the terminal and also output logs to stderr. From da049465357800d456601db3f65752877fc16258 Mon Sep 17 00:00:00 2001 From: JaySon-Huang Date: Wed, 30 Mar 2022 11:13:23 +0800 Subject: [PATCH 8/8] Address comment --- libs/libdaemon/src/tests/gtest_daemon_config.cpp | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/libs/libdaemon/src/tests/gtest_daemon_config.cpp b/libs/libdaemon/src/tests/gtest_daemon_config.cpp index 1fefad2c497..e37391098bb 100644 --- a/libs/libdaemon/src/tests/gtest_daemon_config.cpp +++ b/libs/libdaemon/src/tests/gtest_daemon_config.cpp @@ -248,7 +248,8 @@ level = "debug" return; } char abs_path[PATH_MAX]{}; - (void)::readlink("/proc/self/exe", abs_path, sizeof(abs_path)); + if (ssize_t i_ret = ::readlink("/proc/self/exe", abs_path, sizeof(abs_path)); i_ret < 0) + throw Poco::Exception("can not locate the abs path of binary"); auto stdout_name = fmt::format("/tmp/{}-{}.stdout", reinterpret_cast(&abs_path), ::time(nullptr)); auto stderr_name = fmt::format("/tmp/{}-{}.stderr", reinterpret_cast(&abs_path), ::time(nullptr)); auto stdout_fd = ::open(stdout_name.c_str(), O_CREAT | O_TRUNC | O_RDWR, S_IRUSR | S_IWUSR);