Implement A Thread Time View for Universal Traces#2320
Conversation
These will be required later when implementing offline symbol resolution for ELF images.
Starting with the V6 file format, the processor number is always set. This enables consumers to build tools based on processor usage. For example, this enables tools such as ThreadTime and Processor stacks to be implemented for universal traces.
marklio
left a comment
There was a problem hiding this comment.
In general, this looks reasonable. I have some question/suggestions (some of which) I think merit discussion, so I'm gonna mark this "comment" instead of approve for now
| // The value is the amount of time that thread was switched out. | ||
|
|
||
| TraceThread thread = data.Thread(); | ||
| if (thread == null) |
There was a problem hiding this comment.
Is this hardening against a plausible scenario? Or is this representative of a "do not crash" principle in this codebase? That is, would a null thread here be indicative of a bug elsewhere that we are making hard to diagnose by simply writing to Debug?
There was a problem hiding this comment.
For universal traces this would be a bug. We create all of the threads that we know about when opening the trace for the first time. It's important to check for null here since we don't want to break the tool if we introduce a bug elsewhere. That said, we could potentially do something better here. From a layering perspective, there's not a good log to write to, but that's something that we could fix going forward. Thoughts?
There was a problem hiding this comment.
This is a hard call when a tool is so widely used on a diversity of inputs we can't hope to reasonably cover in validation. Do we use Watson to look at crashes? If this were my tool, I'd want to be set up to get the very best diagnostic artifacts. What is the experience of this "log and ignore" approach? Is it actually less annoying than an actionable crash for the type of user that runs the tool? Would be sweet to have the UI be isolated from this processing in a way that allowed actionable diagnostics to flow and provide a good UI experience, but that's a lot of refactoring.
There was a problem hiding this comment.
On Watson - I don't usually look at it too much, but on occasion yes. I would say that yes, the current behavior is less annoying than the crash. I usually see this fall into one of two buckets:
- There is a single or very small number of events that get ignored because the thread for whatever reason didn't get created.
- We're missing something important in the trace and when you open the view it's effectively empty.
In the first case, the user's analysis is almost always unaffected. In the second case, it's very obvious something went wrong and the user will re-collect and/or report the issue.
I do agree with you - there is a pattern missing here around how we egress diagnostics. Some of the very core pieces of TraceEvent have logging capabilities that PerfView just has to turn on. That pattern likely just needs to be extended here (and frankly to many other places).
| // If the thread wasn't previously marked as blocked, then mark it. | ||
| if (!m_threadState[(int)thread.ThreadIndex].ThreadBlocked) | ||
| { | ||
| double startTimeStampRelMsec = m_eventLog.QPCTimeToRelMSec(data.TimeStampQPC - (long)data.Value); |
There was a problem hiding this comment.
Below, you use data.TimeStampRelativeMSec. This is calculation different? The answer to this may answer my question above
There was a problem hiding this comment.
TraceEvent does most of its calculations in milliseconds, though the data type is a double so we get fractional milliseconds. The reason this one is in QPC is because the entity that writes the event is writing it in QPC and not milliseconds.
There was a problem hiding this comment.
I'm sure I'm missing something. On line 731 (with the same data), it uses .TimeStampRelativeMSec. And further below on 754, which seems like the same "mark as blocked" scenario, it also uses .TimeStampRelativeMSec. What is different about THIS callsite that it does the calculation from QPC?
There was a problem hiding this comment.
I don't think this should block this particular improvement. I'm more just curious in what our story is for reacting to customer pain with this tool.
|
Thank you for the review @marklio. Answered your questions and pushed some changes. |
Updated [Microsoft.Diagnostics.Tracing.TraceEvent](https://github.com/Microsoft/perfview) from 3.1.16 to 3.2.4. <details> <summary>Release notes</summary> _Sourced from [Microsoft.Diagnostics.Tracing.TraceEvent's releases](https://github.com/Microsoft/perfview/releases)._ ## 3.2.4 ## Security This release contains security hardening fixes for a number of malformed-input parsing and path-traversal vulnerabilities: - Bounds-checking for malformed event payloads in the BPerf ULZ777 decompressor and event-record parser - Bounds-checking for malformed metadata in the GCDynamic, RegisteredTraceEventParser (TDH), Dynamic, and EventPipe V3 parsers - Bounds-checking for malformed PE CodeView and Resource directory entries - Path containment hardening for PDB extraction (zipped ETL + container PDBs), DiagSession resource extraction, R2R perf map writes, PdbScope module paths, and dynamic manifest writes - Path-traversal and command-execution hardening for Source Server lookups ## What's Changed * Update CsWin32 Package Version by @brianrob in microsoft/perfview#2425 * Fix incorrect field offsets when parsing ETW events with fixed-count array fields by @Copilot in microsoft/perfview#2427 * Retarget Native Profiler Builds To VS 2026 V145 Toolset by @brianrob in microsoft/perfview#2428 * Stabilize XamlMessageBox UI-thread dispatch test by @brianrob in microsoft/perfview#2430 **Full Changelog**: microsoft/perfview@v3.2.3...v3.2.4 ## 3.2.3 ## What's Changed * Upgrade Microsoft.Windows.CsWin32 to 0.3.209 (GHSA-ghhp-997w-qr28) by @Copilot in microsoft/perfview#2409 * Enable Spectre mitigations and linker optimizations for EtwClrProfiler by @danmoseley in microsoft/perfview#2410 * Fix 'unhanded' / 'occured' typos in UnhandledExceptionDialog body text by @SAY-5 in microsoft/perfview#2413 * Fix GCStats failures on dotnet trace gc-verbose collections (#2414) by @cincuranet in microsoft/perfview#2415 * C entrypoint fixes by @zachcmadsen in microsoft/perfview#2421 ## New Contributors * @SAY-5 made their first contribution in microsoft/perfview#2413 **Full Changelog**: microsoft/perfview@v3.2.2...v3.2.3 ## 3.2.2 ## What's Changed * Fix PDB Symbol Resolution for Unmerged Windows Traces by @brianrob in microsoft/perfview#2407 **Full Changelog**: microsoft/perfview@v3.2.1...v3.2.2 ## 3.2.1 ## Native and R2R Symbol Download and Parsing Now Available As of this release, if you capture a trace using [`dotnet-trace collect-linux`](https://learn.microsoft.com/en-us/dotnet/core/diagnostics/dotnet-trace#dotnet-trace-collect-linux) or [`record-trace`](https://github.com/microsoft/one-collect/tree/main/record-trace), **native and R2R symbols can now be downloaded and resolved at analysis time**. All .NET symbols (both native and R2R) are available on the Microsoft Symbol Server. Additionally, many Azure Linux symbol files are available on the Microsoft Symbol Server. For those targeting other distros, PerfView and TraceEvent are capable of pulling those symbol files from local directories by adding a local symbol path pointing to the files. Most of the work for this was completed in PerfView and TraceEvent 3.2.1 with the final required fixes present in this release. ## What's Changed * Optimize nettrace-to-TraceLog Conversion by @brianrob in microsoft/perfview#2403 * Embed missing System.Text.Json transitive dependencies in PerfView by @brianrob in microsoft/perfview#2404 **Full Changelog**: microsoft/perfview@v3.2.0...v3.2.1 ## 3.2.0 ## What's Changed * Fix Debug.Assert failures in SpeedScope tests and DynamicTraceEventParser by @brianrob in microsoft/perfview#2368 * Add TraceParserGen.Tests project and fix code generation bugs by @Copilot in microsoft/perfview#2308 * Update UsersGuide.htm by @AftabAnsari10662 in microsoft/perfview#2370 * Strip .il and .ni suffixes from TraceModuleFile.Name by @leculver in microsoft/perfview#2364 * Handle provider names that start with a numeric digit. by @brianrob in microsoft/perfview#2369 * Dispose WebView2 controls before Environment.Exit to prevent finalizer crash by @brianrob in microsoft/perfview#2371 * Refactor GetManifestForRegisteredProvider to use XmlWriter by @Copilot in microsoft/perfview#2353 * docs: Add investigation guidance for JIT-inlined missing stack frames by @Copilot in microsoft/perfview#2377 * Fix spurious BROKEN frame at top of Linux thread stacks in CPU Stacks viewer by @Copilot in microsoft/perfview#2375 * Fix NRE in AddUniversalDynamicSymbol for invalid symbol address ranges by @brianrob in microsoft/perfview#2376 * Add missing authority parameter to log by @hoyosjs in microsoft/perfview#2379 * Replace individual code owners with microsoft/perfview-reviewers group by @brianrob in microsoft/perfview#2381 * Fix Dynamic Symbol Resolution for Mappings Shared Across Multiple Processes in Universal Traces by @brianrob in microsoft/perfview#2380 * Implement Symbol Demanglers for Linux Binaries by @brianrob in microsoft/perfview#2383 * Fix NullReferenceException race condition in TraceLog.AllocLookup/FreeLookup by @Copilot in microsoft/perfview#2387 * Add typed schema for AllocationSampled (EventID 303, .NET 10+) in ClrTraceEventParser by @Copilot in microsoft/perfview#2388 * Add ElfSymbolModule for Parsing ELF Symbol Tables by @brianrob in microsoft/perfview#2384 * Update BDN to latest version. by @cincuranet in microsoft/perfview#2389 * Fixed overflow when working with large dumps by @remilema in microsoft/perfview#2399 * Fix XamlMessageBox STA Threading Crash from Background Threads by @brianrob in microsoft/perfview#2400 * Add ELF Symbol Resolution for Linux .nettrace Traces by @brianrob in microsoft/perfview#2397 * Add Missing WCF Event Templates by @brianrob in microsoft/perfview#2390 ## New Contributors * @AftabAnsari10662 made their first contribution in microsoft/perfview#2370 * @remilema made their first contribution in microsoft/perfview#2399 **Full Changelog**: microsoft/perfview@v3.1.30...v3.2.0 ## 3.1.30 ## What's Changed * doc: fix typos by @chinwobble in microsoft/perfview#2359 * Fix SourceLink parsing to support both wildcard and exact path mappings by @ivberg in microsoft/perfview#2355 * add horizontal scrolling to eventviewer by @logangeorge01 in microsoft/perfview#2361 * Add SHA-384 and SHA-512 hash algorithm support for PDB checksums by @Copilot in microsoft/perfview#2366 ## New Contributors * @chinwobble made their first contribution in microsoft/perfview#2359 * @logangeorge01 made their first contribution in microsoft/perfview#2361 **Full Changelog**: microsoft/perfview@v3.1.29...v3.1.30 ## 3.1.29 ## What's Changed * Warn users when circular buffer overflow causes missing type info in allocation views for selected processes by @Copilot in microsoft/perfview#2326 * Special-Case BitMask Parsing by @brianrob in microsoft/perfview#2327 * Refactor PEFile and PEHeader to use ReadOnlySpan exclusively with zero-copy buffer sharing by @Copilot in microsoft/perfview#2317 * Fix cdbstack parser dropping last sample and missing metrics by @Copilot in microsoft/perfview#2329 * Fix unhandled ArgumentOutOfRangeException when exporting FlameGraph with unrendered canvas by @Copilot in microsoft/perfview#2339 * Add guidance for capturing ETW traces in Kubernetes pods by @Copilot in microsoft/perfview#2344 * Fix merge command line order in kubernetes documentation by @Copilot in microsoft/perfview#2346 * Fix GetRegisteredOrEnabledProviders() documentation claiming list is small by @Copilot in microsoft/perfview#2348 * Fix duplicate stringTable elements in instrumentation manifest by @Copilot in microsoft/perfview#2347 * Fix Histogram.AddMetric losing values after single-bucket to array transition by @Copilot in microsoft/perfview#2337 * Fix clipboard copy formatting based on selection dimensions in Stack Viewer by @Copilot in microsoft/perfview#2332 * Fix XML escaping in GetManifestForRegisteredProvider by @Copilot in microsoft/perfview#2351 * Fix race condition in ProviderNameToGuid causing ERROR_INSUFFICIENT_BUFFER crashes by @Copilot in microsoft/perfview#2357 **Full Changelog**: microsoft/perfview@v3.1.28...v3.1.29 ## 3.1.28 ## What's Changed * Add support for Boolean8 to NetTrace V6. by @noahfalk in microsoft/perfview#2318 * Implement A Thread Time View for Universal Traces by @brianrob in microsoft/perfview#2320 * Remove Incorrect Argument Description by @brianrob in microsoft/perfview#2323 **Full Changelog**: microsoft/perfview@v3.1.26...v3.1.28 ## 3.1.26 Roll-up through 2025/10/10. * Only dispose non-null handles in `ETWTraceEventSource` [#2291](microsoft/perfview#2291) * Small cleanup in `NettraceUniversalConverter` [#2292](microsoft/perfview#2292) * Fix hyperlink focus visibility in dark mode and improve keyboard navigation [#2295](microsoft/perfview#2295) * Gracefully handle invalid characters in `PATH` [#2296](microsoft/perfview#2296) * Fix copying First/Last columns with pipe symbols to work in time range input [#2304](microsoft/perfview#2304) ## 3.1.24 Roll-up through 2025/08/26. * Implement NuGet Central Package Version Management [#2262] * Fix broken stacks warning for universal traces [#2268] * Fix jitted code symbols in universal traces to show assembly names instead of memfd:doublemapper [#2269] * Use themed background brush for menu and filter [#2272] * Improve rendering and dark mode [#2274] * Implement configurable symbol server authentication with /SymbolsAuth command line argument for PerfView and HeapDump [#2278] * Add a themed dialog [#2276] * Fix regression: "Goto Item in Callers/Callees" now accumulates across all threads [#2284] * Fix parsing issues and add support for additional events to the Linux perf text file parser [#2286] * Fix TraceLog live session RelatedActivityID/ContainerID corruption by preserving ExtendedData [#2285] * NetTrace LabelList metadata overrides and metadata flushing [#2281] * Fix NullReferenceException in ProviderBrowser.LevelSelected when deselecting level [#2289] ## 3.1.23 Roll-up through 2025/07/11. - Fixed TraceEvent CaptureState API to support previously unsupported keyword configurations. [#2222] - Added Exception Stacks view for .nettrace files to enhance exception diagnostics. [#2223] - Corrected outdated documentation references to "GC Heap Alloc Stacks". [#2224] - Fixed off-by-one error in P/Invoke buffer handling for Windows volume events. [#2227] - Fixed broken links in the PerfView user guide. [#2225] - Improved error handling by throwing when TdhEnumerateProviders fails, enabling better diagnostics. [#2177] - Added AutomationProperties.Name to the Process Selection DataGrid for improved accessibility. [#2239] - Fixed focus indicator visibility for hyperlinks in dark mode and high contrast themes. [#2235] - Addressed NullReferenceException in Anti-Malware view. [#2233] - Fixed WebView2 crash on close by implementing proper disposal pattern. [#2230] - Added support for native AOT gcdumps, expanding compatibility with modern .NET workloads. [#2242] - Fixed NVDA screen reader issue where Theme menu items did not announce selection state. [#2237] - Extended PredefinedDynamicTraceEventParser to support dynamic events from additional sources. [#2232] - Implemented MSFZ symbol format support in SymbolReader. [#2244] - Removed usage of DefaultAzureCredential, simplifying authentication dependencies. [#2255] - Added option to hide TimeStamp columns in the EventWindow View menu. [#2247] - Fixed NVDA screen reader reporting incorrect list count for File menu separators. [#2257] - Fixed unhandled exception when double-clicking in scroll bar area with no content. [#2254] - Fixed universal symbol conversion for overlapping mappings. [#2252] - Fixed TraceEvent.props to respect ProcessorArchitecture when RuntimeIdentifier is set. [#2249] ## 3.1.22 Roll-up through 2025/06/04. - Added GC Heap Analyzer support for .nettrace files to enhance memory analysis workflows. [#2216] - Introduced PredefinedDynamicTraceEventParser for known TraceLogging events, improving trace event parsing. [#2220] - Enabled selection of process trees in the process selection dialog for multi-process analysis, allowing deeper inspection across related processes. [#2195] - Implemented sorting for the Duration column in the process selection dialog using TotalDurationSeconds, improving usability. [#2194] - Improved NetTrace parameter parsing for better command-line flexibility. [#2200] - Fixed GetActiveSessionNames to handle ERROR_MORE_DATA, resolving session enumeration issues. [#2196] - Fixed ObjectDisposedException when opening Net OS Heap Alloc Stacks, improving stability. [#2212] - Fixed null reference exception in GenFragmentationPercent method, enhancing reliability. [#2211] - Fixed TreeView auto-expansion when opening trace files. [#2218] - Fixed StackViewer issue where "Set Time Range" reset "Goto Items by callees". [#2208] - Fixed markdown table formatting when copying from the stack viewer. [#2203] - Fixed TraceEvent NuGet package to exclude Windows-specific native DLLs. [#2215] - Removed PDB generation for .NET Core assemblies using CrossGen, reducing build overhead. [#2202] - Made symbol server timeout configurable and removed dead code in SymbolReader. [#2209] - Changed help ribbons to use textblocks, enabling tab navigation. [#2201] ## 3.1.21 Roll-up through 2025/05/02. - Change NetTrace format version support - Add /OSHeapMaxMB to set a max size for OS heap sessions - Implement Nettrace Support for Traces with Universal Providers - Implement R2R Symbol Lookup for Linux Traces - Fix NetTrace parsing for Start/Stop event names - Fix IndexOutOfRangeException in ProcessGlobalHistory ## 3.1.20 Roll-up through 2025/04/01. - Flamegraph and drill-in menu improvements - Performance improvements around unhandled event dispatch - Add configurable real-time delay in TraceLogEventSource - Don't queue another flush during a real-time ETW session if one is already in-process - Allow configuration of rundown providers for real-time EventPipe sessions - Fix stack handling for NetTrace V4 - Add multi-line view for events viewer - Misc accessibility fixes ## 3.1.19 Roll-up through 2025/01/30. - Added missing time information in the Raw XML View for GCStats. - Updated activity computation logic to support OpenTelemetry events. - Changed timestamp values to use QPC time based on UTC for Relogger. - Fixed issues with report command handling. - Addressed various POH-related issues. - Implemented file-size limitation for rundown using an ETW-based approach. ## 3.1.18 Roll-up through 2024/12/11. - Fixed `perfcollect` install script on Azure Linux 3. - Updated `System.Text.Json` to address dotnet/announcements#329. ## 3.1.17 Roll-up through 2024/11/08. - Numerous accessibility fixes to PerfView. This includes switching out the previous web browser plugin to use WebView2. - Breaking changes to FastSerialization to ensure that only expected types are deserialized. This addresses potential vulnerabilities during deserialization of untrusted input. Details at microsoft/perfview#2121. Commits viewable in [compare view](microsoft/perfview@v3.1.16...v3.2.4). </details> Signed-off-by: dependabot[bot] <support@github.com> Co-authored-by: dependabot[bot] <49699333+dependabot[bot]@users.noreply.github.com>
Traces generated by https://github.com/microsoft/one-collect can provide a comprehensive view of system behavior through CPU and context switch events.
Modify the
ThreadTimeStackComputerto support aggregation of CPU and blocked time from theUniversal.Eventsprovider defined in one-collect.Expose the new view for nettrace files that contain these events.