Dynamically Creating Process Monitor Filters

Introduction

I recently had the need to automate the use of SysInternals’ Process Monitor such that no manual intervention is required to initiate the capture, with a filter, and then to process the results, in PowerShell of course. Searching around, I found that the format of a procmon configuration (.pmc) file didn’t appear to be documented anywhere and, being a binary format, could prove tricky, and time-consuming, to fully reverse engineer. Indeed, web searches showed others looking for ways to dynamically create these configuration files, which contain the filters as well as included columns, but apparently without success.

Of course, one could run it without a filter but that will make for potentially much larger trace files, which could impact free disk space and performance and would take longer to process in PowerShell. I therefore set about trying to figure out how I could add a process id (PID) filter for a specific process via a script and I present the research and relevant script parts here for the benefit of others.

Isolating the Relevant Section of the Configuration File

In order to see if it was feasible to take an existing procmon configuration file containing a PID filter and change it, I performed a binary comparison between two configuration files I had manually saved from the procmon user interface. In terms of the filter parameters they contained, they were identical except one was for a PID of 123456 and the other for a PID 567890, e.g:

procmon controlup pid filter

To perform a binary comparison, I used the built-in Windows File Compare utility fc.exe. Note that when calling this from PowerShell, you must append the .exe to the end of the command since “fc” is a built-in alias for the Format-Custom cmdlet which is not what we want to call. The results looked like this:

procmon pmc binary comparison

Which instantly gave me hope that what I was trying to accomplish was achievable since there were only nine differences and being the sad geek that I am from my 6502 hand assembly days on Commodore computers, I already knew that hex 31 is the ASCII code for the number 1, hex 32 is 2 and so on so that the first six rows of the first column were representing the PID 123456 and the second column 567890. But what about the last 3 bytes which are different? Well, 123456 in hex is 01E240 and 567890 is 08AA52 which we can see stored in those last 3 different bytes, albeit in little endian format.

If we look at the area around these differences in a hex editor (I use XVI32 which has served me well for many years), then we get some context and more information:

xvi32 pmc file

Where the selected character is the start of the “123456” PID string. However, notice that after each ASCII character there is a null (00) – this means that the characters are technically Unicode (16 bit) rather than ASCII (8 bit). This is for information only, it doesn’t cause an issue as we’ll see presently. Also, the (crudely) highlighted portion shows that there is a Unicode null terminator character (00 00) after the “6” of “123456” followed by the PID in little endian format.

So my thinking was that I could produce a template configuration file with a placeholder PID of 123456 and then replace that with the actual PID I wanted procmon to trace. One potential issue was that PIDs can be between 1 and 6 digits long and I didn’t want to risk changing the size/layout of the file since that may have broken procmon. Fortunately I found that procmon was quite happy accepting a PID with leading zeroes such as “000123” so that meant as long as I padded my PID to six digits, procmon would still work.

Dynamically Creating a Configuration File

Whilst it is easy with the procmon GUI to set the filters how you want them and also include or exclude display columns and then save this as a .pmc file, I had the added complication that this script, because it is run as a Script Based Action (SBA) by ControlUp’s Real-Time console, needed to be self-contained so had to have the .pmc configuration file embedded within the script itself.

This fortunately is easy to achieve since we can base64 encode the binary file, which converts it to text that we then just assign to a variable within the script. To base64 encode a file and place it in the clipboard so that it can be pasted into a script, run the following:

