[trace][intelpt] Fix multi CPU decoding TSC assertion error

[jj10306]

Summary

Occasionally the assertion that enforces increasing TSC values in DecodedThread::NotifyTsc
would get tripped during large multi CPU trace decoding.
The root cause of this issue was an assumption that all the data of a
PSB will fit within the start,end TSC of the "owning"
ThreadContinuousExecution. After investigating, this is not the case
because PSBs can have multiple TSCs.
This diff works around this issue by introducing a TSC upper bound for
each PSBBlockDecoder. This fixes the assertion failure by simply
"dropping" the remaining data of PSB whenever the TSC upper bound is
exceeded during decoding.
Future work will do a larger refactor of the multi CPU decoding to
remove the dependencies on this incorrect assumption so that PSB blocks
that span multiple ThreadContinuousExecutions are correctly handled.
correctly

Test Plan:
Run thread dump instructions 3 on a problematic trace and observe the assertion is no longer hit. The new error can be observed in the dump of events:

{
  "id": 5346,
  "error": "decoding truncated: TSC 64197386832965432 exceeds maximum TSC value 64197386633174537, will skip decoding the remaining data of the PSB (skipping 375 of 1336 bytes)"
},

Run relevant unittests

tools/lldb/unittests/Process/Linux/ProcessLinuxTests
tools/lldb/unittests/Utility/UtilityTests --gtest_filter=TraceGDBRemotePacketsTest.*
tools/lldb/unittests/Disassembler/x86/GetControlFlowKindx86Tests
./bin/lldb-dotest -p TestTrace

[wallace]

pretty good! I just left cosmetic requests

lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp

285–312

I suggest moving all of this to another function because it's a bit long

286

use * instead of value(). value() is rarely used in LLVM code. Also use >= instead of >

294–295

add a prefix message for easier regexp search

"decoding truncated: TSC packet {0} exceeds maximum TSC value {1} for this PSB block . Will resume decoding with the next PSB."

Use a better prefix if you can, and btw, you wrote the remining the remaining here.

296

ditto

299–307

I think let's better not include this to keep the error a bit smaller. In any case, you can do thread trace dump instructions <thread> -E and then look for the error prefix when debugging.

but if you insist, the byte offset message should come after the textual description of the error

308

return -pte_internal;

345

move this to the constructor so that it's highlighted by IDEs and appears in the public documentation

Maximum allowed value of TSCs decoded from this psb block. If this value is hit, then decoding for this block is stopped and an error is appended to the trace.

[jj10306]

Address comments

[jj10306]

lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp

299–307

I included the byte offset information so we can get an idea of what % of data we are losing each time this occurs. I'll clean this up a bit.

[wallace]

thanks. Your explanation of why the verbose error is useful was good :)

lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp

public:
   /// \param[in] next_block_ip
   ///     The starting ip at the next PSB block of the same thread if available.
   ///
   /// \param[in] decoded_thread
   ///     A \a DecodedThread object where the decoded instructions will be
   ///     appended to. It might have already some instructions.
   PSBBlockDecoder(PtInsnDecoderUP &&decoder_up, const PSBBlock &psb_block,
                   Optional<lldb::addr_t> next_block_ip,
-                  DecodedThread &decoded_thread)
+                  DecodedThread &decoded_thread,
+                  llvm::Optional<DecodedThread::TSC> tsc_upper_bound)
       : m_decoder_up(std::move(decoder_up)), m_psb_block(psb_block),
-        m_next_block_ip(next_block_ip), m_decoded_thread(decoded_thread) {}
+        m_next_block_ip(next_block_ip), m_decoded_thread(decoded_thread),
+        m_tsc_upper_bound(tsc_upper_bound) {}
 
   /// \param[in] trace_intel_pt
   ///     The main Trace object that own the PSB block.
   ///
   /// \param[in] decoder
   ///     A decoder configured to start and end within the boundaries of the
   ///     given \p psb_block.
   ///
