diff --git a/lldb/docs/lldb-gdb-remote.txt b/lldb/docs/lldb-gdb-remote.txt --- a/lldb/docs/lldb-gdb-remote.txt +++ b/lldb/docs/lldb-gdb-remote.txt @@ -495,11 +495,10 @@ // }, // ] // ], -// "counters"?: { -// "info_kind": {...parameters specific to the provided counter info kind}, -// Each entry includes information related to counters associated with -// the trace. They are described below. -// } +// "warnings"?: [], +// Non-fatal messages useful for troubleshooting. +// +// ... other attributes specific to the given tracing technology // } // // NOTES @@ -520,24 +519,22 @@ // perf_event_open. // - procfsCpuInfo: contents of the /proc/cpuinfo file. // -// Counter info kinds: -// tsc-perf-zero-conversion: +// Additional attributes: +// tscPerfZeroConversion: // -// This field allows converting Intel processor's TSC values to a wall time. +// This field allows converting Intel processor's TSC values to nanoseconds. // It is available through the Linux perf_event API when cap_user_time and cap_user_time_zero // are set. // See the documentation of time_zero in // https://man7.org/linux/man-pages/man2/perf_event_open.2.html for more information about // the calculation and the meaning of the values in the schema below. /// -// Sub-schema for this field: -// -// { -// "tsc-perf-zero-conversion": { -// "time_mult": , -// "time_shift": , -// "time_zero": , -// } +// Schema for this field: +// +// "tscPerfZeroConversion": { +// "timeMult": , +// "timeShift": , +// "timeSero": , // } //---------------------------------------------------------------------- diff --git a/lldb/include/lldb/Utility/TraceGDBRemotePackets.h b/lldb/include/lldb/Utility/TraceGDBRemotePackets.h --- a/lldb/include/lldb/Utility/TraceGDBRemotePackets.h +++ b/lldb/include/lldb/Utility/TraceGDBRemotePackets.h @@ -129,35 +129,11 @@ llvm::json::Value toJSON(const TraceCoreState &packet); -/// Interface for different algorithms used to convert trace -/// counters into different units. -template class TraceCounterConversion { -public: - virtual ~TraceCounterConversion() = default; - - /// Convert from raw counter value to the target type. - /// - /// \param[in] raw_counter_value - /// The raw counter value to be converted. - /// - /// \return - /// The converted counter value. - virtual ToType Convert(uint64_t raw_counter_value) = 0; - - /// Serialize trace counter conversion values to JSON. - /// - /// \return - /// \a llvm::json::Value representing the trace counter conversion object. - virtual llvm::json::Value toJSON() = 0; -}; - -using TraceTscConversionUP = - std::unique_ptr>; - struct TraceGetStateResponse { std::vector traced_threads; std::vector process_binary_data; llvm::Optional> cores; + std::vector warnings; }; bool fromJSON(const llvm::json::Value &value, TraceGetStateResponse &packet, diff --git a/lldb/include/lldb/Utility/TraceIntelPTGDBRemotePackets.h b/lldb/include/lldb/Utility/TraceIntelPTGDBRemotePackets.h --- a/lldb/include/lldb/Utility/TraceIntelPTGDBRemotePackets.h +++ b/lldb/include/lldb/Utility/TraceIntelPTGDBRemotePackets.h @@ -67,16 +67,7 @@ /// See the documentation of `time_zero` in /// https://man7.org/linux/man-pages/man2/perf_event_open.2.html for more /// information. -class LinuxPerfZeroTscConversion - : public TraceCounterConversion { -public: - /// Create new \a LinuxPerfZeroTscConversion object from the conversion values - /// defined in the Linux perf_event_open API. - LinuxPerfZeroTscConversion(uint32_t time_mult, uint16_t time_shift, - uint64_t time_zero) - : m_time_mult(time_mult), m_time_shift(time_shift), - m_time_zero(time_zero) {} - +struct LinuxPerfZeroTscConversion { /// Convert TSC value to nanosecond wall time. The beginning of time (0 /// nanoseconds) is defined by the kernel at boot time and has no particularly /// useful meaning. On the other hand, this value is constant for an entire @@ -89,23 +80,22 @@ /// /// \return /// Nanosecond wall time. - std::chrono::nanoseconds Convert(uint64_t raw_counter_value) override; - - llvm::json::Value toJSON() override; + std::chrono::nanoseconds ToNanos(uint64_t tsc); -private: - uint32_t m_time_mult; - uint16_t m_time_shift; - uint64_t m_time_zero; + uint32_t time_mult; + uint16_t time_shift; + uint64_t time_zero; }; struct TraceIntelPTGetStateResponse : TraceGetStateResponse { /// The TSC to wall time conversion if it exists, otherwise \b nullptr. - TraceTscConversionUP tsc_conversion; + llvm::Optional tsc_perf_zero_conversion; }; bool fromJSON(const llvm::json::Value &value, - TraceTscConversionUP &tsc_conversion, llvm::json::Path path); + LinuxPerfZeroTscConversion &packet, llvm::json::Path path); + +llvm::json::Value toJSON(const LinuxPerfZeroTscConversion &packet); bool fromJSON(const llvm::json::Value &value, TraceIntelPTGetStateResponse &packet, llvm::json::Path path); diff --git a/lldb/source/Plugins/Process/Linux/IntelPTCollector.h b/lldb/source/Plugins/Process/Linux/IntelPTCollector.h --- a/lldb/source/Plugins/Process/Linux/IntelPTCollector.h +++ b/lldb/source/Plugins/Process/Linux/IntelPTCollector.h @@ -73,6 +73,12 @@ llvm::Error TraceStart(lldb::tid_t tid, const TraceIntelPTStartRequest &request); + /// \return + /// The conversion object between TSC and wall time. It caches the result + /// upon success. + llvm::Expected + FetchPerfTscConversionParameters(); + /// The target process. NativeProcessProtocol &m_process; /// Threads traced due to "thread tracing" @@ -82,8 +88,8 @@ /// It might be \b nullptr. IntelPTProcessTraceUP m_process_trace_up; - /// TSC to wall time conversion. - TraceTscConversionUP m_tsc_conversion; + /// Cached TSC to and from wall time conversion. + llvm::Optional m_cached_tsc_conversion; }; } // namespace process_linux diff --git a/lldb/source/Plugins/Process/Linux/IntelPTCollector.cpp b/lldb/source/Plugins/Process/Linux/IntelPTCollector.cpp --- a/lldb/source/Plugins/Process/Linux/IntelPTCollector.cpp +++ b/lldb/source/Plugins/Process/Linux/IntelPTCollector.cpp @@ -33,14 +33,20 @@ using namespace llvm; IntelPTCollector::IntelPTCollector(NativeProcessProtocol &process) - : m_process(process) { - if (Expected tsc_conversion = - LoadPerfTscConversionParameters()) - m_tsc_conversion = - std::make_unique(*tsc_conversion); - else - LLDB_LOG_ERROR(GetLog(POSIXLog::Trace), tsc_conversion.takeError(), - "unable to load TSC to wall time conversion: {0}"); + : m_process(process) {} + +llvm::Expected +IntelPTCollector::FetchPerfTscConversionParameters() { + if (!m_cached_tsc_conversion) { + if (Expected tsc_conversion = + LoadPerfTscConversionParameters()) + m_cached_tsc_conversion = std::move(*tsc_conversion); + else + return createStringError(inconvertibleErrorCode(), + "Unable to load TSC to wall time conversion: %s", + toString(tsc_conversion.takeError()).c_str()); + } + return *m_cached_tsc_conversion; } Error IntelPTCollector::TraceStop(lldb::tid_t tid) { @@ -74,8 +80,20 @@ return createStringError( inconvertibleErrorCode(), "Threads currently traced. Stop tracing them first."); + // CPU tracing is useless if we can't convert tsc to nanos. + Expected tsc_conversion = + FetchPerfTscConversionParameters(); + if (!tsc_conversion) + return tsc_conversion.takeError(); + + // We force the enabledment of TSCs, which is needed for correlating the + // cpu traces. + TraceIntelPTStartRequest effective_request = request; + effective_request.enable_tsc = true; + if (Expected trace = - IntelPTMultiCoreTrace::StartOnAllCores(request, m_process)) { + IntelPTMultiCoreTrace::StartOnAllCores(effective_request, + m_process)) { m_process_trace_up = std::move(*trace); return Error::success(); } else { @@ -146,7 +164,7 @@ if (!cpu_info) return cpu_info.takeError(); - TraceGetStateResponse state; + TraceIntelPTGetStateResponse state; if (m_process_trace_up) state = m_process_trace_up->GetState(); @@ -159,6 +177,12 @@ {{IntelPTDataKinds::kTraceBuffer, thread_trace.GetTraceBufferSize()}}}); }); + + if (Expected tsc_conversion = + FetchPerfTscConversionParameters()) + state.tsc_perf_zero_conversion = *tsc_conversion; + else + state.warnings.push_back(toString(tsc_conversion.takeError())); return toJSON(state); } diff --git a/lldb/source/Plugins/Process/Linux/IntelPTMultiCoreTrace.h b/lldb/source/Plugins/Process/Linux/IntelPTMultiCoreTrace.h --- a/lldb/source/Plugins/Process/Linux/IntelPTMultiCoreTrace.h +++ b/lldb/source/Plugins/Process/Linux/IntelPTMultiCoreTrace.h @@ -72,7 +72,7 @@ void ProcessWillResume() override; - TraceGetStateResponse GetState() override; + TraceIntelPTGetStateResponse GetState() override; bool TracesThread(lldb::tid_t tid) const override; diff --git a/lldb/source/Plugins/Process/Linux/IntelPTMultiCoreTrace.cpp b/lldb/source/Plugins/Process/Linux/IntelPTMultiCoreTrace.cpp --- a/lldb/source/Plugins/Process/Linux/IntelPTMultiCoreTrace.cpp +++ b/lldb/source/Plugins/Process/Linux/IntelPTMultiCoreTrace.cpp @@ -153,8 +153,8 @@ }); } -TraceGetStateResponse IntelPTMultiCoreTrace::GetState() { - TraceGetStateResponse state; +TraceIntelPTGetStateResponse IntelPTMultiCoreTrace::GetState() { + TraceIntelPTGetStateResponse state; for (size_t i = 0; m_process.GetThreadAtIndex(i); i++) state.traced_threads.push_back( diff --git a/lldb/source/Plugins/Process/Linux/IntelPTPerThreadProcessTrace.h b/lldb/source/Plugins/Process/Linux/IntelPTPerThreadProcessTrace.h --- a/lldb/source/Plugins/Process/Linux/IntelPTPerThreadProcessTrace.h +++ b/lldb/source/Plugins/Process/Linux/IntelPTPerThreadProcessTrace.h @@ -42,7 +42,7 @@ llvm::Error TraceStop(lldb::tid_t tid) override; - TraceGetStateResponse GetState() override; + TraceIntelPTGetStateResponse GetState() override; llvm::Expected> GetBinaryData(const TraceGetBinaryDataRequest &request) override; diff --git a/lldb/source/Plugins/Process/Linux/IntelPTPerThreadProcessTrace.cpp b/lldb/source/Plugins/Process/Linux/IntelPTPerThreadProcessTrace.cpp --- a/lldb/source/Plugins/Process/Linux/IntelPTPerThreadProcessTrace.cpp +++ b/lldb/source/Plugins/Process/Linux/IntelPTPerThreadProcessTrace.cpp @@ -35,8 +35,8 @@ return m_thread_traces.TraceStart(tid, m_tracing_params); } -TraceGetStateResponse IntelPTPerThreadProcessTrace::GetState() { - TraceGetStateResponse state; +TraceIntelPTGetStateResponse IntelPTPerThreadProcessTrace::GetState() { + TraceIntelPTGetStateResponse state; m_thread_traces.ForEachThread( [&](lldb::tid_t tid, const IntelPTSingleBufferTrace &thread_trace) { state.traced_threads.push_back({tid, diff --git a/lldb/source/Plugins/Process/Linux/IntelPTProcessTrace.h b/lldb/source/Plugins/Process/Linux/IntelPTProcessTrace.h --- a/lldb/source/Plugins/Process/Linux/IntelPTProcessTrace.h +++ b/lldb/source/Plugins/Process/Linux/IntelPTProcessTrace.h @@ -26,7 +26,7 @@ virtual void ProcessWillResume() {} /// Construct a minimal jLLDBTraceGetState response for this process trace. - virtual TraceGetStateResponse GetState() = 0; + virtual TraceIntelPTGetStateResponse GetState() = 0; virtual bool TracesThread(lldb::tid_t tid) const = 0; diff --git a/lldb/source/Utility/TraceGDBRemotePackets.cpp b/lldb/source/Utility/TraceGDBRemotePackets.cpp --- a/lldb/source/Utility/TraceGDBRemotePackets.cpp +++ b/lldb/source/Utility/TraceGDBRemotePackets.cpp @@ -100,13 +100,15 @@ ObjectMapper o(value, path); return o && o.map("tracedThreads", packet.traced_threads) && o.map("processBinaryData", packet.process_binary_data) && - o.map("cores", packet.cores); + o.map("cores", packet.cores) && + o.mapOptional("warnings", packet.warnings); } json::Value toJSON(const TraceGetStateResponse &packet) { return json::Value(Object{{"tracedThreads", packet.traced_threads}, {"processBinaryData", packet.process_binary_data}, - {"cores", packet.cores}}); + {"cores", packet.cores}, + {"warnings", packet.warnings}}); } bool fromJSON(const json::Value &value, TraceCoreState &packet, diff --git a/lldb/source/Utility/TraceIntelPTGDBRemotePackets.cpp b/lldb/source/Utility/TraceIntelPTGDBRemotePackets.cpp --- a/lldb/source/Utility/TraceIntelPTGDBRemotePackets.cpp +++ b/lldb/source/Utility/TraceIntelPTGDBRemotePackets.cpp @@ -50,67 +50,47 @@ return base; } -std::chrono::nanoseconds -LinuxPerfZeroTscConversion::Convert(uint64_t raw_counter_value) { - uint64_t quot = raw_counter_value >> m_time_shift; - uint64_t rem_flag = (((uint64_t)1 << m_time_shift) - 1); - uint64_t rem = raw_counter_value & rem_flag; - return std::chrono::nanoseconds{m_time_zero + quot * m_time_mult + - ((rem * m_time_mult) >> m_time_shift)}; +std::chrono::nanoseconds LinuxPerfZeroTscConversion::ToNanos(uint64_t tsc) { + uint64_t quot = tsc >> time_shift; + uint64_t rem_flag = (((uint64_t)1 << time_shift) - 1); + uint64_t rem = tsc & rem_flag; + return std::chrono::nanoseconds{time_zero + quot * time_mult + + ((rem * time_mult) >> time_shift)}; } -json::Value LinuxPerfZeroTscConversion::toJSON() { +json::Value toJSON(const LinuxPerfZeroTscConversion &packet) { return json::Value(json::Object{ - {"kind", "tsc-perf-zero-conversion"}, - {"time_mult", m_time_mult}, - {"time_shift", m_time_shift}, - {"time_zero", m_time_zero}, + {"kind", "tscPerfZeroConversion"}, + {"timeMult", packet.time_mult}, + {"timeShift", packet.time_shift}, + {"timeZero", packet.time_zero}, }); } -bool fromJSON(const json::Value &value, TraceTscConversionUP &tsc_conversion, +bool fromJSON(const json::Value &value, LinuxPerfZeroTscConversion &packet, json::Path path) { ObjectMapper o(value, path); - uint64_t time_mult, time_shift, time_zero; - if (!o || !o.map("time_mult", time_mult) || - !o.map("time_shift", time_shift) || !o.map("time_zero", time_zero)) + if (!o || !o.map("timeMult", time_mult) || !o.map("timeShift", time_shift) || + !o.map("timeZero", time_zero)) return false; - - tsc_conversion = std::make_unique( - static_cast(time_mult), static_cast(time_shift), - time_zero); - + packet.time_mult = time_mult; + packet.time_zero = time_zero; + packet.time_shift = time_shift; return true; } bool fromJSON(const json::Value &value, TraceIntelPTGetStateResponse &packet, json::Path path) { ObjectMapper o(value, path); - if (!o || !fromJSON(value, (TraceGetStateResponse &)packet, path)) - return false; - - const Object &obj = *(value.getAsObject()); - if (const json::Value *counters = obj.get("counters")) { - json::Path subpath = path.field("counters"); - ObjectMapper ocounters(*counters, subpath); - if (!ocounters || !ocounters.mapOptional("tsc-perf-zero-conversion", - packet.tsc_conversion)) - return false; - } - return true; + return o && fromJSON(value, (TraceGetStateResponse &)packet, path) && + o.map("tscPerfZeroConversion", packet.tsc_perf_zero_conversion); } json::Value toJSON(const TraceIntelPTGetStateResponse &packet) { json::Value base = toJSON((const TraceGetStateResponse &)packet); - - if (packet.tsc_conversion) { - std::vector counters{}; - base.getAsObject()->try_emplace( - "counters", json::Object{{"tsc-perf-zero-conversion", - packet.tsc_conversion->toJSON()}}); - } - + base.getAsObject()->insert( + {"tscPerfZeroConversion", packet.tsc_perf_zero_conversion}); return base; } diff --git a/lldb/test/API/commands/trace/multiple-threads/TestTraceStartStopMultipleThreads.py b/lldb/test/API/commands/trace/multiple-threads/TestTraceStartStopMultipleThreads.py --- a/lldb/test/API/commands/trace/multiple-threads/TestTraceStartStopMultipleThreads.py +++ b/lldb/test/API/commands/trace/multiple-threads/TestTraceStartStopMultipleThreads.py @@ -200,7 +200,8 @@ self.expect("b 19") self.expect("c") - # We will assert that the trace state will contain valid context switch and trace buffer entries + # We will assert that the trace state will contain valid context switch and trace buffer entries. + # Besides that, we need to get tsc-to-nanos conversion information. # We first parse the json response from the custom packet self.runCmd("""process plugin packet send 'jLLDBTraceGetState:{"type":"intel-pt"}]'""") @@ -213,6 +214,7 @@ self.assertTrue(output is not None) self.assertIn("cores", output) + self.assertIn("tscPerfZeroConversion", output) found_non_empty_context_switch = False for core in output["cores"]: diff --git a/lldb/unittests/Process/Linux/PerfTests.cpp b/lldb/unittests/Process/Linux/PerfTests.cpp --- a/lldb/unittests/Process/Linux/PerfTests.cpp +++ b/lldb/unittests/Process/Linux/PerfTests.cpp @@ -77,7 +77,7 @@ GTEST_SKIP() << toString(tsc_after_sleep.takeError()); std::chrono::nanoseconds converted_tsc_diff = - params->Convert(*tsc_after_sleep) - params->Convert(*tsc_before_sleep); + params->ToNanos(*tsc_after_sleep) - params->ToNanos(*tsc_before_sleep); std::chrono::microseconds acceptable_overhead(500);