[System.Convert]::ToBase64String( [byte[]][System.IO.File]::ReadAllBytes( 'c:\temp\demo.pmc' ) | Clip.exe

and we then paste it into the value of a variable assignment in our script, remembering to place the terminating quote character at the end of what will be a very long line:

base64 encoded

At run time, we can convert this base64 encoded text back to binary data simply by running the following:

[byte[]]$filter = [System.Convert]::FromBase64String( $procmonFilter )

I initially just used XVI32 to determine at what point the “123456” string appeared in the file data and placed that offset into a variable but I found as I tweaked the filter that I had to keep using XVI32 to see what the offset was which became laborious. I therefore wrote a function which returns the offset of a Unicode string within a PowerShell byte array, or -1 if it is not found. I then ended up with the following code snippet which, using the aforementioned function, finds the offset of the “FilterRules” block in the config file (see hex view above), finds “123456” after that offset and replaces the PID with ours from the $processId variable:

posh to replace pmc pid

The in memory configuration file, contained in the $filter variable, can then be written to a .pmc file and the full path to the file specified as an argument to procmon.exe via the “/LoadConfig” option. The arguments highlighted below are the ones I used to capture a trace where I used “/RunTime” which runs the capture for a given number of seconds and then terminates procmon, and thus the trace, cleanly. You could also run it without “/RunTime” and call procmon.exe again with a “/Terminate” argument when you have finished the capture. If you just kill the procmon.exe or procmon64.exe processes then the trace file will not be closed cleanly and will not be usable.

procmon automated options

Once this has finished capturing and exited, it will leave a binary trace in the file argument given to the “/BackingFile” option so to convert this to a CSV file that PowerShell can read in using the Import-Csv cmdlet, we run procmon again thus:

procmon.exe /Quiet /AcceptEula /OpenLog `"$backingFile`" /Minimized /SaveAs `"$csvTrace`" /SaveApplyFilter /LoadConfig `"$pmcFile`"

where $backingFile is the .pml trace, $csvTrace is the csv file that we want it to produce and $pmcFile is the configuration file we constructed and wrote to disk. Notice the quoting of the variables in case they contain spaces.

Downloading Procmon

But what if procmon isn’t already on the system where the script needs to run? Technically I could’ve used the same base64 encoding technique to embed it within the script but this would tie it to a specific version of procmon and may also fall foul of the licence agreement as it could be construed as distributing procmon. Thankfully, for many years, the SysInternals tools have been individually available via live.sysinternals.com so the following will download procmon to the file specified in the $procmon variable (proxy willing):

(New-Object System.Net.WebClient).DownloadFile( 'https://live.sysinternals.com/procmon.exe' , $procmon )

However, depending on security settings, sometimes running of the downloaded executable will produce a dialogue box warning that the file may be untrusted. We can prevent that by running the following:

Unblock-File -Path $procmon

The Finished Script

Will be made available shortly in the ControlUp Script Library. In fact, it’s likely there will be a number of Script Based Actions authored that utilise this dynamic filtering method.

Whilst this technique has shown how a custom PID filter can be dynamically constructed and used, the same techniques could be used to set other filters. The only caveat is that the patterns, such as “123456”, would need to be unique as the simple mechanism presented here cannot determine the column or relation for the filter rule.

Advanced Procmon Part 1 – Filtering exclusions

Introduction

For those of us who’ve been around the IT block a few times, we can remember life before Procmon, and filemon and regmon its honourable parents, and it was much, much harder to diagnose some issues although it still can’t tell you everything, unlike say an API monitor might. Anyway, this article is hopefully going to teach a few of you some extra filtering techniques that I’ve learned over many years of troubleshooting. The problem frequently being that you can’t see the wood for the trees in that there are so many events captured that you can’t find the ones you want amongst the many thousands of irrelevant ones.

Once you have configured filters, they can be exported to file via the File menu for subsequent importing at a later date or quickly configuring on another machine. I’d also select “Drop Filtered Events” from the Events menu since this will require less storage and resources although it does what it says on the tin so you won’t be able to see any of these dropped events if you later realise that you did actually want them.

Also, I always configure procmon to use a backing file rather than let it use the default of virtual memory as I believe that is usually less impactful of system resources, particularly when traces have to be run for a long time. This is on the File menu.

Results that can (usually) be safely ignored

“BUFFER OVERFLOW”

You are almost certainly not seeing malicious code attempt a stack smashing hack; what is most likely happening is that the developer of the code that has had this result returned is trying to establish how big a buffer he (or she) needs to allocate in their code  in order to have the data returned that they require. This is because a developer doesn’t know in advance, for instance, how many registry values there will be in a key that he needs to enumerate so he’ll call the enumerate API with a zero length buffer which the API will interpret as a request to return the size of buffer needed to hold all of the data. The developer can then dynamically allocate a buffer of this size (and free it later when he’s finished with the data otherwise a memory leak will ensue) and then call the same API again with this buffer. You will usually see a procmon entry with all the same entries very soon after the “buffer overflow” one with a result of “success”. Many Microsoft APIs function this way.

buffer overflow

“NO MORE ENTRIES”

These will happen when APIs have been used that enumerate entries, such as the keys or values within a specific registry key. It is the API signalling to the developer that he should stop enumerating the item as there is no more data to be had.

In the example below we see that the Receiver process has been enumerating the per user installed products and after the fourth key (indexes start at zero not one) there are no more keys so the RegEnumKey API signals this by returning “no more entries”.

no more entries

Operations that can be ignored

Close

Unless you are troubleshooting a handle leak or a failed access because an operation on a file or registry key fails since the handle has been closed, which is fairly pointless unless you have source code access for the suspect code and I find Process Explorer better for diagnosing handle leaks anyway since it will give you a list of the handles, then close operations can generally be ignored. We therefore can add the following to our filters:

procmon filter

There are probably more depending on exactly what it is you are trying to diagnose but these are the ones I typically start with to try and reduce the number of entries in a trace to make it easier to find what you are looking for. Remember also that you can right click on any item in a trace and select to exclude it which I do when I see an item appearing frequently in a trace that I reckon is nothing to do with what I am troubleshooting:

dynamic exclude 2

I tend to do this with writes to log files although sometimes it can be very useful to tie in a specific log file entry to other procmon activity – see here for a utility I wrote to quickly show you the text in a file at a given offset that you get from procmon.

Once you’ve found what you are looking for, or at least say the start of the area where the event of interest occurs, you can exclude all events before this point by right clicking on a specific line and selecting “Exclude Events Before” from the menu. This can make a large procmon trace quicker to search and filter further.

Processes that can be ignored

Unless investigating something that may be caused by your anti-virus product, I exclude all of it’s processes. Same for other file system filter or hook based products that your gut tells you aren’t relevant, such as the AMAgent.exe process which is part of AppSense’s Application Manager product.

Although the “System” process is ignored by default, I will sometimes unignore it if say I’m troubleshooting a service start issue at boot (where using the “Enable Boot Logging” option from the “Options” menu is handy and also for logon problems on desktop operating systems like Windows 7).

… and don’t forget that Ctrl-L is the shortcut to the filter dialog – use it and it will save you time if you are frequently tweaking filters as I tend to do.

Part 2 will cover filter includes for specific use cases such as trying to find where a particular application setting is stored in the file system or registry.

Displaying text from a (log) file at a specific offset

When analysing product behaviour here at AppSense we often run SysInternals Process Monitor (procmon) to understand what is going on behind the scenes. In the procmon trace, we will see our log files being written to but all that is shown in the trace is the offset into the file that the data is written to and how much is written which, on the whole, is not that useful. What we sometimes need to know is exactly what text is written to the log file at this point as it will help us to correlate what procmon tells us with what our product’s log file tells us.

In order to be able to perform the correlation, I wrote a utility, called FindFileEntry.exe, which takes an offset (-o), a length (-l) and text log file name (-f) and will output the line number of the file and the text (up to “length” characters) . It will work with both Unicode and ANSI/ASCII text files.

For instance, if we consider the following, somewhat contrived, snippet of a procmon trace:

procmon of log file

We can see that the AppSense Application Manager Agent process (AMAgent.exe) has written 88 bytes to the log file “C:\Temp\amlogs\demo\Application Manager_AGENT_06_11_2013_21_52_28.log” at an offset of 22,252,941 bytes. We therefore run the following options with the FindFileEntry utility:

c:\>FindFileEntry.exe -f "c:\temp\amlogs\demo\Application Manager_AGENT_06_11_2013_21_52_28.log" 
-o 22252941 -l 88

And it outputs the following where the number immediately before the first colon character is the line number within the file

206504:     T031268 693093390 21:54:21.502 [AMPipeServer::Run] Event signalled. waitValue = 22

Given that we now have the line number as well as the text written, we can open the log file in a text editor such as Notepad++ so that we can see what other lines of (useful) debugging information were written around that same period.

notepad++ showing log line

The utility will work for any text log file, not just AppSense’s, and can be downloaded from here. Please refer to the README within the download for more details.

PS. Wouldn’t it be nice if procmon had some kind of customisable capability to allow an event to be right clicked on, or similar, and an arbitrary program be selected to run, with parameters such as parts of the procmon trace line, e.g. to launch the FindFileEntry program seamlessly?