Tracing Thinktecture.IdentityModel.Hawk through Event Tracing for Windows (ETW)

Thinktecture.IdentityModel.Hawk version 2.1.0 now uses ETW infrastructure to raise events. One of the challenges with Hawk authentication is that it uses different parts of the message to compute MAC and when authentication fails, it is generally difficult to figure out what went wrong. Both client and server must use the exact same values in the MAC computation process, for the MAC computed by the server to match the MAC computed by the client. If there is even a slight mismatch such as an additional space or difference in capitalization, etc authentication fails and 401 is the end result. A secure system does not give out much in terms of what went wrong but then, for a developer, it is a real problem to figure out what is wrong. To help solve this problem, tt.idm Hawk now raises ETW events.

ETW is super-performant and the code raising events can be left as-is even in production. This means, ETW tracing will help not only in development but also in production to find out what went wrong. Hawk core is instrumented with ETW and since core is used by both client side and server side, events will be raised by both the client app and Web API.

To see tracing in action, you just need to take the existing sample code from here and get it running after updating the Thinktecture.IdentityModel.Hawk NuGet package. Once the new NuGet package is used, ETW events will be raised by tt.idm Hawk.

In order to capture the events raised, the best tool is PerfView. You can download it from here. The download is just a zip file containing the executable and no installation is required. You can just run the exe directly.

Launch PerfView and go to Collect > Collect menu and enter the details as shown below.

PerfView Collect Menu

Make sure to enter *Thinktecture-IdentityModel-Hawk-Etw-HawkEventSource in the Additional Providers text box, including the leading * and clear out the check boxes above. Then, hit the Start Collection button. With that, PerfView starts to listen for ETW events raised by tt.idm Hawk. With PerfView running, run the sample server and the client apps. Once the response comes through for all the requests, close the apps and press the Stop Collection button.

Now, good things come to those who wait. PerfView takes some time here and finally when it is ready, go to the folder you specified in the collect dialog box, in the left side tree and open (or whatever the name of the file you specified). Double click Events tree node and that will open another window. Select the Event Types starting with “Thinktecture-IdentityModel-Hawk” (there will be four of them and you can leave out the one ending with “ManifestData”) and press Enter. The events corresponding to these three types will be shown in the right pane. The events here will have all the data you will ever need to figure out what is going on under the hood of Hawk.

PerfView Events

As an example, the second row you see is made by the client app, as indicated by the process name of Hawk.Samples.Client.ConsoleApp.vshost. It shows the normalized request message that is used to compute HMAC. The eighth row is made by the server app Hawk.Samples.WebApi.OwinHost.vshost and it shows the same normalized request message as seen by Web API. If you see different values, authentication will obviously fail. In addition to logging the normalized formats, there are additional information as well which will help you debug and determine what went wrong.

If you run Web API and the client app in different machines, make sure to run PerfView in both the boxes and start collection in both instances before issuing a request.

BTW, PerfView is not the only tool that can be used. You can use any ETW controller such as logman, for which you will use the following command.

logman create trace HawkTrace -o Hawk.etl -p "{40758166-efd2-517f-25a8-6f5092360d65}"

Unlike PerfView, logman requires manifest to be installed in a machine before you can use it. For generating the manifest and installing it, refer to my blog entry Event Tracing for Windows (ETW), ETL file and Tracerpt. You will need to use eventregister.exe to generate manifest and wevtutil.exe to install the same.

Hope you find the ETW-based tracing useful.


Leave a Reply

Fill in your details below or click an icon to log in: Logo

You are commenting using your account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s