{"id":202,"date":"2016-05-02T02:00:34","date_gmt":"2016-05-02T02:00:34","guid":{"rendered":"http:\/\/eventlogxp.com\/blog\/?p=202"},"modified":"2016-05-02T16:47:22","modified_gmt":"2016-05-02T16:47:22","slug":"windows-boot-performance-diagnostics-part-2","status":"publish","type":"post","link":"https:\/\/eventlogxp.com\/blog\/windows-boot-performance-diagnostics-part-2\/","title":{"rendered":"Windows boot performance diagnostics. Part 2"},"content":{"rendered":"

If you read the previous part<\/a> of this article, you already know what Microsoft-Windows-Diagnostics-Performance log is for, why similar events have different event types and what information is “hidden” in the event details.<\/p>\n

Now it’s time to practice. First, we need to decide what we will try to optimize. Let’s display only startup, shutdown and standby\/resume events. The event IDs are 100, 200 and 300 respectfully. So let’s filter by event id = 100, 200, 300:
\n\"eventfilter-100-200-300\"<\/a><\/p>\n

You can optionally switch warnings off in the filter to get error and critical events, but I will leave it checked.<\/p>\n

Now we can view statistics of the events. Select Advanced from the main menu, click Analytical Reports. Then in the Analytical Report window click Report and select Event ID stats. I switched to Pivot chart for better view:
\n\"boot<\/a><\/p>\n

As you can see, I have just got a few Windows startup events in this log (and only 1 shutdown event). Most of events here are Standby\/Resume events. There are several reasons for this \u2013 I switch off\/reboot the computer very rarely, most of the time I use hibernate or sleep commands to switch off the computer. My primary drive is a SSD drive so I don’t have problems with prefetch at startup, so My PC commonly starts up in about 10 seconds. \u00a0And I don’t have too many autorun programs or services.<\/p>\n

However, I really have performance issues with hibernation and resume. So let’s check what the reason of such performance degradation can be. Event 300 contains lots of parameters (similar to event 100 described in the previous post), but they don’t describe the source of the problem. As you may remember, the details of the problems are listed in the events that follow the “basic” events. For standby\/resume \u2013 they are 3xx. So let’s filter by event id = 301-399 (Note that if you troubleshoot boot up events, it will be 101-110 or 101-199).
\n\"eventfilter-301-399\"<\/a><\/p>\n

We can build event ID stats diagram again (it is not necessary, but we may find out\u00a0common reasons of the problems):
\n\"degradation-reasons-general\"<\/a><\/p>\n

We can see that the typical reasons of the degradations are the device driver issues (302, 351) and application issues (301).<\/p>\n

So, let’s concentrate only on these events: set event filter to Event ID = 301, 302, 351
\n\"eventfilter-301-302-351\"<\/a><\/p>\n

Now we should somehow display the source of the problem. In this article<\/a>, I showed how to use custom columns. Fortunately for all these events, the sources of the problem have the same sequence numbers:
\n3 \u2013 an application file name or a driver name
\n5 – friendly name of an application or a driver
\n11 – full path to an application or a driver.<\/p>\n

These numbers you can get from the XML view of these events (double click on event and switch to XML).<\/p>\n

I will use friendly name (but you should be aware that some applications may have no friendly name):<\/p>\n

Go to View->Custom columns and add a new column from PARAM[5]:
\n\"ProblemSource-CustomColumn\"<\/a><\/p>\n

Now you can see the problem source as a column in the event list.
\n\"performance-diagnostics<\/a><\/p>\n

Let’s create a new pivot chart for this table, event log view to get statistics for “Problem source” column. Go to Advanced->Analytical reports. Then select “CustomColumn1 stats” from the Report menu.
\n\"diagnostic<\/a><\/p>\n

Now I can see that I should check if a new version of ACPI Driver for NT available (and I should pay attention to Default Hub Driver for USB and several other drivers and applications).<\/p>\n

Although I could stop at this point, I will show one more way of detecting the sources of performance issues. When researching events 101+, 201+ and 301+, you can find two parameters under EventData. They are TotalTime and DegradationTime. Totaltime is the time in milliseconds it took for processing (time to initialize a service, start an application, unload application etc). DegradationTime is the time meaning how much longer than usual it took for processing. So, we can exclude some unnecessary events that took not too much time, but are in the list. Let’s display only events that took 300 or more milliseconds. Do not close the pivot chart, just switch back to Event Log Explorer window to set filter. In the article “Advanced filtering. How to filter events by event description<\/a>”\u00a0I mentioned about setting XML query filters using XPath syntax. Now we can use it to refine events. Select View->XML query and type<\/p>\n

*[EventData[Data[@Name='TotalTime']>'300']]<\/pre>\n
In my case, the number of displayed events reduced 8 times. Switch back to Analytical Report window and click Reconcile button.
\n\"performance<\/a><\/p>\n
And we see a different picture \u2013 BlueSoleilCS and ATAPI miniport make contribution to the performance degradation.<\/p>\n
I hope that not only you learned about Microsoft-Windows-Diagnostic-Performance events, but also got helpful information about the advanced usage of Event Log Explorer. The article covered several topics that our users often miss: XML view of an event, Analytical reports, custom columns and XML query filter.<\/p>\n\"Facebook\"<\/a>\"twitter\"<\/a>\"reddit\"<\/a>\"pinterest\"<\/a>\"linkedin\"<\/a>\"mail\"<\/a>","protected":false},"excerpt":{"rendered":"
If you read the previous part of this article, you already know what Microsoft-Windows-Diagnostics-Performance log is for, why similar events have different event types and what information is “hidden” in the event details. Now it’s time to practice. First, we need to decide what we will try to optimize. Let’s display only startup, shutdown and standby\/resume events. The event IDs are 100, 200 and 300\u2026 Read More »<\/a><\/span><\/p>\n","protected":false},"author":2,"featured_media":212,"comment_status":"closed","ping_status":"open","sticky":false,"template":"","format":"standard","meta":[],"categories":[10,7,39],"tags":[57,5,32,9,35],"amp_enabled":true,"_links":{"self":[{"href":"https:\/\/eventlogxp.com\/blog\/wp-json\/wp\/v2\/posts\/202"}],"collection":[{"href":"https:\/\/eventlogxp.com\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/eventlogxp.com\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/eventlogxp.com\/blog\/wp-json\/wp\/v2\/users\/2"}],"replies":[{"embeddable":true,"href":"https:\/\/eventlogxp.com\/blog\/wp-json\/wp\/v2\/comments?post=202"}],"version-history":[{"count":5,"href":"https:\/\/eventlogxp.com\/blog\/wp-json\/wp\/v2\/posts\/202\/revisions"}],"predecessor-version":[{"id":218,"href":"https:\/\/eventlogxp.com\/blog\/wp-json\/wp\/v2\/posts\/202\/revisions\/218"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/eventlogxp.com\/blog\/wp-json\/wp\/v2\/media\/212"}],"wp:attachment":[{"href":"https:\/\/eventlogxp.com\/blog\/wp-json\/wp\/v2\/media?parent=202"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/eventlogxp.com\/blog\/wp-json\/wp\/v2\/categories?post=202"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/eventlogxp.com\/blog\/wp-json\/wp\/v2\/tags?post=202"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}