Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id 7CBC0200CF8 for ; Thu, 14 Sep 2017 21:15:15 +0200 (CEST) Received: by cust-asf.ponee.io (Postfix) id 7C2651609CD; Thu, 14 Sep 2017 19:15:15 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 724F71609C6 for ; Thu, 14 Sep 2017 21:15:14 +0200 (CEST) Received: (qmail 61675 invoked by uid 500); 14 Sep 2017 19:15:13 -0000 Mailing-List: contact reviews-help@impala.incubator.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Delivered-To: mailing list reviews@impala.incubator.apache.org Received: (qmail 61663 invoked by uid 99); 14 Sep 2017 19:15:13 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd3-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 14 Sep 2017 19:15:13 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd3-us-west.apache.org (ASF Mail Server at spamd3-us-west.apache.org) with ESMTP id E939F184BE6 for ; Thu, 14 Sep 2017 19:15:12 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd3-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 0.362 X-Spam-Level: X-Spam-Status: No, score=0.362 tagged_above=-999 required=6.31 tests=[RDNS_DYNAMIC=0.363, SPF_PASS=-0.001] autolearn=disabled Received: from mx1-lw-us.apache.org ([10.40.0.8]) by localhost (spamd3-us-west.apache.org [10.40.0.10]) (amavisd-new, port 10024) with ESMTP id NnRkAocs72SX for ; Thu, 14 Sep 2017 19:15:10 +0000 (UTC) Received: from ip-10-146-233-104.ec2.internal (ec2-75-101-130-251.compute-1.amazonaws.com [75.101.130.251]) by mx1-lw-us.apache.org (ASF Mail Server at mx1-lw-us.apache.org) with ESMTPS id D0F7E5FC8A for ; Thu, 14 Sep 2017 19:15:09 +0000 (UTC) Received: from localhost (localhost [127.0.0.1]) by ip-10-146-233-104.ec2.internal (8.14.4/8.14.4) with ESMTP id v8EJF8Cj011488; Thu, 14 Sep 2017 19:15:08 GMT Message-Id: <201709141915.v8EJF8Cj011488@ip-10-146-233-104.ec2.internal> Date: Thu, 14 Sep 2017 19:15:08 +0000 From: "Philip Zeyliger (Code Review)" To: Mostafa Mokhtar , impala-cr@cloudera.com, reviews@impala.incubator.apache.org CC: Alex Behm , Tim Armstrong Reply-To: philip@cloudera.com X-Gerrit-MessageType: comment Subject: =?UTF-8?Q?=5BImpala-ASF-CR=5D_IMPALA-5926=3A_Avoid_printing_expensive_stack_when_closing_a_session=0A?= X-Gerrit-Change-Id: I9d0ca485dd17bca758d916040745288c1a20c69f X-Gerrit-ChangeURL: X-Gerrit-Commit: 3e73ce2c4d2a591ef91291d520d4cb3e1d69b092 In-Reply-To: References: MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Content-Disposition: inline User-Agent: Gerrit/2.12.7 archived-at: Thu, 14 Sep 2017 19:15:15 -0000 Philip Zeyliger has posted comments on this change. Change subject: IMPALA-5926: Avoid printing expensive stack when closing a session ...................................................................... Patch Set 3: I took the liberty of trawling through some large impalad log files to see where else this sort of thing could be happening. What you're seeing below is the stack traces produced by status.cc from about 1GB of log files of impala on a cluster at work. I've removed the timestamps, removed the hostnames (outside of the script below), and the query ids. The punch line is that "Not implemented for this format" sure seems to come up a lot and may benefit from similar treatment. I'm not proud of it, but here's the "query": find . -type f -name '*IMPALAD*.gz' | xargs gzcat | awk '/^I/ { if(x) { print x; } x = "" } /status.cc/ { x=" "; } { if(x) { x=x $0 } }' | sed -e 's/0x[0-9a-fx]* //g' | sed -e 's/[0-9a-f]\{16\}:[0-9a-f]*/QUERYID/g' | tr -s '\t' ' ' | tr '[0-9]' 'N' | sort | uniq -c | sort -n | tee output.txt 300090 INNNN NN:NN:NN.NNNNNN NNNNN status.cc:NNNN Not implemented for this format. @ impala::Status::Status() @ impala::HdfsScanNodeBase::Codegen() @ impala::ExecNode::Codegen() @ impala::PartitionedAggregationNode::Codegen() @ impala::FragmentInstanceState::Prepare() @ impala::FragmentInstanceState::Exec() @ impala::QueryState::ExecFInstance() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 70111 INNNN NN:NN:NN.NNNNNN NNNN status.cc:NNNN Not implemented for this format. @ impala::Status::Status() @ impala::HdfsScanNodeBase::Codegen() @ impala::ExecNode::Codegen() @ impala::PartitionedAggregationNode::Codegen() @ impala::FragmentInstanceState::Prepare() @ impala::FragmentInstanceState::Exec() @ impala::QueryState::ExecFInstance() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 52119 INNNN NN:NN:NN.NNNNNN NNNNN status.cc:NNNN Session closed @ impala::Status::Status() @ impala::ImpalaServer::CloseSessionInternal() @ impala::ImpalaServer::ConnectionEnd() @ impala::ThriftServer::ThriftServerEventProcessor::deleteContext() @ apache::thrift::server::TThreadPoolServer::Task::run() @ apache::thrift::concurrency::ThreadManager::Worker::run() @ impala::ThriftThread::RunRunnable() @ boost::detail::function::void_function_obj_invokerN<>::invoke() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 50797 INNNN NN:NN:NN.NNNNNN NNNNNN status.cc:NNNN Not implemented for this format. @ impala::Status::Status() @ impala::HdfsScanNodeBase::Codegen() @ impala::ExecNode::Codegen() @ impala::PartitionedAggregationNode::Codegen() @ impala::FragmentInstanceState::Prepare() @ impala::FragmentInstanceState::Exec() @ impala::QueryState::ExecFInstance() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 43115 INNNN NN:NN:NN.NNNNNN NNNNN status.cc:NNNN Not implemented for this format. @ impala::Status::Status() @ impala::HdfsScanNodeBase::Codegen() @ impala::ExecNode::Codegen() @ impala::TopNNode::Codegen() @ impala::FragmentInstanceState::Prepare() @ impala::FragmentInstanceState::Exec() @ impala::QueryState::ExecFInstance() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 21064 INNNN NN:NN:NN.NNNNNN NNNNN status.cc:NNNN Session closed @ impala::Status::Status() @ impala::ImpalaServer::CloseSessionInternal() @ impala::ImpalaServer::CloseSession() @ apache::hive::service::cli::thrift::TCLIServiceProcessor::process_CloseSession() @ apache::hive::service::cli::thrift::TCLIServiceProcessor::dispatchCall() @ apache::thrift::TDispatchProcessor::process() @ apache::thrift::server::TThreadPoolServer::Task::run() @ apache::thrift::concurrency::ThreadManager::Worker::run() @ impala::ThriftThread::RunRunnable() @ boost::detail::function::void_function_obj_invokerN<>::invoke() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 16750 INNNN NN:NN:NN.NNNNNN NNNNNN status.cc:NNNN Session closed @ impala::Status::Status() @ impala::ImpalaServer::CloseSessionInternal() @ impala::ImpalaServer::ConnectionEnd() @ impala::ThriftServer::ThriftServerEventProcessor::deleteContext() @ apache::thrift::server::TThreadPoolServer::Task::run() @ apache::thrift::concurrency::ThreadManager::Worker::run() @ impala::ThriftThread::RunRunnable() @ boost::detail::function::void_function_obj_invokerN<>::invoke() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 10784 INNNN NN:NN:NN.NNNNNN NNNN status.cc:NNNN Not implemented for this format. @ impala::Status::Status() @ impala::HdfsScanNodeBase::Codegen() @ impala::ExecNode::Codegen() @ impala::TopNNode::Codegen() @ impala::FragmentInstanceState::Prepare() @ impala::FragmentInstanceState::Exec() @ impala::QueryState::ExecFInstance() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 9112 INNNN NN:NN:NN.NNNNNN NNNN status.cc:NNNN Session closed @ impala::Status::Status() @ impala::ImpalaServer::CloseSessionInternal() @ impala::ImpalaServer::ConnectionEnd() @ impala::ThriftServer::ThriftServerEventProcessor::deleteContext() @ apache::thrift::server::TThreadPoolServer::Task::run() @ apache::thrift::concurrency::ThreadManager::Worker::run() @ impala::ThriftThread::RunRunnable() @ boost::detail::function::void_function_obj_invokerN<>::invoke() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 7855 INNNN NN:NN:NN.NNNNNN NNNNNN status.cc:NNNN Not implemented for this format. @ impala::Status::Status() @ impala::HdfsScanNodeBase::Codegen() @ impala::ExecNode::Codegen() @ impala::TopNNode::Codegen() @ impala::FragmentInstanceState::Prepare() @ impala::FragmentInstanceState::Exec() @ impala::QueryState::ExecFInstance() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 5700 INNNN NN:NN:NN.NNNNNN NNNNNN status.cc:NNNN Session closed @ impala::Status::Status() @ impala::ImpalaServer::CloseSessionInternal() @ impala::ImpalaServer::CloseSession() @ apache::hive::service::cli::thrift::TCLIServiceProcessor::process_CloseSession() @ apache::hive::service::cli::thrift::TCLIServiceProcessor::dispatchCall() @ apache::thrift::TDispatchProcessor::process() @ apache::thrift::server::TThreadPoolServer::Task::run() @ apache::thrift::concurrency::ThreadManager::Worker::run() @ impala::ThriftThread::RunRunnable() @ boost::detail::function::void_function_obj_invokerN<>::invoke() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 4761 INNNN NN:NN:NN.NNNNNN NNNN status.cc:NNNN Session closed @ impala::Status::Status() @ impala::ImpalaServer::CloseSessionInternal() @ impala::ImpalaServer::CloseSession() @ apache::hive::service::cli::thrift::TCLIServiceProcessor::process_CloseSession() @ apache::hive::service::cli::thrift::TCLIServiceProcessor::dispatchCall() @ apache::thrift::TDispatchProcessor::process() @ apache::thrift::server::TThreadPoolServer::Task::run() @ apache::thrift::concurrency::ThreadManager::Worker::run() @ impala::ThriftThread::RunRunnable() @ boost::detail::function::void_function_obj_invokerN<>::invoke() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 4080 INNNN NN:NN:NN.NNNNNN NNNNN status.cc:NNN RPC recv timed out: Client hostname:NNNNN timed-out during recv call. @ impala::Status::Status() @ impala::DataStreamSender::Channel::DoTransmitDataRpc() @ impala::DataStreamSender::Channel::TransmitDataHelper() @ impala::DataStreamSender::Channel::TransmitData() @ impala::ThreadPool<>::WorkerThread() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 3976 INNNN NN:NN:NN.NNNNNN NNN status.cc:NNNN Not implemented for this format. @ impala::Status::Status() @ impala::HdfsScanNodeBase::Codegen() @ impala::ExecNode::Codegen() @ impala::PartitionedAggregationNode::Codegen() @ impala::FragmentInstanceState::Prepare() @ impala::FragmentInstanceState::Exec() @ impala::QueryState::ExecFInstance() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 3421 INNNN NN:NN:NN.NNNNNN NNNNN status.cc:NNNN Timestamp not yet supported for codegen. @ impala::Status::Status() @ impala::HdfsScanner::CodegenWriteCompleteTuple() @ impala::HdfsTextScanner::Codegen() @ impala::HdfsScanNodeBase::Codegen() @ impala::FragmentInstanceState::Prepare() @ impala::FragmentInstanceState::Exec() @ impala::QueryState::ExecFInstance() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 3227 INNNN NN:NN:NN.NNNNNN NNNNN status.cc:NNN ReportExecStatus(): Received report for unknown query ID (probably closed or cancelled): QUERYID @ impala::Status::Status() @ impala::ImpalaServer::ReportExecStatus() @ impala::ImpalaInternalServiceProcessor::process_ReportExecStatus() @ impala::ImpalaInternalServiceProcessor::dispatchCall() @ apache::thrift::TDispatchProcessor::process() @ apache::thrift::server::TAcceptQueueServer::Task::run() @ impala::ThriftThread::RunRunnable() @ boost::detail::function::void_function_obj_invokerN<>::invoke() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 2335 INNNN NN:NN:NN.NNNNNN NNNNN status.cc:NNNN Invalid session id: QUERYID @ impala::Status::Status() @ impala::ImpalaServer::CloseSessionInternal() @ impala::ImpalaServer::CloseSession() @ apache::hive::service::cli::thrift::TCLIServiceProcessor::process_CloseSession() @ apache::hive::service::cli::thrift::TCLIServiceProcessor::dispatchCall() @ apache::thrift::TDispatchProcessor::process() @ apache::thrift::server::TThreadPoolServer::Task::run() @ apache::thrift::concurrency::ThreadManager::Worker::run() @ impala::ThriftThread::RunRunnable() @ boost::detail::function::void_function_obj_invokerN<>::invoke() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 2016 INNNN NN:NN:NN.NNNNNN NNNNNN status.cc:NNNN Timestamp not yet supported for codegen. @ impala::Status::Status() @ impala::HdfsScanner::CodegenWriteCompleteTuple() @ impala::HdfsTextScanner::Codegen() @ impala::HdfsScanNodeBase::Codegen() @ impala::FragmentInstanceState::Prepare() @ impala::FragmentInstanceState::Exec() @ impala::QueryState::ExecFInstance() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 1404 INNNN NN:NN:NN.NNNNNN NNN status.cc:NNNN Session closed @ impala::Status::Status() @ impala::ImpalaServer::CloseSessionInternal() @ impala::ImpalaServer::ConnectionEnd() @ impala::ThriftServer::ThriftServerEventProcessor::deleteContext() @ apache::thrift::server::TThreadPoolServer::Task::run() @ apache::thrift::concurrency::ThreadManager::Worker::run() @ impala::ThriftThread::RunRunnable() @ boost::detail::function::void_function_obj_invokerN<>::invoke() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 1384 INNNN NN:NN:NN.NNNNNN NNNNN status.cc:NNNN couldn't deserialize thrift msg:No more data to read. @ impala::Status::Status() @ impala::DeserializeThriftMsg<>() @ impala::BaseScalarColumnReader::ReadPageHeader() @ impala::BaseScalarColumnReader::ReadDataPage() @ impala::BaseScalarColumnReader::NextPage() @ impala::ScalarColumnReader<>::ReadNonRepeatedValueBatch() @ impala::HdfsParquetScanner::AssembleRows() @ impala::HdfsParquetScanner::GetNextInternal() @ impala::HdfsParquetScanner::ProcessSplit() @ impala::HdfsScanNode::ProcessSplit() @ impala::HdfsScanNode::ScannerThread() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 1358 INNNN NN:NN:NN.NNNNNN NNNNN status.cc:NNN RPC recv timed out: Client hostname:NNNNN timed-out during recv call. @ impala::Status::Status() @ impala::ClientConnection<>::DoRpc<>() @ impala::DataStreamSender::Channel::DoTransmitDataRpc() @ impala::DataStreamSender::Channel::TransmitDataHelper() @ impala::DataStreamSender::Channel::TransmitData() @ impala::ThreadPool<>::WorkerThread() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 1031 INNNN NN:NN:NN.NNNNNN NNNNNN status.cc:NNN RPC recv timed out: Client hostname:NNNNN timed-out during recv call. @ impala::Status::Status() @ impala::DataStreamSender::Channel::DoTransmitDataRpc() @ impala::DataStreamSender::Channel::TransmitDataHelper() @ impala::DataStreamSender::Channel::TransmitData() @ impala::ThreadPool<>::WorkerThread() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone 1008 INNNN NN:NN:NN.NNNNNN NNNNNN status.cc:NNNN couldn't deserialize thrift msg:No more data to read. @ impala::Status::Status() @ impala::DeserializeThriftMsg<>() @ impala::BaseScalarColumnReader::ReadPageHeader() @ impala::BaseScalarColumnReader::ReadDataPage() @ impala::BaseScalarColumnReader::NextPage() @ impala::ScalarColumnReader<>::ReadNonRepeatedValueBatch() @ impala::HdfsParquetScanner::AssembleRows() @ impala::HdfsParquetScanner::GetNextInternal() @ impala::HdfsParquetScanner::ProcessSplit() @ impala::HdfsScanNode::ProcessSplit() @ impala::HdfsScanNode::ScannerThread() @ impala::Thread::SuperviseThread() @ boost::detail::thread_data<>::run() @ (unknown) @ start_thread @ clone -- To view, visit http://gerrit.cloudera.org:8080/8060 To unsubscribe, visit http://gerrit.cloudera.org:8080/settings Gerrit-MessageType: comment Gerrit-Change-Id: I9d0ca485dd17bca758d916040745288c1a20c69f Gerrit-PatchSet: 3 Gerrit-Project: Impala-ASF Gerrit-Branch: master Gerrit-Owner: Mostafa Mokhtar Gerrit-Reviewer: Alex Behm Gerrit-Reviewer: Impala Public Jenkins Gerrit-Reviewer: Philip Zeyliger Gerrit-Reviewer: Tim Armstrong Gerrit-HasComments: No