This is an automated email from the ASF dual-hosted git repository.
morningman pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/incubator-doris.git
The following commit(s) were added to refs/heads/master by this push:
new ca8268f [Feature] Extend logger interface, support structured log
output (#6600)
ca8268f is described below
commit ca8268f1c9669aeca510ea705e146d3a4a44a983
Author: ccoffline <45881148+ccoffl...@users.noreply.github.com>
AuthorDate: Sun Nov 7 17:39:53 2021 +0800
[Feature] Extend logger interface, support structured log output (#6600)
Support structured logging.
---
be/src/common/logconfig.cpp | 17 ++++
be/src/runtime/plan_fragment_executor.cpp | 25 +++---
be/src/util/logging.h | 90 ++++++++++++++++++++++
.../doris/common/logger/DefaultDorisLogger.java | 55 +++++++++++++
.../apache/doris/common/logger/LoggerProvider.java | 51 ++++++++++++
.../org/apache/doris/common/logger/TagKey.java | 27 +++++++
.../apache/doris/common/logger/TaggableLogger.java | 64 +++++++++++++++
.../doris/common/logger/TaggedLogFormat.java | 26 +++++++
.../java/org/apache/doris/common/logger/Tags.java | 24 ++++++
9 files changed, 366 insertions(+), 13 deletions(-)
diff --git a/be/src/common/logconfig.cpp b/be/src/common/logconfig.cpp
index e3463f1..49684ac 100644
--- a/be/src/common/logconfig.cpp
+++ b/be/src/common/logconfig.cpp
@@ -159,4 +159,21 @@ std::string FormatTimestampForLog(MicrosecondsInt64
micros_since_epoch) {
tm_time.tm_hour, tm_time.tm_min, tm_time.tm_sec,
usecs);
}
+/// Custom your log format here
+void TaggableLogger::flush() {
+ _stream << _message;
+ Tags *head = _tags;
+ Tags *next;
+ while (head) {
+ next = head->next;
+ _stream << "|" << head->key << "=" << head->value;
+ delete head;
+ head = next;
+ }
+}
+
+/// Modify these tag names to suit your log format and collector.
+const std::string TaggableLogger::QUERY_ID = "query_id";
+const std::string TaggableLogger::INSTANCE_ID = "instance_id";
+
} // namespace doris
diff --git a/be/src/runtime/plan_fragment_executor.cpp
b/be/src/runtime/plan_fragment_executor.cpp
index d0f2cb2..670248e 100644
--- a/be/src/runtime/plan_fragment_executor.cpp
+++ b/be/src/runtime/plan_fragment_executor.cpp
@@ -21,7 +21,6 @@
#include <unordered_map>
-#include "common/logging.h"
#include "common/object_pool.h"
#include "exec/data_sink.h"
#include "exec/exchange_node.h"
@@ -40,7 +39,7 @@
#include "util/mem_info.h"
#include "util/parse_util.h"
#include "util/pretty_printer.h"
-#include "util/uid_util.h"
+#include "util/logging.h"
namespace doris {
@@ -70,9 +69,9 @@ Status PlanFragmentExecutor::prepare(const
TExecPlanFragmentParams& request,
const TPlanFragmentExecParams& params = request.params;
_query_id = params.query_id;
- LOG(INFO) << "Prepare(): query_id=" << print_id(_query_id)
- << " fragment_instance_id=" <<
print_id(params.fragment_instance_id)
- << " backend_num=" << request.backend_num;
+ TAG(LOG(INFO)).log("PlanFragmentExecutor::prepare")
+ .query_id(_query_id).instance_id(params.fragment_instance_id)
+ .tag("backend_num", std::to_string(request.backend_num));
// VLOG_CRITICAL << "request:\n" <<
apache::thrift::ThriftDebugString(request);
const TQueryGlobals& query_globals =
@@ -223,10 +222,10 @@ Status PlanFragmentExecutor::prepare(const
TExecPlanFragmentParams& request,
}
Status PlanFragmentExecutor::open() {
- LOG(INFO) << "Open(): fragment_instance_id="
- << print_id(_runtime_state->fragment_instance_id())
- << ", Using query memory limit: "
- <<
PrettyPrinter::print(_runtime_state->fragment_mem_tracker()->limit(),
TUnit::BYTES);
+ int64_t mem_limit = _runtime_state->fragment_mem_tracker()->limit();
+ TAG(LOG(INFO)).log("PlanFragmentExecutor::open, using query memory limit:
" + PrettyPrinter::print(mem_limit, TUnit::BYTES))
+
.query_id(_query_id).instance_id(_runtime_state->fragment_instance_id())
+ .tag("mem_limit", std::to_string(mem_limit));
// we need to start the profile-reporting thread before calling Open(),
since it
// may block
@@ -445,8 +444,8 @@ Status PlanFragmentExecutor::get_next(RowBatch** batch) {
update_status(status);
if (_done) {
- LOG(INFO) << "Finished executing fragment query_id=" <<
print_id(_query_id)
- << " instance_id=" <<
print_id(_runtime_state->fragment_instance_id());
+ TAG(LOG(INFO)).log("PlanFragmentExecutor::get_next finished")
+
.query_id(_query_id).instance_id(_runtime_state->fragment_instance_id());
// Query is done, return the thread token
stop_report_thread();
send_report(true);
@@ -504,8 +503,8 @@ void PlanFragmentExecutor::update_status(const Status&
new_status) {
}
void PlanFragmentExecutor::cancel() {
- LOG(INFO) << "cancel(): fragment_instance_id="
- << print_id(_runtime_state->fragment_instance_id());
+ TAG(LOG(INFO)).log("PlanFragmentExecutor::cancel")
+
.query_id(_query_id).instance_id(_runtime_state->fragment_instance_id());
DCHECK(_prepared);
_runtime_state->set_is_cancelled(true);
_runtime_state->exec_env()->stream_mgr()->cancel(_runtime_state->fragment_instance_id());
diff --git a/be/src/util/logging.h b/be/src/util/logging.h
index 27d7e82..ab23922 100644
--- a/be/src/util/logging.h
+++ b/be/src/util/logging.h
@@ -25,6 +25,7 @@
#include <string>
#include "common/logging.h"
+#include "util/uid_util.h"
#include "gutil/walltime.h"
namespace doris {
@@ -88,6 +89,95 @@ private:
std::atomic<Aws::Utils::Logging::LogLevel> _log_level;
};
+/// Wrap a glog stream and tag on the log. usage:
+/// TAG(LOG(INFO)).tag("query_id", queryId).log("here is an info for a
query");
+///
+/// TAG is the macro to TaggableLogger, which use method tag(key, value) to
add tags
+/// and log(fmt, ...) to flush and emit the log. Usually the tag key is
determined,
+/// like "query_id", so we use specified tag methods more often, like
query_id(id).
+/// You can add a new tag method if needed.
+///
+/// You can custom your tagged logging format in logconfig.cpp, the default is
like
+/// "#message#|k1=v1|k2=v2". You can also custom all the tag names. For
example, if
+/// you wish to use camelCase style, just set tag name constants like QUERY_ID
to
+/// "queryId". The constants is also listed in logconfig.cpp.
+///
+/// The transfer from the variable of tag method to string is immediate. If a
tagged
+/// logging has time-consuming to-string procedure and is logged to VLOG(10)
which
+/// may not be processed, check VLOG_IS_ON(n) first.
+#define TAG doris::TaggableLogger
+
+class TaggableLogger {
+public:
+ TaggableLogger(std::ostream& _stream) : _stream(_stream), _tags(nullptr)
{};
+
+ ~TaggableLogger() {
+ flush();
+ }
+
+ void flush();
+
+ TaggableLogger& log(std::string&& message) {
+ _message = std::move(message);
+ return *this;
+ }
+
+ inline TaggableLogger& tag(const std::string& key, const std::string&
value) {
+ _tags = new Tags(key, value, _tags);
+ return *this;
+ }
+
+ inline TaggableLogger& tag(const std::string& key, std::string&& value) {
+ _tags = new Tags(key, std::move(value), _tags);
+ return *this;
+ }
+
+private:
+ std::ostream& _stream;
+ std::string _message;
+
+ struct Tags {
+ const std::string& key;
+ const std::string value;
+ Tags* next;
+
+ Tags(const std::string& key, const std::string& value, Tags* next) :
key(key), value(value), next(next) {}
+ Tags(const std::string& key, std::string&& value, Tags* next) :
key(key), value(std::move(value)), next(next) {}
+ };
+
+ Tags* _tags;
+
+public:
+ // add tag method here
+ const static std::string QUERY_ID;
+
+ TaggableLogger& query_id(const std::string& query_id) {
+ return tag(QUERY_ID, query_id);
+ }
+
+ TaggableLogger& query_id(const TUniqueId& query_id) {
+ return tag(QUERY_ID, print_id(query_id));
+ }
+
+ TaggableLogger& query_id(const PUniqueId& query_id) {
+ return tag(QUERY_ID, print_id(query_id));
+ }
+
+ const static std::string INSTANCE_ID;
+
+ TaggableLogger& instance_id(const std::string& instance_id) {
+ return tag(INSTANCE_ID, instance_id);
+ }
+
+ TaggableLogger& instance_id(const TUniqueId& instance_id) {
+ return tag(INSTANCE_ID, print_id(instance_id));
+ }
+
+ TaggableLogger& instance_id(const PUniqueId& instance_id) {
+ return tag(INSTANCE_ID, print_id(instance_id));
+ }
+};
+
} // namespace doris
#endif // DORIS_BE_SRC_COMMON_UTIL_LOGGING_H
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/common/logger/DefaultDorisLogger.java
b/fe/fe-core/src/main/java/org/apache/doris/common/logger/DefaultDorisLogger.java
new file mode 100644
index 0000000..7be90df
--- /dev/null
+++
b/fe/fe-core/src/main/java/org/apache/doris/common/logger/DefaultDorisLogger.java
@@ -0,0 +1,55 @@
+// Licensed to the Apache Software Foundation (ASF) under one
+// or more contributor license agreements. See the NOTICE file
+// distributed with this work for additional information
+// regarding copyright ownership. The ASF licenses this file
+// to you under the Apache License, Version 2.0 (the
+// "License"); you may not use this file except in compliance
+// with the License. You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing,
+// software distributed under the License is distributed on an
+// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+// KIND, either express or implied. See the License for the
+// specific language governing permissions and limitations
+// under the License.
+
+package org.apache.doris.common.logger;
+
+import org.apache.logging.log4j.Level;
+import org.apache.logging.log4j.Marker;
+import org.apache.logging.log4j.message.Message;
+import org.apache.logging.log4j.spi.ExtendedLogger;
+import org.apache.logging.log4j.spi.ExtendedLoggerWrapper;
+
+public class DefaultDorisLogger extends ExtendedLoggerWrapper implements
TaggableLogger {
+
+ private final TaggedLogFormat format;
+ private final ThreadLocal<Tags> tags;
+
+ public DefaultDorisLogger(ExtendedLogger logger, TaggedLogFormat format) {
+ super(logger, logger.getName(), logger.getMessageFactory());
+ this.format = format;
+ this.tags = ThreadLocal.withInitial(Tags::new);
+ }
+
+ @Override
+ public TaggableLogger tag(String key, Object value) {
+ Tags head = this.tags.get();
+ Tags tag = new Tags();
+ tag.key = key;
+ tag.value = value;
+ tag.next = head.next;
+ head.next = tag;
+ return this;
+ }
+
+ @Override
+ public void logMessage(String fqcn, Level level, Marker marker, Message
message, Throwable t) {
+ Tags tags = this.tags.get();
+ Message m = tags.next == null ? message :
format.getTaggedMessage(message, tags.next);
+ super.logMessage(fqcn, level, marker, m, t);
+ tags.next = null;
+ }
+}
\ No newline at end of file
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/common/logger/LoggerProvider.java
b/fe/fe-core/src/main/java/org/apache/doris/common/logger/LoggerProvider.java
new file mode 100644
index 0000000..149445d
--- /dev/null
+++
b/fe/fe-core/src/main/java/org/apache/doris/common/logger/LoggerProvider.java
@@ -0,0 +1,51 @@
+// Licensed to the Apache Software Foundation (ASF) under one
+// or more contributor license agreements. See the NOTICE file
+// distributed with this work for additional information
+// regarding copyright ownership. The ASF licenses this file
+// to you under the Apache License, Version 2.0 (the
+// "License"); you may not use this file except in compliance
+// with the License. You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing,
+// software distributed under the License is distributed on an
+// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+// KIND, either express or implied. See the License for the
+// specific language governing permissions and limitations
+// under the License.
+
+package org.apache.doris.common.logger;
+
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.message.SimpleMessage;
+import org.apache.logging.log4j.spi.ExtendedLogger;
+
+public class LoggerProvider {
+
+ public static TaggableLogger getLogger(Class<?> clazz) {
+ return wrap(LogManager.getLogger(clazz));
+ }
+
+ public static TaggableLogger getLogger(String name) {
+ return wrap(LogManager.getLogger(name));
+ }
+
+ public static TaggableLogger wrap(Logger logger) {
+ return new DefaultDorisLogger((ExtendedLogger) logger,
getTaggedLogFormat());
+ }
+
+ // custom your log format here
+ public static TaggedLogFormat getTaggedLogFormat() {
+ return (message, tags) -> {
+ StringBuilder builder = new
StringBuilder(message.getFormattedMessage());
+ while (tags != null) {
+
builder.append('|').append(tags.key).append('=').append(tags.value);
+ tags = tags.next;
+ }
+ return new SimpleMessage(builder);
+ };
+ }
+
+}
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/common/logger/TagKey.java
b/fe/fe-core/src/main/java/org/apache/doris/common/logger/TagKey.java
new file mode 100644
index 0000000..f1c2ad2
--- /dev/null
+++ b/fe/fe-core/src/main/java/org/apache/doris/common/logger/TagKey.java
@@ -0,0 +1,27 @@
+// Licensed to the Apache Software Foundation (ASF) under one
+// or more contributor license agreements. See the NOTICE file
+// distributed with this work for additional information
+// regarding copyright ownership. The ASF licenses this file
+// to you under the Apache License, Version 2.0 (the
+// "License"); you may not use this file except in compliance
+// with the License. You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing,
+// software distributed under the License is distributed on an
+// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+// KIND, either express or implied. See the License for the
+// specific language governing permissions and limitations
+// under the License.
+
+package org.apache.doris.common.logger;
+
+/**
+ * Modify these tag key name to suit your log format and collector.
+ */
+public class TagKey {
+
+ public static final String QUERY_ID = "query_id";
+
+}
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/common/logger/TaggableLogger.java
b/fe/fe-core/src/main/java/org/apache/doris/common/logger/TaggableLogger.java
new file mode 100644
index 0000000..43d069a
--- /dev/null
+++
b/fe/fe-core/src/main/java/org/apache/doris/common/logger/TaggableLogger.java
@@ -0,0 +1,64 @@
+// Licensed to the Apache Software Foundation (ASF) under one
+// or more contributor license agreements. See the NOTICE file
+// distributed with this work for additional information
+// regarding copyright ownership. The ASF licenses this file
+// to you under the Apache License, Version 2.0 (the
+// "License"); you may not use this file except in compliance
+// with the License. You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing,
+// software distributed under the License is distributed on an
+// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+// KIND, either express or implied. See the License for the
+// specific language governing permissions and limitations
+// under the License.
+
+package org.apache.doris.common.logger;
+
+import org.apache.doris.common.util.DebugUtil;
+import org.apache.doris.proto.PUniqueId;
+import org.apache.doris.thrift.TUniqueId;
+import org.apache.logging.log4j.Logger;
+
+import java.util.UUID;
+
+/**
+ * Wrap a log4j Logger and tag on the log. usage:
+ * LOG.tag("query_id", queryId).info("here is an info for a query");
+ *
+ * TaggableLogger extends log4j Logger, so it's fully compatible with the usual
+ * one. You can use method tag(key, value) to add tags and log all the tags and
+ * message when log method is called, like info(fmt, ...). Usually the tag key
is
+ * determined, like "query_id", so we use specified tag methods more often,
like
+ * query_id(id). You can add a new tag method to TaggableLogger if needed.
+ *
+ * You can custom your tagged logging format in
LoggerProvider.getTaggedLogFormat,
+ * the default is like "#message#|k1=v1|k2=v2". You can also custom all the tag
+ * names in TagKey. For example, if you wish to use camelCase style, just set
tag
+ * name constants like QUERY_ID to "queryId".
+ *
+ * The transfer from the variable of tag method to string is immediate. If a
tagged
+ * logging has time-consuming to-string procedure and is at debug level which
may
+ * not be processed, check isDebugEnabled() first.
+ */
+public interface TaggableLogger extends Logger {
+
+ TaggableLogger tag(String key, Object value);
+
+ // add tag method here
+
+ default TaggableLogger queryId(final TUniqueId queryId) {
+ return tag(TagKey.QUERY_ID, DebugUtil.printId(queryId));
+ }
+
+ default TaggableLogger queryId(final UUID queryId) {
+ return tag(TagKey.QUERY_ID, DebugUtil.printId(queryId));
+ }
+
+ default TaggableLogger queryId(final PUniqueId queryId) {
+ return tag(TagKey.QUERY_ID, DebugUtil.printId(queryId));
+ }
+
+}
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/common/logger/TaggedLogFormat.java
b/fe/fe-core/src/main/java/org/apache/doris/common/logger/TaggedLogFormat.java
new file mode 100644
index 0000000..cf8fcf8
--- /dev/null
+++
b/fe/fe-core/src/main/java/org/apache/doris/common/logger/TaggedLogFormat.java
@@ -0,0 +1,26 @@
+// Licensed to the Apache Software Foundation (ASF) under one
+// or more contributor license agreements. See the NOTICE file
+// distributed with this work for additional information
+// regarding copyright ownership. The ASF licenses this file
+// to you under the Apache License, Version 2.0 (the
+// "License"); you may not use this file except in compliance
+// with the License. You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing,
+// software distributed under the License is distributed on an
+// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+// KIND, either express or implied. See the License for the
+// specific language governing permissions and limitations
+// under the License.
+
+package org.apache.doris.common.logger;
+
+import org.apache.logging.log4j.message.Message;
+
+public interface TaggedLogFormat {
+
+ Message getTaggedMessage(Message message, Tags tags);
+
+}
diff --git a/fe/fe-core/src/main/java/org/apache/doris/common/logger/Tags.java
b/fe/fe-core/src/main/java/org/apache/doris/common/logger/Tags.java
new file mode 100644
index 0000000..7485967
--- /dev/null
+++ b/fe/fe-core/src/main/java/org/apache/doris/common/logger/Tags.java
@@ -0,0 +1,24 @@
+// Licensed to the Apache Software Foundation (ASF) under one
+// or more contributor license agreements. See the NOTICE file
+// distributed with this work for additional information
+// regarding copyright ownership. The ASF licenses this file
+// to you under the Apache License, Version 2.0 (the
+// "License"); you may not use this file except in compliance
+// with the License. You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing,
+// software distributed under the License is distributed on an
+// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+// KIND, either express or implied. See the License for the
+// specific language governing permissions and limitations
+// under the License.
+
+package org.apache.doris.common.logger;
+
+class Tags {
+ String key;
+ Object value;
+ Tags next;
+}
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscr...@doris.apache.org
For additional commands, e-mail: commits-h...@doris.apache.org
