Alois Kraus

blog

  Home  |   Contact  |   Syndication    |   Login
  133 Posts | 8 Stories | 366 Comments | 162 Trackbacks

News



Archives

Post Categories

Programming

My ETW trace collection tool has reached a significant milestone. It becomes more and more THE tool if you want to record ETW traces while recording also user input (keyboard, mouse) along with screenshots to exactly see which actions the user did perform to get into that state. What really stands out that you can use it also as distributed trace collection tool to start ETW tracing on two machines simultaneously while sending the user input also to the remote machine and record them on the remote machine as well. That allows you to easily find distributed problems with one profiling run. Since you can navigate by the recorded user events you do not need to rely on exactly synchronized clocks between both machines.

You can see more of it at https://etwcontroler.codeplex.com/. What is best that on Windows 10 you only need to unzip ETWController v2.1 and you can already record right away because WPR (Windows Performance Recorder) is part of Windows 10. That enables interesting scenarios like sending preconfigured ETWController zips to clients which only need to

  • Unzip ETWController.zip
  • Start ETWController.exe

image

 

  • Go to Trace Collection and press Start
  • Reproduce the use case
  • Press Stop
  • Send gathered data to service

The new version also can record Screenshots for every mouse click and Enter key press. To make sense of the many collected screenshot files during trace stop a HTML report is created. It is located besides the ETL file in a directory named xxx.etl.Screenshots which contains a Report.html file. You can view it with the browser where you can configure the image size as you need it to get a quick overview.

image

For each click event a file with the name Screenshot_dd.jpg is saved where the number is the number of input events (mouse down, mouse up, keyboard down) since trace start. To check if the UI did respond after 500ms a second screenshot is taken with the name Screenshot_ddAfter500ms.jpg. Now it is much easier to find the interesting time points in an ETL file. If you record screenshots from your clients you have to make sure that you do not disclose personal data or you analyze the data on the client machine directly to ensure that no personal information is leaked.

For each click event the mouse location is marked with a red square because the mouse cursor is not part of the captured data.

image

If you record the same use case several times you need to ensure that the old data is not overwritten by accident. ETWController helps you by checking the Append Index checkbox by default. Besides the checkbox there is textbox with a number which is incremented every time profiling is stopped. If you start/stop profiling several times you will get in your directory files of the form

image

which makes it hard to accidentally overwrite data from important profiling runs. This of course works also for distributed profiling where files on both machines get the same extension appended. After saving the data you can click on Show Output button which will open the generated ETL file with WPA with my own Simplified profile which is shipped with ETWController now as well!

image

Simplified WPA Profile Included

It is located in the ETW folder under besides the ETWController executable and named Simple.wpaProfile.

image

I will continue to update the profile under source control and not on Google drive anymore. To see what you can do with the custom profile check out

image

Now you can make sense of the input events and check out how the UI did look at specific times. The Report.html gives you access to all of the screenshots to correlate user visible changes with the profiling timeline.

 

Performance Regression

Another very common use case is to find performance degradations of regression tests. For that it makes sense to get as many screenshots as possible. By default we record a screenshot every 2s. But you can enter in the Configuration dialog for the Screenshot Timer value any number down to 100ms.

image

Taking a screenshot needs about 100ms so in effect we get a screenshot every 200ms. When we execute the use case with with so many screenshots we can first visually compare the screenshots to see if the reported degradation actually exists. I have seen many reported performance degradations gathered by automated tests which did vanish when the same use case was executed manually. Automated tests normally use some easy to gather finish event which is used to calculate the measured duration of the test case. If the software changes that event might be slightly or completely off with what the user experiences. Having many screenshots is a huge bonus. The customer/tester no longer needs to tell you what he did because you see it in the screenshots anyway and you do not need to try to reproduce the issue in the lab which will often fail.

Other Tools

ETWController does not force you to drive everything via the UI. You can also use it as sophisticated keyboard and mouse input event logger with screenshot functionality. If you have your own or better tracing tooling you are free to use it.

This command line will capture mouse and keyboard events and save the screenshots to your own directory without any visible UI

ETWController.exe -hide -capturekeyboard -capturemouseclick -screenshotdir c:\temp\myownDir

For more information check out the Help - Command line options help in ETWController.

You can configure ETWController to use your own trace collection script and ETL viewer to give you the freedom to use as much or as little from ETWController as you need.

Give it a try and tell me what you think. If you miss something or something does not work drop me a note so I can fix it or I can give you a workaround.

posted on Saturday, May 28, 2016 9:52 PM