Uploaded image for project: 'IMPALA'
  1. IMPALA
  2. IMPALA-5275

Avoid printing Status stack trace on hot paths

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Critical
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: Impala 2.10.0
    • Component/s: Backend
    • Labels:

      Description

      Summary from Matthew Jacobs:

      There are 3 known issues to fix ASAP:
      1) In ImpalaServer::GetExecSummary(), do not create Status() while holding the lock.
      2) Change error status in impala::DeserializeThriftMsg<>() to use Status::Expected
      3) PartitionedAggregationNode::CodegenUpdateTuple() handling for unsupported types (e.g. char) should use Status::Expected
      Then separately (less time critical) we should investigate how to improve our stack walking as these issues may come up again in the future. I filed IMPALA-5651.

      More detailed initial report for #2 above, from Mostafa:

      When reading Parquet data attempts to find the Parquet header prints a stack trace to the log even if the error was found successfully.
      Also printing the stack trace without logging which Parquet file was being read makes the log message useless.

      Status::Status(const string& error_msg)
        : msg_(new ErrorMsg(TErrorCode::GENERAL, error_msg)) {
        VLOG(1) << msg_->msg() << "\n" << GetStackTrace();
      }
      

      Vtune data showed that capturing the stack trace is very expensive and spends 130ms CPU per invocation.

      This is the expensive call stack btw 
      CPU Time
      1 of 8: 77.9% (0.106s of 0.136s)
      
      vmlinux ! KSTK_ESP - [unknown source file]
      vmlinux ! vm_is_stack + 0xa1 - [unknown source file]
      vmlinux ! show_map_vma + 0x268 - [unknown source file]
      vmlinux ! show_map + 0x20 - [unknown source file]
      vmlinux ! show_pid_map + 0x12 - [unknown source file]
      vmlinux ! seq_read + 0x24f - [unknown source file]
      vmlinux ! vfs_read + 0x9d - [unknown source file]
      vmlinux ! SyS_read + 0x7e - [unknown source file]
      vmlinux ! tracesys + 0xdc - [unknown source file]
      libpthread-2.17.so ! __read + 0x2c - [unknown source file]
      impalad ! google::OpenObjectFileContainingPcAndGetStartAddress + 0x2cf - [unknown source file]
      impalad ! google::SymbolizeAndDemangle + 0x488 - [unknown source file]
      impalad ! google::DumpStackTrace.constprop.9 + 0x6e - [unknown source file]
      impalad ! impala::GetStackTrace + 0x1e - debug-util.cc:321
      impalad ! impala::Status::Status + 0x68 - status.cc:114
      impalad ! impala::DeserializeThriftMsg<parquet::PageHeader> + 0x2ce - thrift-util.h:128
      impalad ! impala::BaseScalarColumnReader::ReadPageHeader + 0x182 - parquet-column-readers.cc:787
      impalad ! impala::BaseScalarColumnReader::ReadDataPage + 0x9b - parquet-column-readers.cc:966
      impalad ! impala::BaseScalarColumnReader::NextPage + 0x6e - parquet-column-readers.cc:1093
      impalad ! ReadValueBatch<false> + 0x196 - parquet-column-readers.cc:306
      impalad ! impala::ScalarColumnReader<long, (bool)1>::ReadNonRepeatedValueBatch + 0x60 - parquet-column-readers.cc:253
      impalad ! impala::HdfsParquetScanner::AssembleRows + 0x313 - hdfs-parquet-scanner.cc:950
      impalad ! impala::HdfsParquetScanner::GetNextInternal + 0x277 - hdfs-parquet-scanner.cc:482
      impalad ! impala::HdfsParquetScanner::ProcessSplit + 0x73 - hdfs-parquet-scanner.cc:409
      impalad ! impala::HdfsScanNode::ProcessSplit + 0x395 - hdfs-scan-node.cc:526
      impalad ! impala::HdfsScanNode::ScannerThread + 0xbb8 - hdfs-scan-node.cc:417
      impalad ! boost::function0<void>::operator() + 0x1a - function_template.hpp:767
      

      What gets printed to the log

      I0501 14:13:24.154422 21797 status.cc:119] couldn't deserialize thrift msg:
      No more data to read.
         @           0x838a89  impala::Status::Status()
         @           0xc955af  impala::DeserializeThriftMsg<>()
         @           0xc8c973  impala::BaseScalarColumnReader::ReadPageHeader()
         @           0xc8e0fc  impala::BaseScalarColumnReader::ReadDataPage()
         @           0xc8ee6f  impala::BaseScalarColumnReader::NextPage()
         @           0xc9d5a8  impala::ScalarColumnReader<>::ReadNonRepeatedValueBatch()
         @           0xc72764  impala::HdfsParquetScanner::AssembleRows()
         @           0xc77238  impala::HdfsParquetScanner::GetNextInternal()
         @           0xc71e74  impala::HdfsParquetScanner::ProcessSplit()
         @           0xc4eab6  impala::HdfsScanNode::ProcessSplit()
         @           0xc50719  impala::HdfsScanNode::ScannerThread()
         @           0xbdd739  impala::Thread::SuperviseThread()
         @           0xbde184  boost::detail::thread_data<>::run()
         @           0xe4f3ba  (unknown)
         @       0x3797407aa1  (unknown)
         @       0x37970e893d  (unknown)
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                bikramjeet.vig Bikramjeet Vig
                Reporter:
                mmokhtar Mostafa Mokhtar
              • Votes:
                0 Vote for this issue
                Watchers:
                9 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: