Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Logger: Remove stringstream in total #4484

Merged
merged 10 commits into from
Mar 30, 2022
Merged
33 changes: 21 additions & 12 deletions dbms/src/Client/Connection.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@
#include <Common/ClickHouseRevision.h>
#include <Common/CurrentMetrics.h>
#include <Common/Exception.h>
#include <Common/FmtUtils.h>
#include <Common/NetException.h>
#include <Common/config.h>
#include <Core/Defines.h>
Expand Down Expand Up @@ -451,21 +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;
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<size_t>(rows / watch.elapsedSeconds()) << " rows/sec., "
<< maybe_compressed_out_bytes / 1048576.0 << " MiB (" << maybe_compressed_out_bytes / 1048576.0 / watch.elapsedSeconds() << " MiB/sec.)";
auto get_logging_msg = [&]() -> String {
const double elapsed_seconds = watch.elapsedSeconds();

if (compression == Protocol::Compression::Enable)
msg << ", compressed " << static_cast<double>(maybe_compressed_out_bytes) / out_bytes << " times to "
<< out_bytes / 1048576.0 << " MiB (" << out_bytes / 1048576.0 / watch.elapsedSeconds() << " MiB/sec.)";
else
msg << ", no compression.";
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(), msg.rdbuf());
LOG_DEBUG(log_wrapper.get(), get_logging_msg());
}


Expand Down
8 changes: 4 additions & 4 deletions dbms/src/Storages/DeltaMerge/WriteBatches.h
Original file line number Diff line number Diff line change
Expand Up @@ -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");
Expand Down
83 changes: 24 additions & 59 deletions libs/libcommon/include/common/logger_useful.h
Original file line number Diff line number Diff line change
Expand Up @@ -19,69 +19,10 @@
#include <Poco/Logger.h>
#include <fmt/format.h>

#include <sstream>

#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 <typename... Ts>
Expand Down Expand Up @@ -118,6 +59,30 @@ std::string toCheckedFmtStr(const S & format, const Ignored &, Args &&... args)
}
} // namespace LogFmtDetails

/// Logs a message to a specified logger with that level.

#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)
JaySon-Huang marked this conversation as resolved.
Show resolved Hide resolved
#define LOG_FATAL(logger, message) LOG_IMPL(logger, Poco::Message::PRIO_FATAL, message)


/// Logs a message to a specified logger with that level.
/// If more than one argument is provided,
Expand Down
12 changes: 12 additions & 0 deletions libs/libcommon/src/tests/gtest_logger.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -59,6 +59,13 @@ TEST_F(LoggerUsefulTest, 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);

std::string msg_in_log;
msg_in_log = "hello tiflash";
LOG_DEBUG(log, msg_in_log);
}

TEST_F(LoggerUsefulTest, LogFmt)
Expand All @@ -69,6 +76,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
92 changes: 41 additions & 51 deletions libs/libdaemon/include/daemon/BaseDaemon.h
Original file line number Diff line number Diff line change
Expand Up @@ -40,28 +40,20 @@
#include <mutex>
#include <optional>

/// \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_name> --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.
/// # --pid-file - PID file name. Default is pid
/// # --log-file
JaySon-Huang marked this conversation as resolved.
Show resolved Hide resolved
/// # --errorlog-file
/// # --daemon - run as daemon; without this option, the program will be attached to the terminal and also output logs to stderr.
/// <daemon_name> --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;
Expand All @@ -72,31 +64,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<BaseDaemon &>(Poco::Util::Application::instance());
Expand All @@ -105,39 +96,38 @@ class BaseDaemon : public Poco::Util::ServerApplication
/// return none if daemon doesn't exist, reference to the daemon otherwise
static std::optional<std::reference_wrapper<BaseDaemon>> tryGetInstance() { return tryGetInstance<BaseDaemon>(); }

/// Спит заданное количество секунд или до события 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 <class T>
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);
}

template <class T>
void writeToGraphite(const GraphiteWriter::KeyValueVector<T> & 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);
}

template <class T>
void writeToGraphite(const GraphiteWriter::KeyValueVector<T> & 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);
}
Expand All @@ -151,21 +141,21 @@ class BaseDaemon : public Poco::Util::ServerApplication

std::optional<size_t> 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
;
Expand All @@ -177,21 +167,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(); }
Expand All @@ -201,19 +191,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<Poco::Runnable> signal_listener;

/// Файлы с логами.
/// Log files.
Poco::AutoPtr<Poco::FileChannel> log_file;
Poco::AutoPtr<Poco::FileChannel> error_log_file;
Poco::AutoPtr<Poco::FileChannel> tracing_log_file;
Expand Down
Loading