diff --git a/be/src/runtime/fragment_mgr.cpp b/be/src/runtime/fragment_mgr.cpp index 23666c7258bf44..ac3684c12f5625 100644 --- a/be/src/runtime/fragment_mgr.cpp +++ b/be/src/runtime/fragment_mgr.cpp @@ -651,12 +651,7 @@ Status FragmentMgr::exec_plan_fragment(const TPipelineFragmentParams& params, QuerySource query_source, const FinishCallback& cb, const TPipelineFragmentParamsList& parent, std::shared_ptr is_prepare_success) { - VLOG_ROW << "Query: " << print_id(params.query_id) << " exec_plan_fragment params is " - << apache::thrift::ThriftDebugString(params).c_str(); - // sometimes TPipelineFragmentParams debug string is too long and glog - // will truncate the log line, so print query options seperately for debuggin purpose - VLOG_ROW << "Query: " << print_id(params.query_id) << "query options is " - << apache::thrift::ThriftDebugString(params.query_options).c_str(); + VLOG_ROW << "exec_plan_fragment " << print_fragment_params_summary(params); std::shared_ptr query_ctx; RETURN_IF_ERROR(_get_or_create_query_ctx(params, parent, query_source, query_ctx)); @@ -1074,8 +1069,8 @@ Status FragmentMgr::exec_external_plan_fragment(const TScanOpenParams& params, RETURN_IF_ERROR(_build_external_scan_selected_columns(t_query_plan_info.plan_fragment, *desc_tbl, selected_columns)); - VLOG_QUERY << "BackendService execute open() TQueryPlanInfo: " - << apache::thrift::ThriftDebugString(t_query_plan_info); + VLOG_QUERY << "BackendService execute open() query_id=" << print_id(query_id) + << ", fragment_instance_id=" << print_id(fragment_instance_id); // assign the param used to execute PlanFragment TPipelineFragmentParams exec_fragment_params; exec_fragment_params.protocol_version = (PaloInternalServiceVersion::type)0; @@ -1131,8 +1126,8 @@ Status FragmentMgr::exec_external_plan_fragment(const TScanOpenParams& params, query_options.query_type = TQueryType::EXTERNAL; query_options.be_exec_version = BeExecVersionManager::get_newest_version(); exec_fragment_params.__set_query_options(query_options); - VLOG_ROW << "external exec_plan_fragment params is " - << apache::thrift::ThriftDebugString(exec_fragment_params).c_str(); + VLOG_ROW << "external exec_plan_fragment " + << print_fragment_params_summary(exec_fragment_params); TPipelineFragmentParamsList mocked; return exec_plan_fragment(exec_fragment_params, QuerySource::EXTERNAL_CONNECTOR, mocked); diff --git a/be/src/util/debug_util.cpp b/be/src/util/debug_util.cpp index dd1ee2c7dc0726..57ef59b91fc86a 100644 --- a/be/src/util/debug_util.cpp +++ b/be/src/util/debug_util.cpp @@ -20,6 +20,7 @@ #include #include #include +#include #include #include #include @@ -41,6 +42,11 @@ namespace doris { +std::string print_fragment_params_summary(const TPipelineFragmentParams& params) { + return fmt::format("query_id={}, fragment_id={}, local_instances={}", print_id(params.query_id), + params.fragment_id, params.local_params.size()); +} + std::string print_plan_node_type(const TPlanNodeType::type& type) { std::map::const_iterator i; i = _TPlanNodeType_VALUES_TO_NAMES.find(type); diff --git a/be/src/util/debug_util.h b/be/src/util/debug_util.h index 5fad41ec637d46..81e4bcb0c2935d 100644 --- a/be/src/util/debug_util.h +++ b/be/src/util/debug_util.h @@ -26,6 +26,11 @@ namespace doris { +class TPipelineFragmentParams; + +// Only format fixed identifiers and counts. Scan properties and descriptors may contain credentials. +std::string print_fragment_params_summary(const TPipelineFragmentParams& params); + std::string print_plan_node_type(const TPlanNodeType::type& type); std::string print_query_state(const QueryState::type& type); std::string PrintTUnit(const TUnit::type& type); diff --git a/be/test/runtime/fragment_mgr_log_test.cpp b/be/test/runtime/fragment_mgr_log_test.cpp new file mode 100644 index 00000000000000..3fae2a5bd03374 --- /dev/null +++ b/be/test/runtime/fragment_mgr_log_test.cpp @@ -0,0 +1,143 @@ +// 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 +#include +#include + +#include +#include +#include +#include + +#include "common/config.h" +#include "common/logging.h" +#include "runtime/exec_env.h" +#include "runtime/fragment_mgr.h" +#include "util/debug_points.h" + +namespace doris { + +class FragmentMgrLogTest : public testing::Test, public google::LogSink { +public: + void SetUp() override { + _old_debug_points = config::enable_debug_points; + config::enable_debug_points = true; + // Stop after request logging, before creating a query context or dispatching any work. + DebugPoints::instance()->add("FragmentMgr._get_query_ctx.failed"); + _old_vlog_level = google::SetVLOGLevel("fragment_mgr", 10); + google::AddLogSink(this); + _fragment_mgr = std::make_unique(&_exec_env); + } + + void TearDown() override { + _fragment_mgr->stop(); + _fragment_mgr.reset(); + google::RemoveLogSink(this); + google::SetVLOGLevel("fragment_mgr", _old_vlog_level); + DebugPoints::instance()->remove("FragmentMgr._get_query_ctx.failed"); + config::enable_debug_points = _old_debug_points; + } + + void send(google::LogSeverity /*severity*/, const char* /*full_filename*/, + const char* /*base_filename*/, int /*line*/, const google::LogMessageTime& /*time*/, + const char* message, std::size_t message_len) override { + std::lock_guard lock(_mutex); + _messages.append(message, message_len); + _messages.push_back('\n'); + } + +protected: + static TDescriptorTable credential_descriptors() { + TJdbcTable jdbc_table; + jdbc_table.__set_jdbc_password("synthetic-jdbc-password"); + TTableDescriptor table; + table.__set_id(1); + table.__set_tableType(TTableType::JDBC_TABLE); + table.__set_jdbcTable(jdbc_table); + TTupleDescriptor tuple; + tuple.__set_id(0); + tuple.__set_byteSize(0); + tuple.__set_numNullBytes(0); + TDescriptorTable descriptors; + descriptors.__set_tupleDescriptors({tuple}); + descriptors.__set_tableDescriptors({table}); + return descriptors; + } + + std::string messages() { + std::lock_guard lock(_mutex); + return _messages; + } + + ExecEnv _exec_env; + std::unique_ptr _fragment_mgr; + +private: + std::mutex _mutex; + std::string _messages; + bool _old_debug_points = false; + int _old_vlog_level = 0; +}; + +TEST_F(FragmentMgrLogTest, PipelineRequestOmitsCredentials) { + TPipelineFragmentParams params; + TUniqueId query_id; + query_id.__set_hi(0x1234); + query_id.__set_lo(0x5678); + params.__set_query_id(query_id); + params.__set_fragment_id(9); + params.__set_desc_tbl(credential_descriptors()); + TFileScanRangeParams scan_params; + scan_params.__set_properties({{"AWS_SECRET_KEY", "synthetic-storage-secret"}, + {"unknown_property", "synthetic-future-credential"}}); + params.__set_file_scan_params({{1, scan_params}}); + TTxnParams txn_params; + txn_params.__set_token("synthetic-transaction-token"); + params.__set_txn_conf(txn_params); + + const auto status = _fragment_mgr->exec_plan_fragment(params, QuerySource::INTERNAL_FRONTEND, + TPipelineFragmentParamsList {}); + EXPECT_FALSE(status.ok()); + EXPECT_NE(std::string::npos, status.to_string().find("FragmentMgr._get_query_ctx.failed")); + const auto log = messages(); + EXPECT_NE(std::string::npos, log.find("exec_plan_fragment query_id=1234-5678, fragment_id=9")); + EXPECT_EQ(std::string::npos, log.find("synthetic-")); +} + +TEST_F(FragmentMgrLogTest, ExternalRequestOmitsDescriptorCredentials) { + TQueryPlanInfo query_plan; + query_plan.__set_desc_tbl(credential_descriptors()); + TUniqueId query_id; + query_id.__set_hi(0x1234); + query_id.__set_lo(0x5678); + TUniqueId instance_id; + instance_id.__set_hi(0xabcd); + instance_id.__set_lo(0xef01); + std::vector selected_columns; + + const auto status = _fragment_mgr->exec_external_plan_fragment( + TScanOpenParams {}, query_plan, query_id, instance_id, &selected_columns); + EXPECT_FALSE(status.ok()); + EXPECT_NE(std::string::npos, status.to_string().find("FragmentMgr._get_query_ctx.failed")); + const auto log = messages(); + EXPECT_NE(std::string::npos, log.find("query_id=1234-5678, fragment_instance_id=abcd-ef01")); + EXPECT_NE(std::string::npos, log.find("external exec_plan_fragment query_id=1234-5678")); + EXPECT_EQ(std::string::npos, log.find("synthetic-")); +} + +} // namespace doris diff --git a/be/test/util/fragment_params_log_test.cpp b/be/test/util/fragment_params_log_test.cpp new file mode 100644 index 00000000000000..833996c4740039 --- /dev/null +++ b/be/test/util/fragment_params_log_test.cpp @@ -0,0 +1,69 @@ +// 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 +#include + +#include "util/debug_util.h" + +namespace doris { + +TEST(FragmentParamsLogTest, KeepsIdentifiersAndInstanceCount) { + TPipelineFragmentParams params; + TUniqueId query_id; + query_id.__set_hi(0x1234); + query_id.__set_lo(0x5678); + params.__set_query_id(query_id); + params.__set_fragment_id(9); + params.local_params.resize(2); + + EXPECT_EQ("query_id=1234-5678, fragment_id=9, local_instances=2", + print_fragment_params_summary(params)); +} + +TEST(FragmentParamsLogTest, OmitsCredentialsWithoutChangingExecutionParams) { + TPipelineFragmentParams params; + TFileScanRangeParams scan_params; + scan_params.__set_properties({{"AWS_ACCESS_KEY", "synthetic-access-key"}, + {"AWS_SECRET_KEY", "synthetic-secret-key"}, + {"AWS_TOKEN", "synthetic-session-token"}, + {"unknown_property", "synthetic-future-credential"}}); + params.__set_file_scan_params({{1, scan_params}}); + + TJdbcTable jdbc_table; + jdbc_table.__set_jdbc_password("synthetic-jdbc-password"); + TTableDescriptor table; + table.__set_jdbcTable(jdbc_table); + table.__set_tableName("synthetic-sensitive-table-name"); + TDescriptorTable descriptors; + descriptors.__set_tableDescriptors({table}); + params.__set_desc_tbl(descriptors); + const auto original_params = params; + + // Neither known credential keys nor future free-form properties belong in the summary. + EXPECT_EQ("query_id=0-0, fragment_id=0, local_instances=0", + print_fragment_params_summary(params)); + EXPECT_EQ(original_params, params); +} + +TEST(FragmentParamsLogTest, HandlesAbsentOptionalParams) { + const TPipelineFragmentParams params; + EXPECT_EQ("query_id=0-0, fragment_id=0, local_instances=0", + print_fragment_params_summary(params)); +} + +} // namespace doris