Skip to content

Commit

Permalink
Merge pull request #40251 from ClibMouse/Structured-logging-custom-keys
Browse files Browse the repository at this point in the history
Feature Improvement: Custom Key Names for Structured Logging Support
  • Loading branch information
evillique authored Aug 31, 2022
2 parents 00c7a0f + 87a28c2 commit e98ceb2
Show file tree
Hide file tree
Showing 10 changed files with 382 additions and 92 deletions.
26 changes: 24 additions & 2 deletions programs/server/config.xml
Original file line number Diff line number Diff line change
Expand Up @@ -65,9 +65,31 @@
in specified format like JSON.
For example, as below:
{"date_time":"1650918987.180175","thread_name":"#1","thread_id":"254545","level":"Trace","query_id":"","logger_name":"BaseDaemon","message":"Received signal 2","source_file":"../base/daemon/BaseDaemon.cpp; virtual void SignalListener::run()","source_line":"192"}
To enable JSON logging support, just uncomment <formatting> tag below.
To enable JSON logging support, please uncomment the entire <formatting> tag below.
a) You can modify key names by changing values under tag values inside <names> tag.
For example, to change DATE_TIME to MY_DATE_TIME, you can do like:
<date_time>MY_DATE_TIME</date_time>
b) You can stop unwanted log properties to appear in logs. To do so, you can simply comment out (recommended)
that property from this file.
For example, if you do not want your log to print query_id, you can comment out only <query_id> tag.
However, if you comment out all the tags under <names>, the program will print default values for as
below.
-->
<!-- <formatting>json</formatting> -->
<!-- <formatting>
<type>json</type>
<names>
<date_time>date_time</date_time>
<thread_name>thread_name</thread_name>
<thread_id>thread_id</thread_id>
<level>level</level>
<query_id>query_id</query_id>
<logger_name>logger_name</logger_name>
<message>message</message>
<source_file>source_file</source_file>
<source_line>source_line</source_line>
</names>
</formatting> -->
</logger>

