This is an automated email from the ASF dual-hosted git repository. michaelsmith pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/impala.git
commit c0b35807543f96cb382240717ab552d17f6f78a6 Author: jasonmfehr <[email protected]> AuthorDate: Thu Sep 11 16:51:12 2025 -0700 IMPALA-14372: Output OpenTelemetry SDK Logs to Impala Logs Emits log messages from the OpenTelemetry SDK to the Impalad DEBUG, INFO, WARNING, and ERROR logs. Previously, these SDK log messages were dropped. Modifies the function of the 'otel_debug' startup flag. This flag defaults to 'false' which causes log messages from the SDK to be dropped. When set to 'true', log messages from the OpenTelemetry SDK will be sent to the Impala logging system. The overall glog level is applied to all messages sent from the OpenTelemetry SDK, thus DEBUG SDK logs will not appear in the Impalad logs unless the glog level is greater than or equal to 2. When a trace is successfully sent to the OpenTelemetry collector, zero log lines are generated. When a trace cannot be sent, local testing showed 12 lines with a total size around 3k were written between the impalad.ERROR and impalad.WARNING log files. The request body is not included in these log messages unless the glog level is greater than or equal to 2 thus log message size will not grow or shrink based on the size of the trace(s). This patch also removes the completely useless 'LoggingInstrumentation' class. Previously, the 'otel_debug' flag caused this class to log messages, but those messages provided no insightful information. Generated-by: Github Copilot (Claude Sonnet 3.7) Change-Id: I41aba21f46233e6430eede9606be1e791071717a Reviewed-on: http://gerrit.cloudera.org:8080/23418 Reviewed-by: Impala Public Jenkins <[email protected]> Tested-by: Impala Public Jenkins <[email protected]> --- be/src/observe/CMakeLists.txt | 1 + be/src/observe/otel-flags.cc | 4 +- be/src/observe/otel-instrument.h | 64 ------------------------- be/src/observe/otel-log-handler.cc | 82 +++++++++++++++++++++++++++++++++ be/src/observe/otel-log-handler.h | 35 ++++++++++++++ be/src/observe/otel.cc | 42 +++++++++-------- tests/custom_cluster/test_otel_trace.py | 20 +++++++- 7 files changed, 163 insertions(+), 85 deletions(-) diff --git a/be/src/observe/CMakeLists.txt b/be/src/observe/CMakeLists.txt index 93be4f22a..1dffc0b1f 100644 --- a/be/src/observe/CMakeLists.txt +++ b/be/src/observe/CMakeLists.txt @@ -24,6 +24,7 @@ set(EXECUTABLE_OUTPUT_PATH "${BUILD_OUTPUT_ROOT_DIRECTORY}/observe") add_library(Observe otel-flags.cc otel-flags-trace.cc + otel-log-handler.cc otel.cc span-manager.cc timed-span.cc diff --git a/be/src/observe/otel-flags.cc b/be/src/observe/otel-flags.cc index b4958120f..206c92344 100644 --- a/be/src/observe/otel-flags.cc +++ b/be/src/observe/otel-flags.cc @@ -19,6 +19,7 @@ #include <chrono> +#include <gflags/gflags.h> #include <opentelemetry/exporters/otlp/otlp_file_client_options.h> #include "util/gflag-validator-util.h" @@ -26,7 +27,8 @@ using namespace std; using namespace std::chrono; -DEFINE_bool(otel_debug, false, "If set to true, outputs additional debug info"); +DEFINE_bool(otel_debug, false, "If set to true, send debug logs from the " + "OpenTelemetry SDK to the Impala logging system."); // // Start of OTLP File Exporter flags diff --git a/be/src/observe/otel-instrument.h b/be/src/observe/otel-instrument.h deleted file mode 100644 index 4a9260978..000000000 --- a/be/src/observe/otel-instrument.h +++ /dev/null @@ -1,64 +0,0 @@ -// 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. - -#pragma once - -#ifndef ENABLE_THREAD_INSTRUMENTATION_PREVIEW -#define ENABLE_THREAD_INSTRUMENTATION_PREVIEW -#endif - -#include <string> - -#include <glog/logging.h> -#include <opentelemetry/sdk/common/thread_instrumentation.h> - -namespace impala { - -class LoggingInstrumentation : public opentelemetry::sdk::common::ThreadInstrumentation { - -public: - LoggingInstrumentation(const std::string& thread_type) : thread_type_(thread_type) {} - - void OnStart() override { - VLOG(2) << thread_type_ << " opentelemetry thread started"; - } - - void OnEnd() override { - VLOG(2) << thread_type_ << " opentelemetry thread ended"; - } - - void BeforeWait() override { - VLOG(2) << thread_type_ << " opentelemetry thread before wait"; - } - - void AfterWait() override { - VLOG(2) << thread_type_ << " opentelemetry thread after wait"; - } - - void BeforeLoad() override { - VLOG(2) << thread_type_ << " opentelemetry thread before load"; - } - - void AfterLoad() override { - VLOG(2) << thread_type_ << " opentelemetry thread after load"; - } - -private: - const std::string thread_type_; -}; // class LoggingInstrumentation - -} // namespace impala diff --git a/be/src/observe/otel-log-handler.cc b/be/src/observe/otel-log-handler.cc new file mode 100644 index 000000000..840609f7d --- /dev/null +++ b/be/src/observe/otel-log-handler.cc @@ -0,0 +1,82 @@ +// 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. + +#include "observe/otel-log-handler.h" + +#include <sstream> + +#include <glog/logging.h> +#include <opentelemetry/common/attribute_value.h> +#include <opentelemetry/sdk/common/global_log_handler.h> +#include <opentelemetry/nostd/variant.h> + +#include "common/compiler-util.h" +#include "gutil/strings/substitute.h" + +using namespace std; +using namespace opentelemetry::nostd; +using namespace opentelemetry::sdk::common; +using namespace opentelemetry::sdk::common::internal_log; + +namespace impala { + +void OtelLogHandler::Handle(LogLevel level, const char* file, int line, const char* msg, + const AttributeMap &attributes) noexcept { + stringstream attr_stream; + + for (const auto& attribute : attributes) { + attr_stream << " " << attribute.first << "=\""; + if (holds_alternative<bool>(attribute.second)) { + attr_stream << get<bool>(attribute.second); + } else if (holds_alternative<int32_t>(attribute.second)) { + attr_stream << to_string(get<int32_t>(attribute.second)); + } else if (holds_alternative<int64_t>(attribute.second)) { + attr_stream << to_string(get<int64_t>(attribute.second)); + } else if (holds_alternative<uint32_t>(attribute.second)) { + attr_stream << to_string(get<uint32_t>(attribute.second)); + } else if (holds_alternative<uint64_t>(attribute.second)) { + attr_stream << to_string(get<uint64_t>(attribute.second)); + } else if (holds_alternative<double>(attribute.second)) { + attr_stream << to_string(get<double>(attribute.second)); + } else if (holds_alternative<string>(attribute.second)) { + attr_stream << get<string>(attribute.second); + } else { + attr_stream << "unsupported-type"; + } + attr_stream << "\""; + } + + string log_msg = strings::Substitute("$0 file=\"$1\" line=\"$2\"$3", msg, file, line, + attr_stream.str()); + + switch (level) { + case LogLevel::Error: + LOG(ERROR) << log_msg; + break; + case LogLevel::Warning: + LOG(WARNING) << log_msg; + break; + case LogLevel::Info: + LOG(INFO) << log_msg; + break; + default: + VLOG(2) << log_msg; + break; + } +} // function OtelLogHandler::Handle + +} // namespace impala diff --git a/be/src/observe/otel-log-handler.h b/be/src/observe/otel-log-handler.h new file mode 100644 index 000000000..fa0c9dcc1 --- /dev/null +++ b/be/src/observe/otel-log-handler.h @@ -0,0 +1,35 @@ +// 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. + +#pragma once + +#include <opentelemetry/sdk/common/global_log_handler.h> + +namespace impala { + +// Custom log handler for OpenTelemetry SDK internal logs. +// +// Log messages generated by the OpenTelemetry SDK are dropped by default. This class +// implements the SDK's LogHandler interface to emit internal SDK log messages to Impala's +// logging system. +class OtelLogHandler : public opentelemetry::sdk::common::internal_log::LogHandler { + void Handle(opentelemetry::sdk::common::internal_log::LogLevel level, + const char* file, int line, const char* msg, + const opentelemetry::sdk::common::AttributeMap &attributes) noexcept override; +}; + +} // namespace impala diff --git a/be/src/observe/otel.cc b/be/src/observe/otel.cc index dbd71434b..b46224110 100644 --- a/be/src/observe/otel.cc +++ b/be/src/observe/otel.cc @@ -28,7 +28,7 @@ #include <boost/algorithm/string/case_conv.hpp> #include <boost/algorithm/string/predicate.hpp> #include <boost/algorithm/string/trim.hpp> -#include <gflags/gflags.h> +#include <gflags/gflags_declare.h> #include <glog/logging.h> #include <gutil/strings/split.h> #include <opentelemetry/exporters/otlp/otlp_file_exporter.h> @@ -39,6 +39,8 @@ #include <opentelemetry/exporters/otlp/otlp_http_exporter_factory.h> #include <opentelemetry/exporters/otlp/otlp_http_exporter_options.h> #include <opentelemetry/exporters/otlp/otlp_http_exporter_runtime_options.h> +#include <opentelemetry/nostd/shared_ptr.h> +#include <opentelemetry/sdk/common/global_log_handler.h> #include <opentelemetry/sdk/resource/resource.h> #include <opentelemetry/sdk/trace/batch_span_processor.h> #include <opentelemetry/sdk/trace/batch_span_processor_factory.h> @@ -57,13 +59,14 @@ #include "common/status.h" #include "common/version.h" #include "gen-cpp/Query_types.h" -#include "observe/otel-instrument.h" +#include "observe/otel-log-handler.h" #include "observe/span-manager.h" #include "service/client-request-state.h" using namespace boost::algorithm; using namespace opentelemetry; using namespace opentelemetry::exporter::otlp; +using namespace opentelemetry::sdk::common::internal_log; using namespace opentelemetry::sdk::trace; using namespace std; @@ -107,6 +110,9 @@ static const regex query_newline( "(select|alter|compute|create|delete|drop|insert|invalidate|update|with)\\s*" "(\n|\\s*\\\\*\\/)", regex::icase | regex::optimize | regex::nosubs); +// Holds the custom log handler for OpenTelemetry internal logs. +static nostd::shared_ptr<LogHandler> otel_log_handler_; + // Lambda function to check if SQL starts with relevant keywords for tracing static const function<bool(std::string_view)> is_traceable_sql = [](std::string_view sql_str) -> bool { @@ -255,14 +261,7 @@ static Status init_exporter_http(unique_ptr<SpanExporter>& exporter) { } } - if (FLAGS_otel_debug) { - opentelemetry::v1::exporter::otlp::OtlpHttpExporterRuntimeOptions runtime_opts; - runtime_opts.thread_instrumentation = - make_shared<LoggingInstrumentation>("http_exporter"); - exporter = OtlpHttpExporterFactory::Create(opts, runtime_opts); - } else { - exporter = OtlpHttpExporterFactory::Create(opts); - } + exporter = OtlpHttpExporterFactory::Create(opts); return Status::OK(); } // function init_exporter_http @@ -300,6 +299,19 @@ Status init_otel_tracer() { VLOG(2) << "OpenTelemetry namespace: " << OPENTELEMETRY_STRINGIFY(OPENTELEMETRY_NAMESPACE); + otel_log_handler_ = nostd::shared_ptr<LogHandler>(new OtelLogHandler()); + GlobalLogHandler::SetLogHandler(otel_log_handler_); + + // Set the OpenTelemetry SDK internal log level based on the current glog level. The SDK + // does not support changing the log level once a Provider has been created. + if (FLAGS_otel_debug) { + GlobalLogHandler::SetLogLevel(LogLevel::Debug); + } else if (VLOG_IS_ON(1)) { + GlobalLogHandler::SetLogLevel(LogLevel::Info); + } else { + GlobalLogHandler::SetLogLevel(LogLevel::None); + } + unique_ptr<SpanExporter> exporter; if(FLAGS_otel_trace_exporter == OTEL_EXPORTER_OTLP_HTTP) { @@ -321,15 +333,7 @@ Status init_otel_tracer() { batch_opts.schedule_delay_millis = chrono::milliseconds(FLAGS_otel_trace_batch_schedule_delay_ms); - if (FLAGS_otel_debug) { - BatchSpanProcessorRuntimeOptions runtime_opts; - runtime_opts.thread_instrumentation = - make_shared<LoggingInstrumentation>("batch_span_processor"); - processor = BatchSpanProcessorFactory::Create(move(exporter), batch_opts, - runtime_opts); - } else { - processor = BatchSpanProcessorFactory::Create(move(exporter), batch_opts); - } + processor = BatchSpanProcessorFactory::Create(move(exporter), batch_opts); } else { VLOG(2) << "Using SimpleSpanProcessor for OTel spans"; LOG(WARNING) << "Setting --otel_trace_span_processor=simple blocks the query " diff --git a/tests/custom_cluster/test_otel_trace.py b/tests/custom_cluster/test_otel_trace.py index 967b516cc..eb5b1acbd 100644 --- a/tests/custom_cluster/test_otel_trace.py +++ b/tests/custom_cluster/test_otel_trace.py @@ -56,7 +56,7 @@ class TestOtelTraceBase(CustomClusterTestSuite): @CustomClusterTestSuite.with_args( - impalad_args="-v=2 --cluster_id=select_dml {}".format(TRACE_FLAGS), + impalad_args="-v=2 --cluster_id=select_dml --otel_debug {}".format(TRACE_FLAGS), cluster_size=1, tmp_dir_placeholders=[OUT_DIR], disable_log_buffering=True) class TestOtelTraceSelectsDMLs(TestOtelTraceBase): """Tests that exercise OpenTelemetry tracing behavior for select and dml queries.""" @@ -424,6 +424,24 @@ class TestOtelTraceSelectsDMLs(TestOtelTraceBase): cluster_id="select_dml", trace_cnt=2) + def test_debug_logs(self): + """Asserts OpenTelemetry SDK debug logs are written to the Impalad INFO log when + vlog is set to 2.""" + result = self.execute_query_expect_success(self.client, + "SELECT COUNT(*) FROM functional.alltypes") + assert result.success + + # Assert the trace exporter debug log lines were emitted. + self.assert_impalad_log_contains("INFO", r"otel-log-handler.cc:\d+\] \[OTLP TRACE " + r"FILE Exporter\] Export \d+ trace span\(s\) success file=\".*?" + r"\/opentelemetry-cpp-\d+.\d+.\d+\/exporters\/otlp\/src\/otlp_file_exporter.cc\" " + r"line=\"\d+\"", -1) + + self.assert_impalad_log_contains("INFO", r"otel-log-handler.cc:\d+\] \[OTLP FILE " + r"Client\] Write body\(Json\).*? file=\".*?" + r"\/opentelemetry-cpp-\d+.\d+.\d+\/exporters\/otlp\/src\/otlp_file_client.cc\" " + r"line=\"\d+\"", -1) + class TestOtelTraceSelectQueued(TestOtelTraceBase): """Tests that require setting additional startup flags to assert admission control
