Process Monitor (or procmon) is a very powerful diagnostics tool for Windows. I remember when I first run it, a few years ago, I was overwhelmed by the number of events happening on my system each and every second. Thankfully, procmon has features to help you deal with this bulk of data, including filters, highlighters, and bookmarks. But sometimes even a filtered log is not enough to find the root cause of a problem. On such occasions, other log sources may contain the missing bits of information. We only need to correlate them with our procmon trace. And today, I would like to show you how I do that.
Application Insights is a performance monitoring service, created by Microsoft and available on Azure. It gives you space to store the performance metrics and logs of your application (1GB for free!), as well as functionalities to search and manage them. In this post I am not going to present you the whole platform – Microsoft already did it in the Azure documentation, but rather focus on an element of the log collection, named dependency calls tracking. I did some analysis on the Application Insights libraries, and decided to publish my findings, in the hope that the results might interest some of you too.
Dependency calls are requests, which your application makes to the external services (such as databases or REST services). When this telemetry type is enabled, all the dependent actions form a timeline within the scope of the parent action. Using this timeline we may easily verify whether the delay in our application is caused by an external service, or the application itself. Let’s analyze in detail how this data is collected.
The title mentions ASP.NET 4.5.x, but the encryption algorithm is exactly the same in ASP.NET 4.6.x. It won’t work however in earlier versions of ASP.NET.
Some time ago I published a post entitled “Decrypting ASP.NET identity cookies”. In that post we wrote a Python script to decrypt ASP.NET Identity cookies. You could have also learnt how the derived keys, used to encrypt those cookies, are calculated. If you are interested in details, please have a look at that article. But to summarize, the following steps are performed by ASP.NET:
- Extract the encryption and the validation key from the web.config file
- Calculate the derived keys using the SP800-108 specification, with the context and the label taken from an adequate Purpose class instance
- Validate and decrypt the cipher
The above procedure applies not only to the cookies decryption, but also to many other cryptographic operations, such as ViewState encryption, Forms Authentication, Anti-Forgery tokens creation etc. However, there is still a missing gap in the presented flow. What if the encryption and the validation keys are not explicitly set in the web.config file? Today, we will answer this question.
In today’s short post I would like to present you a new tool in my diagnostics toolkit: wtrace, and an update to procgov (or Process Governor). Let’s start with wtrace.
On Linux, when I need to check what a given process is doing, I usually use strace. I was always missing such a tool for Windows. We have procmon (which is great), but it does not run in a console, and thus can’t be used in the command line scripts, or on a Nano server. This might change soon, as in one of the latest episodes of the Defrag Tools show, Mark Russinovich shared the plan of releasing the procmon version for Nano. Till then though we don’t have much choice when it comes to real-time tracing. You may think of xperf or wpr, but those tools only record ETW events for further analysis. However, we may use the same ETW events in a realtime session, and print information they provide to the console output. This is how the idea for wtrace was born in my head. Few weeks ago Sasha Goldstein released another tool for ETW processing named etrace, which basically does something very similar and has many interesting options. I decided to publish wtrace nonetheless, as my point was to create a tool with an extremely simple interface. Wtrace is collecting only a small subset of events (FileIO, TcpIp, Process/Thread Start) from the kernel provider. It may either start a process, or trace one that is already running. At the end of the trace it also shows some statistics (unless you use the –nosummary switch). Trace session will end either when you press Ctrl+C, or when the traced process terminates. Events are printed in the console window. An example session might look as follows:
This is how the story begins. On our build server we are using a JetBrains Resharper CLT to generate a code analysis report. In one of the projects build we started getting the following exception log:
Executing the powershell script: C:\install\TFS \1.0.691\resharp.ps1 JetBrains Inspect Code 2016.1.2 Running in 64-bit mode, .NET runtime 4.0.30319.42000 under Microsoft Windows NT 6.2.9200.0 'AutoMapper' already has a dependency defined for 'Microsoft.CSharp'. --- EXCEPTION #1/2 [InvalidOperationException] Message = "'AutoMapper' already has a dependency defined for 'Microsoft.CSharp'." ExceptionPath = Root.InnerException ClassName = System.InvalidOperationException HResult = COR_E_INVALIDOPERATION=80131509 Source = NuGet.Core StackTraceString = " at NuGet.Manifest.ValidateDependencySets(IPackageMetadata metadata) at NuGet.Manifest.ReadFrom(Stream stream, IPropertyProvider propertyProvider, Boolean validateSchema) at NuGet.LocalPackage.ReadManifest(Stream manifestStream) at NuGet.OptimizedZipPackage.EnsureManifest() at NuGet.SharedPackageRepository.OpenPackage(String path) at NuGet.LocalPackageRepository.GetPackage(Func`2 openPackage, String path) at NuGet.LocalPackageRepository.<>c__DisplayClass13.<FindPackage>b__f(String path) at System.Linq.Enumerable.WhereSelectEnumerableIterator`2.MoveNext() at System.Linq.Enumerable.WhereSelectEnumerableIterator`2.MoveNext() at System.Linq.Enumerable.FirstOrDefault[TSource](IEnumerable`1 source) at NuGet.LocalPackageRepository.FindPackage(Func`2 openPackage, String packageId, SemanticVersion version) at NuGet.SharedPackageRepository.FindPackage(String packageId, SemanticVersion version) at JetBrains.ProjectModel.Packages.SharedPackageRepositoryInTemp.FindPackage(String packageId, SemanticVersion version) at NuGet.PackageRepositoryExtensions.FindPackage(IPackageRepository repository, String packageId, SemanticVersion version, IPackageConstraintProvider constraintProvider, Boolean allowPrereleaseVersions, Boolean allowUnlisted) at NuGet.PackageReferenceRepository.GetPackage(PackageReference reference) at System.Linq.Enumerable.WhereSelectEnumerableIterator`2.MoveNext() at System.Linq.Enumerable.WhereEnumerableIterator`1.MoveNext() at System.Collections.Generic.List`1..ctor(IEnumerable`1 collection) at JetBrains.ProjectModel.Packages.NuGetSolutionManager.<>c__DisplayClass7.<GetInstalledPackages>b__6() at JetBrains.Util.ILoggerEx.Catch[TValue](ILogger th?s, Func`1 F, ExceptionOrigin origin, LoggingLevel loggingLevel)
I am working on adding a support for ASP.NET performance counters into Musketeer. Compared to other .NET performance counters they have quite surprising instance names. ASP.NET developers decided that their performance counter instances will be identified by names derived from the AppDomain names (more information can be found here). This is probably due to a fact that one process may host multiple ASP.NET applications, thus one counter instance per process won’t be enough. Consequently, in order to match collected metrics with process ids we need to know which AppDomain belongs to which process. How can we do that?
When we work with binary data we often use the dt command to group the bytes into meaningful fields, eg.
0:000> dt ntdll!_PEB @$peb +0x000 InheritedAddressSpace : 0 '' +0x001 ReadImageFileExecOptions : 0 '' +0x002 BeingDebugged : 0x1 '' +0x003 BitField : 0x8 '' +0x003 ImageUsesLargePages : 0y0 +0x003 IsProtectedProcess : 0y0 +0x003 IsLegacyProcess : 0y0 +0x003 IsImageDynamicallyRelocated : 0y1 +0x003 SkipPatchingUser32Forwarders : 0y0 ...
The problem arises when the library owner does not provide type information in the symbol files. We are usually left with a manual decomposition of the bytes in a binary editor (010 Editor has a nice template system). Wouldn’t it be great if we had some template system available also in the debugger? I have some good news for you: with the latest release of WinDbg we received a very powerful feature: .natvis files. There were even two Defrag Tools episodes dedicated to this functionality: Defrag Tools #138 and Defrag Tools #139. Let’s first analyze how the .natvis files are built, to later use them in our binary data analysis.