[IMPALA-5940] Log-spew and performance hit from Status objects that generate stack traces unnecessarily

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Fix Version/s: Impala 2.11.0
• Component/s: Backend
• Epic Color: ghx-label-9
• Assignee: Philip Martin
• Reporter: Philip Martin
• Created: 15/Sep/17 03:30
• Updated: 05/Dec/17 20:12
• Resolved: 18/Oct/17 22:07

Description

In IMPALA-5926, we fixed a case where closing the session triggered a stack trace in the logs which impacted performance for short-running queries. Looking at log files from an active cluster, I identified a few other cases where we could clean up log spew with the same (trivial) approach. A snippet of the analysis is below.

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