<!-- Add headers to response in options request. OPTIONS method is used in CORS preflight requests. -->
Expand Down
4 changes: 2 additions & 2 deletions src/Daemon/BaseDaemon.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -1016,8 +1016,8 @@ void BaseDaemon::setupWatchdog()
if (config().getRawString("logger.stream_compress", "false") == "true")
{
Poco::AutoPtr<OwnPatternFormatter> pf;
if (config().getString("logger.formatting", "") == "json")
pf = new OwnJSONPatternFormatter;
if (config().getString("logger.formatting.type", "") == "json")
pf = new OwnJSONPatternFormatter(config());
else
pf = new OwnPatternFormatter;
Poco::AutoPtr<DB::OwnFormattingChannel> log = new DB::OwnFormattingChannel(pf, new Poco::ConsoleChannel(std::cerr));
Expand Down
16 changes: 8 additions & 8 deletions src/Loggers/Loggers.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -99,8 +99,8 @@ void Loggers::buildLoggers(Poco::Util::AbstractConfiguration & config, Poco::Log

Poco::AutoPtr<OwnPatternFormatter> pf;

if (config.getString("logger.formatting", "") == "json")
pf = new OwnJSONPatternFormatter;
if (config.getString("logger.formatting.type", "") == "json")
pf = new OwnJSONPatternFormatter(config);
else
pf = new OwnPatternFormatter;

Expand Down Expand Up @@ -140,8 +140,8 @@ void Loggers::buildLoggers(Poco::Util::AbstractConfiguration & config, Poco::Log

Poco::AutoPtr<OwnPatternFormatter> pf;

if (config.getString("logger.formatting", "") == "json")
pf = new OwnJSONPatternFormatter;
if (config.getString("logger.formatting.type", "") == "json")
pf = new OwnJSONPatternFormatter(config);
else
pf = new OwnPatternFormatter;

Expand Down Expand Up @@ -184,8 +184,8 @@ void Loggers::buildLoggers(Poco::Util::AbstractConfiguration & config, Poco::Log

Poco::AutoPtr<OwnPatternFormatter> pf;

if (config.getString("logger.formatting", "") == "json")
pf = new OwnJSONPatternFormatter;
if (config.getString("logger.formatting.type", "") == "json")
pf = new OwnJSONPatternFormatter(config);
else
pf = new OwnPatternFormatter;

Expand All @@ -211,8 +211,8 @@ void Loggers::buildLoggers(Poco::Util::AbstractConfiguration & config, Poco::Log
}

Poco::AutoPtr<OwnPatternFormatter> pf;
if (config.getString("logger.formatting", "") == "json")
pf = new OwnJSONPatternFormatter;
if (config.getString("logger.formatting.type", "") == "json")
pf = new OwnJSONPatternFormatter(config);
else
pf = new OwnPatternFormatter(color_enabled);
Poco::AutoPtr<DB::OwnFormattingChannel> log = new DB::OwnFormattingChannel(pf, new Poco::ConsoleChannel);
Expand Down
239 changes: 166 additions & 73 deletions src/Loggers/OwnJSONPatternFormatter.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -8,93 +8,186 @@
#include <Common/CurrentThread.h>
#include <Common/HashTable/Hash.h>

OwnJSONPatternFormatter::OwnJSONPatternFormatter() : OwnPatternFormatter("")
OwnJSONPatternFormatter::OwnJSONPatternFormatter(Poco::Util::AbstractConfiguration & config)
{
if (config.has("logger.formatting.names.date_time"))
date_time = config.getString("logger.formatting.names.date_time", "");

if (config.has("logger.formatting.names.thread_name"))
thread_name = config.getString("logger.formatting.names.thread_name", "");

if (config.has("logger.formatting.names.thread_id"))
thread_id = config.getString("logger.formatting.names.thread_id", "");

if (config.has("logger.formatting.names.level"))
level = config.getString("logger.formatting.names.level", "");

if (config.has("logger.formatting.names.query_id"))
query_id = config.getString("logger.formatting.names.query_id", "");

if (config.has("logger.formatting.names.logger_name"))
logger_name = config.getString("logger.formatting.names.logger_name", "");

if (config.has("logger.formatting.names.message"))
message = config.getString("logger.formatting.names.message", "");

if (config.has("logger.formatting.names.source_file"))
source_file = config.getString("logger.formatting.names.source_file", "");

if (config.has("logger.formatting.names.source_line"))
source_line = config.getString("logger.formatting.names.source_line", "");

if (date_time.empty() && thread_name.empty() && thread_id.empty() && level.empty() && query_id.empty()
&& logger_name.empty() && message.empty() && source_file.empty() && source_line.empty())
{
date_time = "date_time";
thread_name = "thread_name";
thread_id = "thread_id";
level = "level";
query_id = "query_id";
logger_name = "logger_name";
message = "message";
source_file = "source_file";
source_line = "source_line";
}
}


void OwnJSONPatternFormatter::formatExtended(const DB::ExtendedLogMessage & msg_ext, std::string & text) const
{
DB::WriteBufferFromString wb(text);

DB::FormatSettings settings;
bool print_comma = false;

const Poco::Message & msg = msg_ext.base;
DB::writeChar('{', wb);

writeJSONString("date_time", wb, settings);
DB::writeChar(':', wb);

DB::writeChar('\"', wb);
/// Change delimiters in date for compatibility with old logs.
writeDateTimeUnixTimestamp(msg_ext.time_seconds, 0, wb);
DB::writeChar('.', wb);
DB::writeChar('0' + ((msg_ext.time_microseconds / 100000) % 10), wb);
DB::writeChar('0' + ((msg_ext.time_microseconds / 10000) % 10), wb);
DB::writeChar('0' + ((msg_ext.time_microseconds / 1000) % 10), wb);
DB::writeChar('0' + ((msg_ext.time_microseconds / 100) % 10), wb);
DB::writeChar('0' + ((msg_ext.time_microseconds / 10) % 10), wb);
DB::writeChar('0' + ((msg_ext.time_microseconds / 1) % 10), wb);
DB::writeChar('\"', wb);

DB::writeChar(',', wb);

writeJSONString("thread_name", wb, settings);
DB::writeChar(':', wb);

writeJSONString(msg.getThread(), wb, settings);

DB::writeChar(',', wb);

writeJSONString("thread_id", wb, settings);
DB::writeChar(':', wb);
DB::writeChar('\"', wb);
DB::writeIntText(msg_ext.thread_id, wb);
DB::writeChar('\"', wb);

DB::writeChar(',', wb);

writeJSONString("level", wb, settings);
DB::writeChar(':', wb);
int priority = static_cast<int>(msg.getPriority());
writeJSONString(std::to_string(priority), wb, settings);
DB::writeChar(',', wb);
if (!date_time.empty())
{
writeJSONString(date_time, wb, settings);
DB::writeChar(':', wb);

DB::writeChar('\"', wb);
/// Change delimiters in date for compatibility with old logs.
writeDateTimeUnixTimestamp(msg_ext.time_seconds, 0, wb);
DB::writeChar('.', wb);
DB::writeChar('0' + ((msg_ext.time_microseconds / 100000) % 10), wb);
DB::writeChar('0' + ((msg_ext.time_microseconds / 10000) % 10), wb);
DB::writeChar('0' + ((msg_ext.time_microseconds / 1000) % 10), wb);
DB::writeChar('0' + ((msg_ext.time_microseconds / 100) % 10), wb);
DB::writeChar('0' + ((msg_ext.time_microseconds / 10) % 10), wb);
DB::writeChar('0' + ((msg_ext.time_microseconds / 1) % 10), wb);
DB::writeChar('\"', wb);
print_comma = true;
}

if (!thread_name.empty())
{
if (print_comma)
DB::writeChar(',', wb);
else
print_comma = true;

writeJSONString(thread_name, wb, settings);
DB::writeChar(':', wb);

writeJSONString(msg.getThread(), wb, settings);
}

if (!thread_id.empty())
{
if (print_comma)
DB::writeChar(',', wb);
else
print_comma = true;

writeJSONString(thread_id, wb, settings);
DB::writeChar(':', wb);
DB::writeChar('\"', wb);
DB::writeIntText(msg_ext.thread_id, wb);
DB::writeChar('\"', wb);
}

if (!level.empty())
{
if (print_comma)
DB::writeChar(',', wb);
else
print_comma = true;

writeJSONString(level, wb, settings);
DB::writeChar(':', wb);
int priority = static_cast<int>(msg.getPriority());
writeJSONString(std::to_string(priority), wb, settings);
}

if (!query_id.empty())
{
if (print_comma)
DB::writeChar(',', wb);
else
print_comma = true;

/// We write query_id even in case when it is empty (no query context)
/// just to be convenient for various log parsers.

writeJSONString(query_id, wb, settings);
DB::writeChar(':', wb);
writeJSONString(msg_ext.query_id, wb, settings);
}

if (!logger_name.empty())
{
if (print_comma)
DB::writeChar(',', wb);
else
print_comma = true;

writeJSONString(logger_name, wb, settings);
DB::writeChar(':', wb);

writeJSONString(msg.getSource(), wb, settings);
}

if (!message.empty())
{
if (print_comma)
DB::writeChar(',', wb);
else
print_comma = true;

writeJSONString(message, wb, settings);
DB::writeChar(':', wb);
writeJSONString(msg.getText(), wb, settings);
}

if (!source_file.empty())
{
if (print_comma)
DB::writeChar(',', wb);
else
print_comma = true;

/// We write query_id even in case when it is empty (no query context)
/// just to be convenient for various log parsers.

writeJSONString("query_id", wb, settings);
DB::writeChar(':', wb);
writeJSONString(msg_ext.query_id, wb, settings);

DB::writeChar(',', wb);

writeJSONString("logger_name", wb, settings);
DB::writeChar(':', wb);

writeJSONString(msg.getSource(), wb, settings);
DB::writeChar(',', wb);

writeJSONString("message", wb, settings);
DB::writeChar(':', wb);
writeJSONString(msg.getText(), wb, settings);
DB::writeChar(',', wb);

writeJSONString("source_file", wb, settings);
DB::writeChar(':', wb);
const char * source_file = msg.getSourceFile();
if (source_file != nullptr)
writeJSONString(source_file, wb, settings);
else
writeJSONString("", wb, settings);
DB::writeChar(',', wb);

writeJSONString("source_line", wb, settings);
DB::writeChar(':', wb);
DB::writeChar('\"', wb);
DB::writeIntText(msg.getSourceLine(), wb);
DB::writeChar('\"', wb);

DB::writeChar(':', wb);
const char * source_file_name = msg.getSourceFile();
if (source_file_name != nullptr)
writeJSONString(source_file_name, wb, settings);
else
writeJSONString("", wb, settings);
}

if (!source_line.empty())
{
if (print_comma)
DB::writeChar(',', wb);

writeJSONString(source_line, wb, settings);
DB::writeChar(':', wb);
DB::writeChar('\"', wb);
DB::writeIntText(msg.getSourceLine(), wb);
DB::writeChar('\"', wb);
}
DB::writeChar('}', wb);
}

Expand Down
14 changes: 13 additions & 1 deletion src/Loggers/OwnJSONPatternFormatter.h
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@


#include <Poco/PatternFormatter.h>
#include <Poco/Util/AbstractConfiguration.h>
#include "ExtendedLogChannel.h"
#include "OwnPatternFormatter.h"

Expand All @@ -25,8 +26,19 @@ class Loggers;
class OwnJSONPatternFormatter : public OwnPatternFormatter
{
public:
OwnJSONPatternFormatter();
OwnJSONPatternFormatter(Poco::Util::AbstractConfiguration & config);

void format(const Poco::Message & msg, std::string & text) override;
void formatExtended(const DB::ExtendedLogMessage & msg_ext, std::string & text) const override;

private:
std::string date_time;
std::string thread_name;
std::string thread_id;
std::string level;
std::string query_id;
std::string logger_name;
std::string message;
std::string source_file;
std::string source_line;
};
Loading

0 comments on commit e98ceb2

Please sign in to comment.