[trace][intel pt] Introduce wall clock time for each trace item

[wallace]

Summary

• Decouple TSCs from trace items
• Turn TSCs into events just like CPUs. The new name is HW clock tick, wich could be reused by other vendors.
• Add a GetWallTime that returns the wall time that the trace plug-in can infer for each trace item.
• For intel pt, we are doing the following interpolation: if an instruction takes less than 1 TSC, we use that duration, otherwise, we assume the instruction took 1 TSC. This helps us avoid having to handle context switches, changes to kernel, idle times, decoding errors, etc. We are just trying to show some approximation and not the real data. For the real data, TSCs are the way to go. Besides that, we are making sure that no two trace items will give the same interpolation value. Finally, we are using as time 0 the time at which tracing started. For simplicity, I'm assuming all errors and events have a duration.

Sample output:

(lldb) r
Process 750047 launched: '/home/wallace/a.out' (x86_64)
Process 750047 stopped
* thread #1, name = 'a.out', stop reason = breakpoint 1.1
    frame #0: 0x0000000000402479 a.out`main at main.cpp:29:20
   26   };
   27
   28   int main() {
-> 29     std::vector<int> vvv;
   30     for (int i = 0; i < 100; i++)
   31       vvv.push_back(i);
   32
(lldb) process trace start -s 64kb -t --per-cpu
(lldb) b 60
Breakpoint 2: where = a.out`main + 1689 at main.cpp:60:23, address = 0x0000000000402afe
(lldb) c
Process 750047 resuming
Process 750047 stopped
* thread #1, name = 'a.out', stop reason = breakpoint 2.1
    frame #0: 0x0000000000402afe a.out`main at main.cpp:60:23
   57     map<int, int> m;
   58     m[3] = 4;
   59
-> 60     map<string, string> m2;
   61     m2["5"] = "6";
   62
   63     std::vector<std::string> vs = {"2", "3"};
(lldb) thread trace dump instructions -t -f -e thread #1: tid = 750047
    0: [379567.000 ns] (event) HW clock tick [48599428476224707]
    1: [379569.000 ns] (event) CPU core changed [new CPU=2]
    2: [390487.000 ns] (event) HW clock tick [48599428476246495]
    3: [1602508.000 ns] (event) HW clock tick [48599428478664855]
    4: [1662745.000 ns] (event) HW clock tick [48599428478785046]
  libc.so.6`malloc
    5: [1662746.995 ns] 0x00007ffff7176660    endbr64
    6: [1662748.991 ns] 0x00007ffff7176664    movq   0x32387d(%rip), %rax      ;  + 408
    7: [1662750.986 ns] 0x00007ffff717666b    pushq  %r12
    8: [1662752.981 ns] 0x00007ffff717666d    pushq  %rbp
    9: [1662754.977 ns] 0x00007ffff717666e    pushq  %rbx
    10: [1662756.972 ns] 0x00007ffff717666f    movq   (%rax), %rax
    11: [1662758.967 ns] 0x00007ffff7176672    testq  %rax, %rax
    12: [1662760.963 ns] 0x00007ffff7176675    jne    0x9c7e0                   ; <+384>
    13: [1662762.958 ns] 0x00007ffff717667b    leaq   0x17(%rdi), %rax
    14: [1662764.953 ns] 0x00007ffff717667f    cmpq   $0x1f, %rax
    15: [1662766.949 ns] 0x00007ffff7176683    ja     0x9c730                   ; <+208>
    16: [1662768.944 ns] 0x00007ffff7176730    andq   $-0x10, %rax
    17: [1662770.939 ns] 0x00007ffff7176734    cmpq   $-0x41, %rax
    18: [1662772.935 ns] 0x00007ffff7176738    seta   %dl
    19: [1662774.930 ns] 0x00007ffff717673b    jmp    0x9c690                   ; <+48>
    20: [1662776.925 ns] 0x00007ffff7176690    cmpq   %rdi, %rax
    21: [1662778.921 ns] 0x00007ffff7176693    jb     0x9c7b0                   ; <+336>
    22: [1662780.916 ns] 0x00007ffff7176699    testb  %dl, %dl
    23: [1662782.911 ns] 0x00007ffff717669b    jne    0x9c7b0                   ; <+336>
    24: [1662784.906 ns] 0x00007ffff71766a1    movq   0x3236c0(%rip), %r12      ;  + 24
(lldb) thread trace dump instructions -t -f -e -J -c 4
[
  {
    "id": 0,
    "timestamp_ns": "379567.000000",
    "event": "HW clock tick",
    "hwClock": 48599428476224707
  },
  {
    "id": 1,
    "timestamp_ns": "379569.000000",
    "event": "CPU core changed",
    "cpuId": 2
  },
  {
    "id": 2,
    "timestamp_ns": "390487.000000",
    "event": "HW clock tick",
    "hwClock": 48599428476246495
  },
  {
    "id": 3,
    "timestamp_ns": "1602508.000000",
    "event": "HW clock tick",
    "hwClock": 48599428478664855
  },
  {
    "id": 4,
    "timestamp_ns": "1662745.000000",
    "event": "HW clock tick",
    "hwClock": 48599428478785046
  },
  {
    "id": 5,
    "timestamp_ns": "1662746.995324",
    "loadAddress": "0x7ffff7176660",
    "module": "libc.so.6",
    "symbol": "malloc",
    "mnemonic": "endbr64"
  },
  {
    "id": 6,
    "timestamp_ns": "1662748.990648",
    "loadAddress": "0x7ffff7176664",
    "module": "libc.so.6",
    "symbol": "malloc",
    "mnemonic": "movq"
  },
  {
    "id": 7,
    "timestamp_ns": "1662750.985972",
    "loadAddress": "0x7ffff717666b",
    "module": "libc.so.6",
    "symbol": "malloc",
    "mnemonic": "pushq"
  },
  {
    "id": 8,
    "timestamp_ns": "1662752.981296",
    "loadAddress": "0x7ffff717666d",
    "module": "libc.so.6",
    "symbol": "malloc",
    "mnemonic": "pushq"
  }
]

[wallace]

fix nits

[jj10306]

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

183

What's purpose does the TscRange class serve? Specifically, why can't we take the same approach we take for CPU events where we just store a map and the chronologically last CPU ID on the DecodedThread:

// The cpu information is stored as a map. It maps `instruction index -> CPU`
// A CPU is associated with the next instructions that follow until the next cpu is seen.
std::map<uint64_t, lldb::cpu_id_t> m_cpus;
/// This is the chronologically last CPU ID.
llvm::Optional<uint64_t> m_last_cpu = llvm::None;

we currently store this same information for TSCs but then we have this whole additional TscRange notion that lives on a TraceCursorIntelPT

This is basically an extension of the conversation we had inline on (https://reviews.llvm.org/D129340) about eventually moving TSCs to be the same as CPUs. Perhaps now that we are making this change to treat TSCs like events (just like CPU changes) it would be a good time to revisit the design and make it simpler/consistent with CPU change events, if possible.

tl;dr iiuc the TSC lookup for an instruction is basically identical to the CPU ID lookup for an instruction, so why should the way we do the lookup be different for TSCs vs CPU IDs

191–197

I found this a little difficult to reason about.
Perhaps consistent use of the different iterator variables, minor renaming and docs may make this a little more understandable. Feel free to take none or any of the above suggestions 🙂

198–205

Doesn't this check essentially make it so m_tsc_duration_per_instruction is either 0 or 1?
Where is the heuristic that every instruction should take <= 1 TSC to execute coming from?

From a visualization perspective, how should we display instructions in a TscRange where m_tsc_duration_per_instruction is 0? Doesn't this force us to stack those instructions since will all have the same interpolated timestamp?

lldb/source/Plugins/Trace/intel-pt/DecodedThread.h

275

Now that we are introducing timestamps (ie wall clock from TSCs), should we rename this to make it clear that these are TSC values and not timestamps?

[jj10306]

AFAICT this doesn't handle the TSCs we get for CPU change events through the context switch traces, is that correct?
This will be very useful to have for visualization purposes.

[wallace]

..

[jj10306]

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

288 ↗

(On Diff #445980)

if we have both a start and end TSC, shouldn't we emit the start here (like you're doing) and then after decoding all the instructions we should also emit the the end TSC?

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

98–101

Is this correct?
I don't see an issue with choosing a 1 TSC per instruction as a heuristic in this case, but we should be cautious not to explain this heuristic as being tied to any "expected" performance of the hardware because there are way too many variables that influence IPC like differences in workload, microarchitecture (speculative execution/branch prediction implementation, vector units, super scalar, etc), etc not to mention the difference b/t TSC and CPU cycles (like you mentioned).

103

Won't our interpolation calculation be messed up since items_since_last_tsc will be counting all trace errors, events, etc and not just the instructions/events that we want to assign a timestamp to and thus should be part of this calculation?

I'm thinking of a case like below :
i - instruction, e - error

tsc, cpu_change, i, e, e, e, tsc
in this case the items_since last_tsc would be 5 even though there is only 1 instruction.

i guess this brings up a more general question around how timestamps should be assigned. For example, in this case I see a couple different options:

1. What we are doing now where we assign all events timestamps

Pro: easy implementation
Con: visualization may be weird bc timestamps are being influenced by events (ie errors) that users of the visualization don't care or know about

2. Ignore errors but treat all instructions and events the same (ie instructions and events get timestamps)
3. Ignore errors and treat instructions and events differently (ie instructions are the only things that contribute to items_since_last_tsc) and then events are simply assigned the same timestamp as an instruction

We can discuss this in more depth offline.

[wallace]

.

[wallace]

final version

[wallace]

fix test

[wallace]

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

288 ↗

(On Diff #445980)

you are right

[wallace]

fix a bug that happens when the initial trace items don't have timing information

lldb/include/lldb/Target/TraceCursor.h

public:
   ///     \b true if and only if the cursor ends up pointing to a valid item.
   virtual bool Seek(int64_t offset, SeekType origin) = 0;
 
   /// \return
   ///   The \a ExecutionContextRef of the backing thread from the creation time
   ///   of this cursor.
   ExecutionContextRef &GetExecutionContextRef();
 
-  /// Instruction, event or error information
+  /// Trace item information (instructions, errors and events)
   /// \{
 
   /// \return
   ///     The kind of item the cursor is pointing at.
   virtual lldb::TraceItemKind GetItemKind() const = 0;
 
   /// \return
   ///     Whether the cursor points to an error or not.
public:
   /// \return
   ///     Whether the cursor points to an instruction.
   bool IsInstruction() const;
 
   /// \return
   ///     The load address of the instruction the cursor is pointing at.
   virtual lldb::addr_t GetLoadAddress() const = 0;
 
-  /// Get the hardware counter of a given type associated with the current
-  /// instruction. Each architecture might support different counters. It might
-  /// happen that only some instructions of an entire trace have a given counter
-  /// associated with them.
-  ///
-  /// \param[in] counter_type
-  ///    The counter type.
-  /// \return
-  ///    The value of the counter or \b llvm::None if not available.
-  virtual llvm::Optional<uint64_t>
-  GetCounter(lldb::TraceCounter counter_type) const = 0;
-
   /// Get the CPU associated with the current trace item.
   ///
   /// This call might not be O(1), so it's suggested to invoke this method
-  /// whenever a cpu change event is fired.
+  /// whenever an eTraceEventCPUChanged event is fired.
   ///
   /// \return
   ///    The requested CPU id, or \a llvm::None if this information is
   ///    not available for the current item.
   virtual llvm::Optional<lldb::cpu_id_t> GetCPU() const = 0;
+
+  /// Get the last hardware clock value that was emitted before the current
+  /// trace item.
+  ///
+  /// This call might not be O(1), so it's suggested to invoke this method
+  /// whenever an eTraceEventHWClockTick event is fired.
+  ///
+  /// \return
+  ///     The requested HW clock value, or \a llvm::None if this information is
+  ///     not available for the current item.
+  virtual llvm::Optional<uint64_t> GetHWClock() const = 0;
+
+  /// Get the approximate wall clock time in nanoseconds at which the current
+  /// trace item was executed. Each trace plug-in has a different definition for
+  /// what time 0 means.
+  ///
+  /// \return
+  ///     The approximate wall clock time for the trace item, or \a llvm::None
+  ///     if not available.
+  virtual llvm::Optional<uint64_t> GetWallClockTime() const = 0;
   /// \}
 
 protected:
   ExecutionContextRef m_exe_ctx_ref;
   bool m_forwards = false;
 };
 } // namespace lldb_private
 
 #endif // LLDB_TARGET_TRACE_CURSOR_H

lldb/include/lldb/Target/TraceDumper.h

struct TraceDumperOptions {
   bool forwards = false;
   /// Dump only instruction addresses without disassembly nor symbol
   /// information.
   bool raw = false;
   /// Dump in json format.
   bool json = false;
   /// When dumping in JSON format, pretty print the output.
   bool pretty_print_json = false;
-  /// For each instruction, print the corresponding timestamp counter if
+  /// For each trace item, print the corresponding timestamp in nanoseconds if
   /// available.
-  bool show_tsc = false;
+  bool show_timestamps = false;
   /// Dump the events that happened between instructions.
   bool show_events = false;
   /// For each instruction, print the instruction kind.
   bool show_control_flow_kind = false;
   /// Optional custom id to start traversing from.
   llvm::Optional<uint64_t> id = llvm::None;
   /// Optional number of instructions to skip from the starting position
   /// of the cursor.
struct SymbolInfo {
     lldb::InstructionSP instruction;
     lldb_private::ExecutionContext exe_ctx;
   };
 
   /// Helper struct that holds all the information we know about a trace item
   struct TraceItem {
     lldb::user_id_t id;
     lldb::addr_t load_address;
-    llvm::Optional<uint64_t> tsc;
+    llvm::Optional<uint64_t> timestamp;
+    llvm::Optional<uint64_t> hw_clock;
     llvm::Optional<llvm::StringRef> error;
     llvm::Optional<lldb::TraceEvent> event;
     llvm::Optional<SymbolInfo> symbol_info;
     llvm::Optional<SymbolInfo> prev_symbol_info;
     llvm::Optional<lldb::cpu_id_t> cpu_id;
   };
 
   /// Interface used to abstract away the format in which the instruction

lldb/include/lldb/lldb-enumerations.h

 // Style of core file to create when calling SaveCore.
 enum SaveCoreStyle {
   eSaveCoreUnspecified = 0,
   eSaveCoreFull = 1,
   eSaveCoreDirtyOnly = 2,
   eSaveCoreStackOnly = 3,
 };
 
-// Type of counter values associated with instructions in a trace.
-enum TraceCounter {
-  // Timestamp counter, like the one offered by Intel CPUs (TSC).
-  eTraceCounterTSC = 0,
-};
-
 /// Events that might happen during a trace session.
 enum TraceEvent {
   /// Tracing was disabled for some time due to a software trigger
   eTraceEventDisabledSW,
   /// Tracing was disable for some time due to a hardware trigger
   eTraceEventDisabledHW,
   /// Event due to CPU change for a thread. This event is also fired when
   /// suddenly it's not possible to identify the cpu of a given thread.
   eTraceEventCPUChanged,
+  /// Event due to a CPU HW clock tick
+  eTraceEventHWClockTick,
 };
 
 // Enum used to identify which kind of item a \a TraceCursor is pointing at
 enum TraceItemKind {
   eTraceItemKindError = 0,
   eTraceItemKindEvent,
   eTraceItemKindInstruction,
 };
 
 } // namespace lldb
 
 #endif // LLDB_LLDB_ENUMERATIONS_H

lldb/source/Commands/CommandObjectThread.cpp

Status SetOptionValue(uint32_t option_idx, llvm::StringRef option_arg,
         m_dumper_options.forwards = true;
         break;
       }
       case 'k': {
         m_dumper_options.show_control_flow_kind = true;
         break;
       }
       case 't': {
-        m_dumper_options.show_tsc = true;
+        m_dumper_options.show_timestamps = true;
         break;
       }
       case 'e': {
         m_dumper_options.show_events = true;
         break;
       }
       case 'j': {
         m_dumper_options.json = true;

lldb/source/Commands/Options.td

let Command = "thread trace dump instructions" in {
   def thread_trace_dump_instructions_file : Option<"file", "F">, Group<1>,
     Arg<"Filename">,
     Desc<"Dump the instruction to a file instead of the standard output.">;
   def thread_trace_dump_instructions_json: Option<"json", "j">,
     Group<1>,
     Desc<"Dump in simple JSON format.">;
   def thread_trace_dump_instructions_pretty_print: Option<"pretty-json", "J">,
     Group<1>,
-    Desc<"Dump in JSON format but pretty printing the output for easier readability.">;
+    Desc<"Dump in JSON format but pretty printing the output for easier "
+    "readability.">;
   def thread_trace_dump_instructions_show_kind : Option<"kind", "k">, Group<1>,
     Desc<"Show instruction control flow kind. Refer to the enum "
     "`InstructionControlFlowKind` for a list of control flow kind. "
     "As an important note, far jumps, far calls and far returns often indicate "
     "calls to and from kernel.">;
-  def thread_trace_dump_instructions_show_tsc : Option<"tsc", "t">, Group<1>,
-    Desc<"For each instruction, print the corresponding timestamp counter if "
-    "available.">;
+  def thread_trace_dump_instructions_show_timestamps: Option<"time", "t">,
+    Group<1>,
+    Desc<"For each trace item, print the corresponding wall clock timestamp "
+    "if available.">;
   def thread_trace_dump_instructions_show_events : Option<"events", "e">,
     Group<1>,
     Desc<"Dump the events that happened during the execution of the target.">;
   def thread_trace_dump_instructions_continue: Option<"continue", "C">,
     Group<1>,
     Desc<"Continue dumping instructions right where the previous invocation of "
     "this command was left, or from the beginning if this is the first "
     "invocation. The --skip argument is discarded and the other arguments are "

lldb/source/Plugins/Trace/intel-pt/DecodedThread.h

 /// Class holding the instructions and function call hierarchy obtained from
 /// decoding a trace, as well as a position cursor used when reverse debugging
 /// the trace.
 ///
 /// Each decoded thread contains a cursor to the current position the user is
 /// stopped at. See \a Trace::GetCursorPosition for more information.
 class DecodedThread : public std::enable_shared_from_this<DecodedThread> {
 public:
+  using TSC = uint64_t;
+
   /// \class TscRange
   /// Class that represents the trace range associated with a given TSC.
   /// It provides efficient iteration to the previous or next TSC range in the
   /// decoded trace.
   ///
   /// TSC timestamps are emitted by the decoder infrequently, which means
   /// that each TSC covers a range of instruction indices, which can be used to
   /// speed up TSC lookups.
   class TscRange {
   public:
     /// Check if this TSC range includes the given instruction index.
-    bool InRange(size_t insn_index) const;
+    bool InRange(uint64_t insn_index) const;
 
     /// Get the next range chronologically.
     llvm::Optional<TscRange> Next() const;
 
     /// Get the previous range chronologically.
     llvm::Optional<TscRange> Prev() const;
 
     /// Get the TSC value.
-    size_t GetTsc() const;
+    TSC GetTsc() const;
     /// Get the smallest instruction index that has this TSC.
-    size_t GetStartInstructionIndex() const;
+    uint64_t GetStartInstructionIndex() const;
     /// Get the largest instruction index that has this TSC.
-    size_t GetEndInstructionIndex() const;
+    uint64_t GetEndInstructionIndex() const;
+    /// Get an interpolated TSC value for the given item index assuming it
+    /// belongs to the current range.
+    TSC GetInterpolatedTSC(uint64_t item_index) const;
 
   private:
     friend class DecodedThread;
 
-    TscRange(std::map<size_t, uint64_t>::const_iterator it,
+    TscRange(std::map<uint64_t, uint64_t>::const_iterator it,
              const DecodedThread &decoded_thread);
 
     /// The iterator pointing to the beginning of the range.
-    std::map<size_t, uint64_t>::const_iterator m_it;
+    std::map<uint64_t, TSC>::const_iterator m_it;
     /// The largest instruction index that has this TSC.
-    size_t m_end_index;
+    uint64_t m_end_index;
+    /// Duration per instruction
+    long double m_tsc_duration_per_instruction;
 
     const DecodedThread *m_decoded_thread;
   };
 
   // Struct holding counts for libipts errors;
   struct LibiptErrorsStats {
     // libipt error -> count
     llvm::DenseMap<const char *, int> libipt_errors_counts;
public:
   /// \param[in] insn_index
   ///   The instruction index in question.
   ///
   /// \param[in] hint_range
   ///   An optional range that might include the given index or might be a
   ///   neighbor of it. It might help speed it traversals of the trace with
   ///   short jumps.
   llvm::Optional<TscRange> CalculateTscRange(
-      size_t insn_index,
+      uint64_t insn_index,
       const llvm::Optional<DecodedThread::TscRange> &hint_range) const;
 
   /// \return
   ///   The error associated with a given trace item.
-  const char *GetErrorByIndex(size_t item_index) const;
+  const char *GetErrorByIndex(uint64_t item_index) const;
 
   /// \return
   ///   The trace item kind given an item index.
-  lldb::TraceItemKind GetItemKindByIndex(size_t item_index) const;
+  lldb::TraceItemKind GetItemKindByIndex(uint64_t item_index) const;
 
   /// \return
   ///   The underlying event type for the given trace item index.
   lldb::TraceEvent GetEventByIndex(int item_index) const;
 
   /// Get the most recent CPU id before or at the given trace item index.
   ///
   /// \param[in] item_index
   ///   The trace item index to compare with.
   ///
   /// \return
   ///   The requested cpu id, or \a llvm::None if not available.
   llvm::Optional<lldb::cpu_id_t> GetCPUByIndex(uint64_t item_index) const;
 
   /// \return
   ///     The load address of the instruction at the given index.
-  lldb::addr_t GetInstructionLoadAddress(size_t item_index) const;
-
-  /// Get a new cursor for the decoded thread.
-  lldb::TraceCursorUP CreateNewCursor();
+  lldb::addr_t GetInstructionLoadAddress(uint64_t item_index) const;
 
   /// Return an object with statistics of the TSC decoding errors that happened.
   /// A TSC error is not a fatal error and doesn't create gaps in the trace.
   /// Instead we only keep track of them as statistics.
   ///
   /// \return
   ///   An object with the statistics of TSC decoding errors.
   const LibiptErrorsStats &GetTscErrorsStats() const;
public:
   /// The approximate size in bytes used by this instance,
   /// including all the already decoded instructions.
   size_t CalculateApproximateMemoryUsage() const;
 
   lldb::ThreadSP GetThread();
 
   /// Notify this object that a new tsc has been seen.
   /// If this a new TSC, an event will be created.
-  void NotifyTsc(uint64_t tsc);
+  void NotifyTsc(TSC tsc);
 
   /// Notify this object that a CPU has been seen.
   /// If this a new CPU, an event will be created.
   void NotifyCPU(lldb::cpu_id_t cpu_id);
 
   /// Append a decoding error.
   void AppendError(const IntelPTError &error);
 
private:
   std::vector<uint8_t> m_item_kinds;
 
   /// This map contains the TSCs of the decoded instructions. It maps
   /// `instruction index -> TSC`, where `instruction index` is the first index
   /// at which the mapped TSC appears. We use this representation because TSCs
   /// are sporadic and we can think of them as ranges. If TSCs are present in
   /// the trace, all instructions will have an associated TSC, including the
   /// first one. Otherwise, this map will be empty.
-  std::map<uint64_t, uint64_t> m_timestamps;
+  std::map<uint64_t, TSC> m_timestamps;
   /// This is the chronologically last TSC that has been added.
-  llvm::Optional<uint64_t> m_last_tsc = llvm::None;
+  llvm::Optional<TSC> m_last_tsc = llvm::None;
 
   // The cpu information is stored as a map. It maps `instruction index -> CPU`
   // A CPU is associated with the next instructions that follow until the next
   // cpu is seen.
   std::map<uint64_t, lldb::cpu_id_t> m_cpus;
   /// This is the chronologically last CPU ID.
   llvm::Optional<uint64_t> m_last_cpu = llvm::None;
 

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

void IntelPTError::log(llvm::raw_ostream &OS) const {
   if (m_address != LLDB_INVALID_ADDRESS && m_address > 0)
     OS << formatv(": {0:x+16}", m_address);
 }
 
 int64_t DecodedThread::GetItemsCount() const {
   return static_cast<int64_t>(m_item_kinds.size());
 }
 
-lldb::addr_t DecodedThread::GetInstructionLoadAddress(size_t item_index) const {
+lldb::addr_t
+DecodedThread::GetInstructionLoadAddress(uint64_t item_index) const {
   return m_item_data[item_index].load_address;
 }
 
 ThreadSP DecodedThread::GetThread() { return m_thread_sp; }
 
 DecodedThread::TraceItemStorage &
 DecodedThread::CreateNewTraceItem(lldb::TraceItemKind kind) {
   m_item_kinds.push_back(kind);
   m_item_data.emplace_back();
   return m_item_data.back();
 }
 
 void DecodedThread::NotifyTsc(uint64_t tsc) {
   if (!m_last_tsc || *m_last_tsc != tsc) {
     m_timestamps.emplace(m_item_kinds.size(), tsc);
     m_last_tsc = tsc;
+    AppendEvent(lldb::eTraceEventHWClockTick);
   }
 }
 
 void DecodedThread::NotifyCPU(lldb::cpu_id_t cpu_id) {
   if (!m_last_cpu || *m_last_cpu != cpu_id) {
     m_cpus.emplace(m_item_kinds.size(), cpu_id);
     m_last_cpu = cpu_id;
     AppendEvent(lldb::eTraceEventCPUChanged);

 }
 
 void DecodedThread::EventsStats::RecordEvent(lldb::TraceEvent event) {
   events_counts[event]++;
   total_count++;
 }
 
 Optional<DecodedThread::TscRange> DecodedThread::CalculateTscRange(
-    size_t insn_index,
+    uint64_t insn_index,
     const Optional<DecodedThread::TscRange> &hint_range) const {
   // We first try to check the given hint range in case we are traversing the
   // trace in short jumps. If that fails, then we do the more expensive
   // arbitrary lookup.
   if (hint_range) {
     Optional<TscRange> candidate_range;
     if (insn_index < hint_range->GetStartInstructionIndex())
       candidate_range = hint_range->Prev();
     else if (insn_index > hint_range->GetEndInstructionIndex())
       candidate_range = hint_range->Next();
     else
       candidate_range = hint_range;
 
     if (candidate_range && candidate_range->InRange(insn_index))
       return candidate_range;
   }
   // Now we do a more expensive lookup
   auto it = m_timestamps.upper_bound(insn_index);
   if (it == m_timestamps.begin())
     return None;
 
   return TscRange(--it, *this);
 }
 
-lldb::TraceItemKind DecodedThread::GetItemKindByIndex(size_t item_index) const {
+lldb::TraceItemKind
+DecodedThread::GetItemKindByIndex(uint64_t item_index) const {
   return static_cast<lldb::TraceItemKind>(m_item_kinds[item_index]);
 }
 
-const char *DecodedThread::GetErrorByIndex(size_t item_index) const {
+const char *DecodedThread::GetErrorByIndex(uint64_t item_index) const {
   return m_item_data[item_index].error;
 }
 
 DecodedThread::DecodedThread(ThreadSP thread_sp) : m_thread_sp(thread_sp) {}
 
-lldb::TraceCursorUP DecodedThread::CreateNewCursor() {
-  return std::make_unique<TraceCursorIntelPT>(m_thread_sp, shared_from_this());
-}
-
 size_t DecodedThread::CalculateApproximateMemoryUsage() const {
   return sizeof(TraceItemStorage) * m_item_data.size() +
          sizeof(uint8_t) * m_item_kinds.size() +
          (sizeof(size_t) + sizeof(uint64_t)) * m_timestamps.size() +
          (sizeof(size_t) + sizeof(lldb::cpu_id_t)) * m_cpus.size();
 }
 
-DecodedThread::TscRange::TscRange(std::map<size_t, uint64_t>::const_iterator it,
+DecodedThread::TscRange::TscRange(std::map<uint64_t, TSC>::const_iterator it,
                                   const DecodedThread &decoded_thread)
     : m_it(it), m_decoded_thread(&decoded_thread) {
   auto next_it = m_it;
   ++next_it;
   m_end_index = (next_it == m_decoded_thread->m_timestamps.end())
-                    ? std::numeric_limits<uint64_t>::max()
+                    ? decoded_thread.GetItemsCount() - 1
                     : next_it->first - 1;
+  TSC tsc_duration =
+      next_it == m_decoded_thread->m_timestamps.end()
+          ? (m_end_index + 1 - it->first) // for the last range, we assume each
+                                          // instruction took 1 TSC
+          : next_it->second - it->second;
+  m_tsc_duration_per_instruction =
+      static_cast<long double>(tsc_duration) / (m_end_index - m_it->first + 1);
+  // duration_per_instruction will be greater than 1 if the PSBs are too spread
+  // out, e.g. when we missed instructions or there was a context switch in
+  // between. In this case, we change it to 1 to have a more real number. If
+  // duration_per_instruction is less than 1, then that means that multiple
+  // instructions were executed in the same tsc.
+  if (m_tsc_duration_per_instruction > 1)
+    m_tsc_duration_per_instruction = 1;
+}
+
+DecodedThread::TSC
+DecodedThread::TscRange::GetInterpolatedTSC(uint64_t item_index) const {
+  return GetTsc() + (item_index - GetStartInstructionIndex()) *
+                        m_tsc_duration_per_instruction;
 }
 
-size_t DecodedThread::TscRange::GetTsc() const { return m_it->second; }
+DecodedThread::TSC DecodedThread::TscRange::GetTsc() const {
+  return m_it->second;
+}
 
-size_t DecodedThread::TscRange::GetStartInstructionIndex() const {
+uint64_t DecodedThread::TscRange::GetStartInstructionIndex() const {
   return m_it->first;
 }
 
-size_t DecodedThread::TscRange::GetEndInstructionIndex() const {
+uint64_t DecodedThread::TscRange::GetEndInstructionIndex() const {
   return m_end_index;
 }
 
-bool DecodedThread::TscRange::InRange(size_t insn_index) const {
+bool DecodedThread::TscRange::InRange(uint64_t insn_index) const {
   return GetStartInstructionIndex() <= insn_index &&
          insn_index <= GetEndInstructionIndex();
 }
 
 Optional<DecodedThread::TscRange> DecodedThread::TscRange::Next() const {
   auto next_it = m_it;
   ++next_it;
   if (next_it == m_decoded_thread->m_timestamps.end())

lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h

 
 #include "ThreadDecoder.h"
 
 namespace lldb_private {
 namespace trace_intel_pt {
 
 class TraceCursorIntelPT : public TraceCursor {
 public:
-  TraceCursorIntelPT(lldb::ThreadSP thread_sp,
-                     DecodedThreadSP decoded_thread_sp);
+  TraceCursorIntelPT(
+      lldb::ThreadSP thread_sp, DecodedThreadSP decoded_thread_sp,
+      const llvm::Optional<LinuxPerfZeroTscConversion> &tsc_conversion);
 
   bool Seek(int64_t offset, SeekType origin) override;
 
   void Next() override;
 
   bool HasValue() const override;
 
   const char *GetError() const override;
 
   lldb::addr_t GetLoadAddress() const override;
 
-  llvm::Optional<uint64_t>
-  GetCounter(lldb::TraceCounter counter_type) const override;
-
   lldb::TraceEvent GetEventType() const override;
 
   llvm::Optional<lldb::cpu_id_t> GetCPU() const override;
 
+  llvm::Optional<uint64_t> GetHWClock() const override;
+
   lldb::TraceItemKind GetItemKind() const override;
 
   bool GoToId(lldb::user_id_t id) override;
 
   lldb::user_id_t GetId() const override;
 
   bool HasId(lldb::user_id_t id) const override;
 
+  llvm::Optional<uint64_t> GetWallClockTime() const override;
+
 private:
   /// Calculate the tsc range for the current position if needed.
   void CalculateTscRange();
 
   /// Storage of the actual instructions
   DecodedThreadSP m_decoded_thread_sp;
   /// Internal instruction index currently pointing at.
   int64_t m_pos;
   /// Tsc range covering the current instruction.
   llvm::Optional<DecodedThread::TscRange> m_tsc_range;
+  /// TSC to nanos conversion
+  llvm::Optional<LinuxPerfZeroTscConversion> m_tsc_conversion;
 };
 
 } // namespace trace_intel_pt
 } // namespace lldb_private
 
 #endif // LLDB_SOURCE_PLUGINS_TRACE_INTEL_PT_TRACECURSORINTELPT_H

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

 
 #include <cstdlib>
 
 using namespace lldb;
 using namespace lldb_private;
 using namespace lldb_private::trace_intel_pt;
 using namespace llvm;
 
-TraceCursorIntelPT::TraceCursorIntelPT(ThreadSP thread_sp,
-                                       DecodedThreadSP decoded_thread_sp)
-    : TraceCursor(thread_sp), m_decoded_thread_sp(decoded_thread_sp) {
+TraceCursorIntelPT::TraceCursorIntelPT(
+    ThreadSP thread_sp, DecodedThreadSP decoded_thread_sp,
+    const llvm::Optional<LinuxPerfZeroTscConversion> &tsc_conversion)
+    : TraceCursor(thread_sp), m_decoded_thread_sp(decoded_thread_sp),
+      m_tsc_conversion(tsc_conversion) {
   Seek(0, SeekType::End);
 }
 
 void TraceCursorIntelPT::CalculateTscRange() {
   // If we failed, then we look for the exact range
   if (!m_tsc_range || !m_tsc_range->InRange(m_pos))
     m_tsc_range = m_decoded_thread_sp->CalculateTscRange(
         m_pos, /*hit_range=*/m_tsc_range);

 const char *TraceCursorIntelPT::GetError() const {
   return m_decoded_thread_sp->GetErrorByIndex(m_pos);
 }
 
 lldb::addr_t TraceCursorIntelPT::GetLoadAddress() const {
   return m_decoded_thread_sp->GetInstructionLoadAddress(m_pos);
 }
 
-Optional<uint64_t>
-TraceCursorIntelPT::GetCounter(lldb::TraceCounter counter_type) const {
-  switch (counter_type) {
-  case lldb::eTraceCounterTSC:
-    if (m_tsc_range)
-      return m_tsc_range->GetTsc();
-    else
-      return llvm::None;
-  }
+Optional<uint64_t> TraceCursorIntelPT::GetHWClock() const {
+
+Optional<uint64_t> TraceCursorIntelPT::GetWallClockTime() const {
+  if (!m_tsc_conversion || !m_tsc_range)
+    return None;
+
+  return m_tsc_conversion->ToNanos(m_tsc_range->GetInterpolatedTSC(m_pos));
 }
 
 Optional<lldb::cpu_id_t> TraceCursorIntelPT::GetCPU() const {
   return m_decoded_thread_sp->GetCPUByIndex(m_pos);
 }
 
 lldb::TraceEvent TraceCursorIntelPT::GetEventType() const {
   return m_decoded_thread_sp->GetEventByIndex(m_pos);
 }
 
 bool TraceCursorIntelPT::GoToId(user_id_t id) {
   if (!HasId(id))
     return false;
   m_pos = id;
   m_tsc_range = m_decoded_thread_sp->CalculateTscRange(m_pos, m_tsc_range);
 
   return true;
 }
 
 bool TraceCursorIntelPT::HasId(lldb::user_id_t id) const {
   return static_cast<int64_t>(id) < m_decoded_thread_sp->GetItemsCount();
 }
 
 user_id_t TraceCursorIntelPT::GetId() const { return m_pos; }

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

 //===-- TraceIntelPT.cpp --------------------------------------------------===//
 //
 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
 // See https://llvm.org/LICENSE.txt for license information.
 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
 //
 //===----------------------------------------------------------------------===//
 
 #include "TraceIntelPT.h"
 
+#include "TraceCursorIntelPT.h"
+
 #include "../common/ThreadPostMortemTrace.h"
 #include "CommandObjectTraceStartIntelPT.h"
 #include "DecodedThread.h"
 #include "TraceIntelPTConstants.h"
 #include "TraceIntelPTBundleLoader.h"
 #include "TraceIntelPTBundleSaver.h"
 #include "lldb/Core/PluginManager.h"
 #include "lldb/Target/Process.h"
Expected<DecodedThreadSP> TraceIntelPT::Decode(Thread &thread) {
   if (it == storage.thread_decoders.end())
     return createStringError(inconvertibleErrorCode(), "thread not traced");
   return it->second->Decode();
 }
 
 llvm::Expected<lldb::TraceCursorUP>
 TraceIntelPT::CreateNewCursor(Thread &thread) {
   if (Expected<DecodedThreadSP> decoded_thread = Decode(thread))
-    return decoded_thread.get()->CreateNewCursor();
+    return std::make_unique<TraceCursorIntelPT>(
+        thread.shared_from_this(), *decoded_thread, m_storage.tsc_conversion);
   else
     return decoded_thread.takeError();
 }
 
 void TraceIntelPT::DumpTraceInfo(Thread &thread, Stream &s, bool verbose,
                                  bool json) {
   Storage &storage = GetUpdatedStorage();
 

lldb/source/Target/TraceCursor.cpp

 const char *TraceCursor::EventKindToString(lldb::TraceEvent event_kind) {
   switch (event_kind) {
   case lldb::eTraceEventDisabledHW:
     return "hardware disabled tracing";
   case lldb::eTraceEventDisabledSW:
     return "software disabled tracing";
   case lldb::eTraceEventCPUChanged:
     return "CPU core changed";
+  case lldb::eTraceEventHWClockTick:
+    return "HW clock tick";
   }
 }

lldb/source/Target/TraceDumper.cpp

if (item.symbol_info) {
       }
     }
 
     if (item.error && !m_was_prev_instruction_an_error)
       m_s << "    ...missing instructions\n";
 
     m_s.Format("    {0}: ", item.id);
 
-    if (m_options.show_tsc) {
-      m_s.Format("[tsc={0}] ",
-                 item.tsc ? std::to_string(*item.tsc) : "unavailable");
+    if (m_options.show_timestamps) {
+      m_s.Format("[{0}] ", item.timestamp
+                               ? (std::to_string(*item.timestamp) + " ns")
+                               : "unavailable");
     }
 
     if (item.event) {
       m_s << "(event) " << TraceCursor::EventKindToString(*item.event);
-      if (*item.event == eTraceEventCPUChanged) {
+      switch (*item.event) {
+      case eTraceEventCPUChanged:
         m_s.Format(" [new CPU={0}]",
                    item.cpu_id ? std::to_string(*item.cpu_id) : "unavailable");
+        break;
+      case eTraceEventHWClockTick:
+        m_s.Format(" [{0}]", item.hw_clock ? std::to_string(*item.hw_clock)
+                                           : "unavailable");
+        break;
+      case eTraceEventDisabledHW:
+      case eTraceEventDisabledSW:
+        break;
       }
     } else if (item.error) {
       m_s << "(error) " << *item.error;
     } else {
       m_s.Format("{0:x+16}", item.load_address);
       if (item.symbol_info && item.symbol_info->instruction) {
         m_s << "    ";
         item.symbol_info->instruction->Dump(
| {
       "cpuId"? decimal,
     } | {
       "error": string,
       "id": decimal,
       "tsc"?: string decimal,
     | {
       "loadAddress": string decimal,
       "id": decimal,
-      "tsc"?: string decimal,
+      "hwClock"?: string decimal,
+      "timestamp_ns"?: string decimal,
       "module"?: string,
       "symbol"?: string,
       "line"?: decimal,
       "column"?: decimal,
       "source"?: string,
       "mnemonic"?: string,
     }
   */
 public:
   OutputWriterJSON(Stream &s, const TraceDumperOptions &options)
       : m_s(s), m_options(options),
         m_j(m_s.AsRawOstream(),
             /*IndentSize=*/options.pretty_print_json ? 2 : 0) {
     m_j.arrayBegin();
   };
 
   ~OutputWriterJSON() { m_j.arrayEnd(); }
 
   void DumpEvent(const TraceDumper::TraceItem &item) {
     m_j.attribute("event", TraceCursor::EventKindToString(*item.event));
-    if (item.event == eTraceEventCPUChanged)
+    switch (*item.event) {
+    case eTraceEventCPUChanged:
       m_j.attribute("cpuId", item.cpu_id);
+      break;
+    case eTraceEventHWClockTick:
+      m_j.attribute("hwClock", item.hw_clock);
+      break;
+    case eTraceEventDisabledHW:
+    case eTraceEventDisabledSW:
+      break;
+    }
   }
 
   void DumpInstruction(const TraceDumper::TraceItem &item) {
     m_j.attribute("loadAddress", formatv("{0:x}", item.load_address));
     if (item.symbol_info) {
       m_j.attribute("module", ToOptionalString(GetModuleName(item)));
       m_j.attribute(
           "symbol",
if (item.symbol_info) {
         m_j.attribute("column", item.symbol_info->sc.line_entry.column);
       }
     }
   }
 
   void TraceItem(const TraceDumper::TraceItem &item) override {
     m_j.object([&] {
       m_j.attribute("id", item.id);
-      if (m_options.show_tsc)
-        m_j.attribute(
-            "tsc",
-            item.tsc ? Optional<std::string>(std::to_string(*item.tsc)) : None);
+      if (m_options.show_timestamps)
+        m_j.attribute("timestamp_ns", item.timestamp
+                                          ? Optional<std::string>(
+                                                std::to_string(*item.timestamp))
+                                          : None);
 
       if (item.event) {
         DumpEvent(item);
       } else if (item.error) {
         m_j.attribute("error", *item.error);
       } else {
         DumpInstruction(item);
       }
m_cursor_up->Seek((m_options.forwards ? 1 : -1) * *m_options.skip,
                       TraceCursor::SeekType::Current);
   }
 }
 
 TraceDumper::TraceItem TraceDumper::CreatRawTraceItem() {
   TraceItem item;
   item.id = m_cursor_up->GetId();
 
-  if (m_options.show_tsc)
-    item.tsc = m_cursor_up->GetCounter(lldb::eTraceCounterTSC);
+  if (m_options.show_timestamps)
+    item.timestamp = m_cursor_up->GetWallClockTime();
   return item;
 }
 
 /// Find the symbol context for the given address reusing the previous
 /// instruction's symbol context when possible.
 static SymbolContext
 CalculateSymbolContext(const Address &address,
                        const TraceDumper::SymbolInfo &prev_symbol_info) {
for (size_t insn_seen = 0; insn_seen < count && m_cursor_up->HasValue();
 
     last_id = m_cursor_up->GetId();
     TraceItem item = CreatRawTraceItem();
 
     if (m_cursor_up->IsEvent()) {
       if (!m_options.show_events)
         continue;
       item.event = m_cursor_up->GetEventType();
-      if (*item.event == eTraceEventCPUChanged)
+      switch (*item.event) {
+      case eTraceEventCPUChanged:
         item.cpu_id = m_cursor_up->GetCPU();
+        break;
+      case eTraceEventHWClockTick:
+        item.hw_clock = m_cursor_up->GetHWClock();
+        break;
+      case eTraceEventDisabledHW:
+      case eTraceEventDisabledSW:
+        break;
+      }
     } else if (m_cursor_up->IsError()) {
       item.error = m_cursor_up->GetError();
     } else {
       insn_seen++;
       item.load_address = m_cursor_up->GetLoadAddress();
 
       if (!m_options.raw) {
         SymbolInfo symbol_info;