public:
   ///     The starting ip at the next PSB block of the same thread if available.
   ///
   /// \param[in] decoded_thread
   ///     A \a DecodedThread object where the decoded instructions will be
   ///     appended to. It might have already some instructions.
   static Expected<PSBBlockDecoder>
   Create(TraceIntelPT &trace_intel_pt, const PSBBlock &psb_block,
          ArrayRef<uint8_t> buffer, Process &process,
-         Optional<lldb::addr_t> next_block_ip, DecodedThread &decoded_thread) {
+         Optional<lldb::addr_t> next_block_ip, DecodedThread &decoded_thread,
+         llvm::Optional<DecodedThread::TSC> tsc_upper_bound) {
     Expected<PtInsnDecoderUP> decoder_up =
         CreateInstructionDecoder(trace_intel_pt, buffer, process);
     if (!decoder_up)
       return decoder_up.takeError();
 
     return PSBBlockDecoder(std::move(*decoder_up), psb_block, next_block_ip,
-                           decoded_thread);
+                           decoded_thread, tsc_upper_bound);
   }
 
   void DecodePSBBlock() {
     int status = pt_insn_sync_forward(m_decoder_up.get());
     assert(status >= 0 &&
            "Synchronization shouldn't fail because this PSB was previously "
            "decoded correctly.");
 
while (HasEvents(status)) {
       std::memset(&event, 0, sizeof event);
       status = pt_insn_event(m_decoder_up.get(), &event, sizeof(event));
 
       if (IsLibiptError(status)) {
         m_decoded_thread.AppendError(IntelPTError(status));
         return status;
       }
 
-      if (event.has_tsc)
+      if (event.has_tsc) {
+        if (m_tsc_upper_bound && event.tsc > m_tsc_upper_bound.value()) {
+          // This event and all the remaining events of this PSB have a TSC
+          // outside the range of the "owning" ThreadContinuousExecution. For
+          // now we drop all of these events/instructions, future work can
+          // improve upon this by determining the "owning"
+          // ThreadContinuousExecution of the remaining PSB data.
+          std::string err_msg =
+              formatv(
+                  "TSC {0} exceeds maximum TSC value {1}. Will skip decoding"
+                  " the remining the remaining data of the PSB.",
+                  event.tsc, m_tsc_upper_bound.value())
+                  .str();
+
+          uint64_t offset;
+          int status = pt_insn_get_offset(m_decoder_up.get(), &offset);
+          if (!IsLibiptError(status)) {
+            err_msg =
+                formatv("At byte offset {0} of PSB with size {1} bytes, {2}",
+                        offset, m_psb_block.size, err_msg)
+                    .str();
+          }
+          m_decoded_thread.AppendCustomError(err_msg);
+          return -1;
+        } else {
           m_decoded_thread.NotifyTsc(event.tsc);
+        }
+      }
 
       switch (event.type) {
       case ptev_disabled:
         // The CPU paused tracing the program, e.g. due to ip filtering.
         m_decoded_thread.AppendEvent(lldb::eTraceEventDisabledHW);
         break;
       case ptev_async_disabled:
         // The kernel or user code paused tracing the program, e.g.
int ProcessPTEvents(int status) {
     return status;
   }
 
 private:
   PtInsnDecoderUP m_decoder_up;
   PSBBlock m_psb_block;
   Optional<lldb::addr_t> m_next_block_ip;
   DecodedThread &m_decoded_thread;
+  // Maximum allowed value of TSCs decoded from m_psb_block.
+  llvm::Optional<DecodedThread::TSC> m_tsc_upper_bound;
 };
 
 Error lldb_private::trace_intel_pt::DecodeSingleTraceForThread(
     DecodedThread &decoded_thread, TraceIntelPT &trace_intel_pt,
     ArrayRef<uint8_t> buffer) {
   Expected<std::vector<PSBBlock>> blocks =
       SplitTraceIntoPSBBlock(trace_intel_pt, buffer, /*expect_tscs=*/false);
   if (!blocks)
     return blocks.takeError();
 
   for (size_t i = 0; i < blocks->size(); i++) {
     PSBBlock &block = blocks->at(i);
 
     Expected<PSBBlockDecoder> decoder = PSBBlockDecoder::Create(
         trace_intel_pt, block, buffer.slice(block.psb_offset, block.size),
         *decoded_thread.GetThread()->GetProcess(),
         i + 1 < blocks->size() ? blocks->at(i + 1).starting_ip : None,
-        decoded_thread);
+        decoded_thread, llvm::None);
     if (!decoder)
       return decoder.takeError();
 
     decoder->DecodePSBBlock();
   }
 
   return Error::success();
 }
if (has_seen_psbs) {
       }
     }
 
     for (size_t j = 0; j < execution.psb_blocks.size(); j++) {
       const PSBBlock &psb_block = execution.psb_blocks[j];
 
       Expected<PSBBlockDecoder> decoder = PSBBlockDecoder::Create(
           trace_intel_pt, psb_block,
-          buffers.lookup(executions[i].thread_execution.cpu_id)
+          buffers.lookup(execution.thread_execution.cpu_id)
               .slice(psb_block.psb_offset, psb_block.size),
           *decoded_thread.GetThread()->GetProcess(),
           j + 1 < execution.psb_blocks.size()
               ? execution.psb_blocks[j + 1].starting_ip
               : None,
-          decoded_thread);
+          decoded_thread, execution.thread_execution.GetEndTSC());
       if (!decoder)
         return decoder.takeError();
 
       has_seen_psbs = true;
       decoder->DecodePSBBlock();
     }
 
     // If we haven't seen a PSB yet, then it's fine not to show errors