{"id":5691,"date":"2021-12-14T10:46:00","date_gmt":"2021-12-14T18:46:00","guid":{"rendered":"https:\/\/devblogs.microsoft.com\/pix\/?p=5691"},"modified":"2022-01-25T13:43:04","modified_gmt":"2022-01-25T21:43:04","slug":"critical-path-analysis-in-timing-captures","status":"publish","type":"post","link":"https:\/\/devblogs.microsoft.com\/pix\/critical-path-analysis-in-timing-captures\/","title":{"rendered":"Critical path analysis in Timing Captures"},"content":{"rendered":"

The 2201.24 version of PIX on Windows<\/a> includes a new feature that uses the CPU context switch data collected during a Timing Capture<\/a> to compute the critical path for a selected PIX event. The critical path is the series of events and thread dependencies that, if shortened, would reduce the overall duration of the selected event.<\/p>\n

As an example, consider the following PIX event named MainLoop 17864<\/strong>.\u00a0 This event represents one frame of CPU time. In this frame, we can see where execution begins and ends, as represented by the dark blue boxes.\u00a0 However, there is also a significant portion of the frame drawn in a dim hatched color.\u00a0 This period of time represents a stall, or a period of time in which our main thread is not running.<\/p>\n

\"Image<\/a><\/p>\n

If we can reduce, or eliminate this time altogether, we can reduce the overall duration of the frame.\u00a0 This is where critical path analysis comes in.<\/p>\n

To compute the critical path, right click on the event and select Calculate Critical Path for Selected PIX event<\/strong> from the context menu.<\/p>\n

\"Image<\/a><\/p>\n

The critical path is displayed in a new lane in the Timeline named \u201cCritical path\u201d followed by the event name.\u00a0 As before, we can see the periods of time at the beginning and the end of the frame when our main thread is executing.\u00a0 But now, the shaded area representing the stall is filled in with information about the events that were running during the stall, and therefore accounted for the overall stalled time.<\/p>\n

\"Image<\/a><\/p>\n

The change in color of the thread indicator line during the stall from peach, to green to orange indicates that there are three different threads running during this time.<\/p>\n

\"Image<\/a><\/p>\n

So now that we\u2019ve seen what\u2019s running, let\u2019s look at why those events ran, which resulted in this long stall.<\/p>\n

We\u2019ll start by focusing on the transition from our main thread to the first thread that runs during the stall.\u00a0 Clicking on the vertical red line at the point in time when our main thread stopped running causes a dependency arrow to be drawn.\u00a0 This arrow indicates there is a direct dependency between these two threads.<\/p>\n

\"Image<\/a><\/p>\n

Tooltips can be used to understand why the dependency exists.\u00a0 Hovering over the new thread displays a tooltip that describes the reason for the dependency.\u00a0 Specifically, the tooltip shows that the Loader<\/em> thread started running because it was readied by the AppMain<\/em> thread.<\/p>\n

\"Image<\/a><\/p>\n

The dependency between the Loader<\/em> thread and AppMain<\/em> is one of the reasons for the stall, but it is not the only reason.\u00a0 Two additional threads ran during the time that AppMain<\/em> was stalled, the thread that ran a series of TaskWrapper<\/em> events and the thread that ran an event named DoneWorking<\/em>.<\/p>\n

These two threads are unrelated, that is, there is no direct dependency between them.\u00a0 However, the fact that one follows after the other in the timeline means that these events are executing in sequence.\u00a0 But if they\u2019re not dependent on each other, why can\u2019t they run in parallel, thereby reducing the time of our stall?<\/p>\n

By hovering over these events, tooltips are displayed that provides the answer.\u00a0 In this case, the two threads were both assigned to the same core (Core 4), and also had the same priority, so core contention is the reason these two events ran sequentially.\u00a0 One way to fix this is to assign these threads to different CPU cores to eliminate this contention.<\/p>\n

\"Image<\/a><\/p>\n

Analyzing additional context switches and readying events (as represented by the vertical red lines), would show that both the WorkerH1<\/em> and Worker<\/em> threads were readied by the Loader<\/em> thread, giving us a complete picture of what caused the stall.\u00a0 To summarize:<\/p>\n

    \n
  1. AppMain readied the Loader thread.\u00a0 This caused AppMain to stop running.<\/li>\n
  2. The Loader thread then readied WorkerH1 and Worker<\/li>\n
  3. WorkerH1 and Worker further lengthened the stall because they ran on the same CPU core<\/li>\n
  4. AppMain had to wait for WorkerH1 and Worker to finish before resuming execution.<\/li>\n<\/ol>\n

    A more complete description of the critical path feature can be found on the XYZ documentation page.<\/p>\n

    Steven.<\/p>\n","protected":false},"excerpt":{"rendered":"

    The 2201.24 version of PIX on Windows includes a new feature that uses the CPU context switch data collected during a Timing Capture to compute the critical path for a selected PIX event. The critical path is the series of events and thread dependencies that, if shortened, would reduce the overall duration of the selected […]<\/p>\n","protected":false},"author":1915,"featured_media":5693,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"_acf_changed":false,"footnotes":""},"categories":[1],"tags":[],"class_list":["post-5691","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-pix"],"acf":[],"blog_post_summary":"

    The 2201.24 version of PIX on Windows includes a new feature that uses the CPU context switch data collected during a Timing Capture to compute the critical path for a selected PIX event. The critical path is the series of events and thread dependencies that, if shortened, would reduce the overall duration of the selected […]<\/p>\n","_links":{"self":[{"href":"https:\/\/devblogs.microsoft.com\/pix\/wp-json\/wp\/v2\/posts\/5691","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/devblogs.microsoft.com\/pix\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/devblogs.microsoft.com\/pix\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/pix\/wp-json\/wp\/v2\/users\/1915"}],"replies":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/pix\/wp-json\/wp\/v2\/comments?post=5691"}],"version-history":[{"count":0,"href":"https:\/\/devblogs.microsoft.com\/pix\/wp-json\/wp\/v2\/posts\/5691\/revisions"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/pix\/wp-json\/wp\/v2\/media\/5693"}],"wp:attachment":[{"href":"https:\/\/devblogs.microsoft.com\/pix\/wp-json\/wp\/v2\/media?parent=5691"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/pix\/wp-json\/wp\/v2\/categories?post=5691"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/devblogs.microsoft.com\/pix\/wp-json\/wp\/v2\/tags?post=5691"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}