Sysinternals procmon sometimes ignores the Drop Filtered Events checkbox

[randomascii]

Item	Value
OS, Version / Build	10.0.19041.0 Microsoft Windows NT 10.0.19041.0
Processor Architecture	AMD64
Processor Type & Model	Intel(R) Core(TM) i7-7700HQ CPU @ 2.80GHz, 3192 Mhz, 4 Core(s), 8 Logical Processor(s)
Memory	128GB
Storage Type, free / capacity (e.g. C: SSD 128GB / 512GB)	SSD 2TB
Relevant apps installed	Process Monitor

Description

While trying to track down the cause of a file being created by Chromium's browser_tests my coworker left procmon running with an aggressive filter (so aggressive that no events were shown) and with Drop Filtered Events checked. Despite the request to drop all events the working set for procmon gradually increased to hundreds of GB. I was able to reproduce this on some other machines, but not all. On one machine upgrading fixed the problem, but on other machines it did not. On some machines the new version (3.52) failed, and on some machines the old version (3.52) worked. I first mentioned this issue here:

https://twitter.com/BruceDawson0xB/status/1296156206839418880

This issue made procmon unusable for my coworker for this scenario. Luckily it worked on one of my machines so I was able to gather the necessary data for them.

Steps to reproduce

The bug is inconsistent. The feature works sometimes and fails other times. It is not obvious that the feature is failing unless you know what to look for. If you realize that the event counts are not supposed to go up when all events are dropped then the bug is obvious. Otherwise you have to notice that the memory footprint is increasing without bounds.

Expected behavior

Filtered events should be dropped when that is requested, thus reducing CPU and memory load.

Actual behavior

Filtered events are not reliably dropped when requested, for unknown reasons.

If necessary I can do some debugging on the machine that currently exhibits the problem.

[riverar]

@randomascii Thanks for reporting this. This is definitely one of those small nits I deal with nearly every day!

[randomascii]

It would be good just to know where the procmon settings are stored, since then I could spelunk into them and/or reset them by deleting the registry keys.

It is odd that it works on some machines and not others, and that on one machine the upgrade to 3.53 fixed the issue.

[bitcrazed]

Assigning to Alex who will investigate in the couple few weeks, once he's cleared is current high-pri backlog.

[randomascii]

I hit this again while tracing a build of Chrome. All events except for 200 were filtered out and the "drop events" setting was set, but events were clearly not dropped. The procmon working set went to 99 GB and I hit lots of OOM failures.

Any guidance as to where the settings are so that I can clear them, since that seems to help?

[riverar]

@randomascii HKEY_CURRENT_USER\SOFTWARE\Sysinternals\Process Monitor particularly DestructiveFilter dword

[randomascii]

Thanks! I deleted most of the settings (I just kept DbgHelpPath and SymbolPath because I am lazy and didn't want to reconfigure) and then started it and reconfigured my filtered capture with most events dropped. It claimed that it was displaying ~20 items out of 128,000 (the 128,000 from before I applied the filter) but the commit size went up to ~15 GB (and there were two procmon64.exe processes).

I then stopped capturing and cleared the capture but it is taking many minutes for the commit charge to come down. It's dropping by a few MB per second and I don't want to wait an hour.

I quit and then relaunched it (DestructiveFilter gets written to the registry on exit) and it briefly seemed to be working. WS/commit was holding steady at 1.7 GB/7 GB for a while.

However after a couple of minutes I have a second Procmon64.exe process (maybe it was always there?) and it's WS and commit are growing without bounds. It's at 10 GB/10 GB now and still going up.

So, I can reproduce the bug 100% of the time. Procmon thinks it has captured zero events and the main Procmon process uses a reasonable (large, but reasonable) amount of WS and commit, but the other Procmon process grows without bounds. Resetting everything doesn't help. I don't understand the multi-proc behavior so I can't reason about it.

I guess I'll need to find other ways to monitor my builds.

[zodiacon]

@randomascii, I would like to repro this. Can you share details of your filters? You don't have to be too specific - just the filter type (process name, etc.) and relationship (is, greater than, etc.)

[riverar]

@zodiacon Here's one way:

1. Open Process Monitor
2. In the Process Monitor Filter window, add a filter for contains abcdefghij
3. Click Filter > Drop Filtered Events if not already checked
4. Click the Clear button to clear all events (the status bar will indicate this via "No events")
5. Click Filter > Enable Advanced Output to toggle its value (not important if it's on or off)
6. Observe events are unexpectedly streaming through Process Monitor

[zodiacon]

Excellent, thank you! On it.

[riverar]

Just a warning: I suspect there are multiple bug entrypoints here; I believe I've also seen this without touching the Enable Advanced Output feature. That will be harder to reproduce, of course.

[zodiacon]

Found the bug :)

[randomascii]

Found the bug :)

That's great!

I look forward to a fixed version as this will unblock some important scenarios. It's not really important but are there any interesting details you can share about the cause? I'm just curious.

[zodiacon]

Not worth sharing :)

[riverar]

So, Procmon 3.70 was released today but this behavior still seems to be present. And the feature doesn't seem to work anymore.

Video: Clicking Filter > Drop Filtered Events doesn't stop the event flow anymore

https://user-images.githubusercontent.com/475132/115627556-15e3dd80-a2b4-11eb-8d53-b637c2a3a19c.mp4

Video: Removing a filter does show events that should have been dropped

https://user-images.githubusercontent.com/475132/115627562-17ada100-a2b4-11eb-9f85-ba92b5c3afd1.mp4

[zodiacon]

Does your filter include "Result" column conditions? Try disabling them. The issue might be the fact that when the event comes in, the result is not yet known, so it has to go through. Only later it can be determined whether that was supposed to be dropped, but that is too late - we don't go back to drop the event. (at least not at this time)

[riverar]

@zodiacon Nope. Just the default inbox filters.

[zodiacon]

@riverar the default inbox filters do include at least one result column item.

[riverar]

@zodiacon Ah missed that, thanks. Working as expected now. Might help to add a warning in status bar to that effect, or something!

[zodiacon]

Agreed!

[AdamBraden]

Closing as this appears to have been fixed.