AdguardForWindows icon indicating copy to clipboard operation
AdguardForWindows copied to clipboard
verified publisher icon AdguardTeam

AdGuard keeps modifying locally saved filter file randomly even though there's no changes made in Filter Editor

Open mahara opened this issue 2 years ago • 10 comments

AdGuard version

7.15.1

Browser version

Chrome 119

OS version

Windows 11, 22H2

What filters do you have enabled?

A filter file saved in local drive.

What Stealth Mode options do you have enabled?

Strip URLs of tracking parameters, Protect from DPI

Support ticket ID

No response

Issue Details

Steps to reproduce:

  1. Create a local filter saved locally in local drive.
  2. Add invalid expiration time metadata in the filter, e.g.: ! Expires: 1 days (update frequency), ! Expires: 1 hours (update frequency), etc.
  3. Add some valid rules in the filter, e.g.: rules for removing tracking parameters from URLs.
  4. Add the filter as Trusted Filter using Import Filter by browsing and selecting the local filter file created.
  5. Observe the file modification time keeps changing randomly from time to time, even though there's no related change made in the Filter Editor. And because AdGuard would randomly modify the filter file, restart Windows (and/or re-login) to force triggering the issue.
  6. Also observe that this issue would trigger AdGuard VPN disconnection and reconnection issue (https://github.com/AdguardTeam/AdGuardVPNForWindows/issues/552).

Actual Behavior

AdGuard keeps modifying the filter file RANDOMLY even though there's no related changes made in Filter Editor.

Expected Behavior

AdGuard should ONLY modify the locally saved filter file when there's any changes made in Filter Editor.

Screenshots

No response

Additional Information

This issue seems to trigger a disconnection and reconnection issue in AdGuard VPN (https://github.com/AdguardTeam/AdGuardVPNForWindows/issues/552).

mahara avatar Nov 15 '23 14:11 mahara

Hi @mahara

Unfortunately, we have not been able to reproduce the problem. To diagnose it, we need to get the application logs. Here's what we need you to do:

  1. Collect the debug log as it's explained here.
  2. Remember the exact time when the issue was reproduced. We will need it to find the corresponding records in the log file.
  3. Send the archive to [email protected] and mention this issue number in the subject.

Also, if possible, please provide us with the custom filter you are using. You can send it along with the application log files.

AlexandrPkhm avatar Nov 16 '23 11:11 AlexandrPkhm

The culprit lies in invalid unit of expiration time defined in the filter metadata. I attached sample filters to demonstrate the issue.

In the bad filters, expiration time set as ! Expires: 1 days (update frequency) (instead of 1 day, which I accidentally did and triggered this issue) and ! Expires: 1 hours (update frequency) (instead of 1 hour). And the good filters obviously won't trigger the issue.

I'll update the repro steps with these additional details.

AdGuard URL Tracking Filter - Test.zip

mahara avatar Nov 17 '23 15:11 mahara

Hi @mahara

Unfortunately, we are still unable to reproduce the issue. Could you please record the video of the issue for us?

AlexandrPkhm avatar Nov 28 '23 17:11 AlexandrPkhm

@AlexandrPkhm I've managed to reproduce the issue by relog in; first attempt by restarting Windows didn't seem to trigger the issue. I've sent the log details to [email protected]. Time of occurrence was on 2023 November 29 at 10:51:41 (GMT+7).

Here's an interesting excerpt from the service log "service_2023-11-29-10_47_50.224.log":

INFO, AdguardSvc.exe, Logger, 5, 29.11.2023 10:51:29.677, Try to remove previous downloading directories.
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.074, Handling subscription file change at: D:\TEMP\TEMP\AdGuard URL Tracking Filter - Test - #21 Bad.txt
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.074, Getting all filters
VERBOSE, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.091, Start getting filter subscription meta from path: D:\TEMP\TEMP\AdGuard URL Tracking Filter - Test - #21 Bad.txt
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.091, Getting all filters
VERBOSE, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.105, The subscription with the same subscribe url found. Getting its meta
VERBOSE, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.108, Start installing filter subscription from meta: Name=AdGuard URL Tracking Filter Description=Filter that enhances privacy by removing tracking parameters from URLs. Version=1.0.0.0SubscriptionUrl=D:\TEMP\TEMP\AdGuard URL Tracking Filter - Test - #21 Bad.txt
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.108, Getting all filters
VERBOSE, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.122, Invalid url: http://D:\TEMP\TEMP\AdGuard URL Tracking Filter - Test - #21 Bad.txt
INFO, AdguardSvc.exe, wcEqSNE9msXXYunx75X, 60, 29.11.2023 10:51:41.123, Start compiling filter from file:\\\D:\TEMP\TEMP\AdGuard URL Tracking Filter - Test - #21 Bad.txt
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.123, Downloading data from the file:\\\D:\TEMP\TEMP\AdGuard URL Tracking Filter - Test - #21 Bad.txt
VERBOSE, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.123, Invalid url: http://file:\\\D:\TEMP\TEMP\AdGuard URL Tracking Filter - Test - #21 Bad.txt
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.123, Downloading data (total 1132 bytes) successfully completed from the file:\\\D:\TEMP\TEMP\AdGuard URL Tracking Filter - Test - #21 Bad.txt
INFO, AdguardSvc.exe, wcEqSNE9msXXYunx75X, 60, 29.11.2023 10:51:41.123, Compiling filter has been completed successfully
VERBOSE, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.133, OnConfigurationChanged, in particular - Updated for FilterSubscription
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.134, Start getting filter subscription rules for filter 100002
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.135, Getting filter subscription rules for filter 100002 completed
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.136, Start saving filter subscription rules for filter 100002
VERBOSE, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.143, OnConfigurationChanged, in particular - Updated for FilterSubscriptionRules
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.143, Saving filter subscription rules for filter 100002 completed
VERBOSE, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.143, Subscription with the same subscribe url found. Updating status
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.143, Subscription file change handled successfully
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.144, Removing watcher for subscription: AdGuard URL Tracking Filter - Test - #21 Bad.txt
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.145, Watcher removed successfully
VERBOSE, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.146, Invalid url: http://D:\TEMP\TEMP\AdGuard URL Tracking Filter - Test - #21 Bad.txt
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.146, Registering file watcher for subscription file D:\TEMP\TEMP\AdGuard URL Tracking Filter - Test - #21 Bad.txt
INFO, AdguardSvc.exe, Logger, 60, 29.11.2023 10:51:41.146, File watcher was successfully registered for D:\TEMP\TEMP\AdGuard URL Tracking Filter - Test - #21 Bad.txt
INFO, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.669, FilterSubscriptionStateService.GetInstalledFilterSubscriptions: Start
INFO, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.669, Getting all filters
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.685, GetInstalledFilterSubscriptions: isEnabled - 
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.685, GetInstalledFilterSubscriptions: Add filter id 102
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.685, GetInstalledFilterSubscriptions: Add filter id 120
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.685, GetInstalledFilterSubscriptions: Add filter id 227
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.685, GetInstalledFilterSubscriptions: Add filter id 253
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.685, GetInstalledFilterSubscriptions: Add filter id 14
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.685, GetInstalledFilterSubscriptions: Add filter id 15
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.685, GetInstalledFilterSubscriptions: Add filter id 16
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.685, GetInstalledFilterSubscriptions: Add filter id 17
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.685, GetInstalledFilterSubscriptions: Add filter id 18
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.685, GetInstalledFilterSubscriptions: Add filter id 19
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.685, GetInstalledFilterSubscriptions: Add filter id 1
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 20
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 21
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 22
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 2
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 3
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 4
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 6
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 7
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 9
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 0
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 200000
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 100000
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 100001
VERBOSE, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, GetInstalledFilterSubscriptions: Add filter id 100002
INFO, AdguardSvc.exe, Logger, 58, 29.11.2023 10:51:41.687, FilterSubscriptionStateService.GetInstalledFilterSubscriptions: Stop

mahara avatar Nov 29 '23 04:11 mahara

@mahara

Could you please check if the issue is reproducible on the latest released AdGuard for Windows beta? It is available via the following link.

AlexandrPkhm avatar Dec 04 '23 16:12 AlexandrPkhm

@AlexandrPkhm The file modification issue is still occurring in latest beta version, although it doesn't seem to trigger the AdGuard VPN reconnection issue (AdguardTeam/AdGuardVPNForWindows#552) anymore, which is really good.

It seems stable enough (at least for now) regarding the AdGuard VPN connection. I haven't noticed any VPN reconnection issue, that happened in 7.15, triggered by filter related actions (adding new filters, updating existing filters, or even by action triggered by AdGuard itself (this issue)).

As for this issue itself, I don't really understand how AdGuard actually works, but it seems the following line from the service log that triggers it:

INFO, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:22.879, Handling subscription file change at: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt

as a respond for file watcher registered on the filter file earlier here:

INFO, AdguardSvc.exe, Logger, 4, 07.12.2023 16:41:39.338, Registering file watcher for subscription file C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt
INFO, AdguardSvc.exe, Logger, 4, 07.12.2023 16:41:39.338, File watcher was successfully registered for C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt

It then triggers the saving filter file action which it seems actually modifies the filter file:

VERBOSE, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.325, OnConfigurationChanged, in particular - Updated for FilterSubscription
INFO, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.325, Start getting filter subscription rules for filter 100002
INFO, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.326, Getting filter subscription rules for filter 100002 completed
INFO, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.327, Start saving filter subscription rules for filter 100002
VERBOSE, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.335, OnConfigurationChanged, in particular - Updated for FilterSubscriptionRules
INFO, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.335, Saving filter subscription rules for filter 100002 completed
VERBOSE, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.335, Subscription with the same subscribe url found. Updating status
INFO, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.335, Subscription file change handled successfully
INFO, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.337, Removing watcher for subscription: AdGuard URL Tracking Filter - Test - #111 Good.txt
INFO, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.337, Watcher removed successfully
VERBOSE, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.339, Invalid url: http://C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt
INFO, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.339, Registering file watcher for subscription file C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt
INFO, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:24.339, File watcher was successfully registered for C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt
What I still don't understand is WHO and/or WHAT PROCESS that actually trigger the filter file change in the first place. It just happened immediately after I sign in after signing out just before.

INFO, AdguardSvc.exe, Logger, 67, 07.12.2023 16:44:22.879, Handling subscription file change at: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt

Also, it doesn't seem related to the validity of filter metadata. Both valid and invalid filter metadata seem just to trigger this issue.

I will send the logs to support email.

mahara avatar Dec 07 '23 10:12 mahara

@mahara, Hi! I'm working on this problem, but unfortunately I couldn't reproduce the problem. We determine whether the file is being modified using the standard class in .NET, as you noticed, the File watcher was successfully register log indicates that we are monitoring the file, but no additional changes are applied to this file. Also, the Handling subscription file change at log indicates that the file was changed from outside the program, that is these changes were not made by Adguard. I also suggest putting the last nightly

Danila-Arg avatar Dec 12 '23 13:12 Danila-Arg

@Danila-Arg What's really bugging me is what I said previously: "I still don't understand is WHO and/or WHAT PROCESS that actually triggered the filter file change in the first place. It just happened immediately after I sign in after signing out just before."

TLDR: Conclusion (based on my analysis below)

  1. The FileSystemWatcher seems sending false positive notification about a filter file content change. It's being triggered, but there's no actual modification made in the file content itself, nor logged by Windows Audit in Event Viewer. This can be also checked using by file hash/file checksum.
  2. Using file change notification triggered by FileSystemWatcher itself only doesn't seem to provide a robust and reliable way to determine whether a filter file content is actually changed or not. This is including relying on some certain file attributes (e.g.: file last modification time, etc.), which can be easily changed using other app/tool; I used BulkFileChanger by NirSoft (https://www.nirsoft.net/utils/bulk_file_changer.html) in this case to set the file modification time to "2023-08-01T00:00:00 (GMT+7)"; this way I can easily and quickly observe if the file was modified or not.
  3. File hash/file checksum should be used instead to determine actual filter file content change, not just by relying on FileSystemWatcher file change notification and/or its file attributes' changes. A file hash of a filter file can be calculated and stored internally when adding a filter file, and then rechecked upon, in this case, file change notification triggered by FileSystemWatcher.
  4. If my analysis is correct, it would be very interesting to see something like this in AdGuard service log:
INFO, AdguardSvc.exe, Logger, 26, [TIME], File change notification triggered at: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt
INFO, AdguardSvc.exe, Logger, 26, [TIME], No file content change detected at: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt (SHA-256: 6DB3C19BB57C38BAF1FDE6A1B6160B5AFE1EEA13850FA8DF6091CE8390BC04CC)
INFO, AdguardSvc.exe, Logger, 26, [TIME], File change notification dismissed for: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt

Analysis

  1. FileSystemWatcher doesn't provide information about WHO and/or WHAT PROCESS that is actually triggering the changes. Nor even the underlying Win32 APIs it uses, I read. CMIIW.

  2. I found that the only way to figure out what process that has modified a file is by using Windows Audit (https://www.lepide.com/how-to/track-who-read-files-on-your-windows-file-servers.html). After doing the audit, I can't find any process modifying the file logged by Windows Audit in Event Viewer between FileSystemWatcher being registered and filter file change notification triggered by FileSystemWatcher.

FileSystemWatcher registered after Windows restart, before I signed out and signed in again.

INFO, AdguardSvc.exe, Logger, 4, 13.12.2023 6:29:12.672, Registering file watcher for subscription file C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt
...
INFO, AdguardSvc.exe, Logger, 4, 13.12.2023 6:29:12.682, File watcher was successfully registered for C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt

File change notification triggered. after I signed in back.

INFO, AdguardSvc.exe, Logger, 26, 13.12.2023 6:31:00.016, Handling subscription file change at: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt
  1. The only process that modified the filter file logged by Windows Audit in Event Viewer is AdGuard (C:\Program Files\AdGuard\AdguardSvc.exe). And it happened just after the filter file change notification triggered and it was modified by AdGuard. The time the filter file was modified (roughly) matched the time the audit event was logged in Event Viewer: 13.12.2023 6:31:00.091 (GMT+7) and 2023-12-12T23:31:00.0953161Z (UTC) respectively.

Filter file modified by AdGuard.

INFO, AdguardSvc.exe, Logger, 26, 13.12.2023 6:31:00.080, Getting filter subscription rules for filter 100002 completed
INFO, AdguardSvc.exe, Logger, 26, 13.12.2023 6:31:00.081, Start saving filter subscription rules for filter 100002
VERBOSE, AdguardSvc.exe, Logger, 26, 13.12.2023 6:31:00.091, OnConfigurationChanged, in particular - Updated for FilterSubscriptionRules
INFO, AdguardSvc.exe, Logger, 26, 13.12.2023 6:31:00.091, Saving filter subscription rules for filter 100002 completed
VERBOSE, AdguardSvc.exe, Logger, 26, 13.12.2023 6:31:00.091, Subscription with the same subscribe url found. Updating status
INFO, AdguardSvc.exe, Logger, 26, 13.12.2023 6:31:00.091, Subscription file change handled successfully

Audit event on the filter file logged in Event Viewer

    <TimeCreated SystemTime="2023-12-12T23:31:00.0953161Z" />

----

A handle to an object was requested.

Subject:
	Security ID:		SYSTEM
	Account Name:		[COMPUTER_NAME]$
	Account Domain:		[DOMAIN_NAME]
	Logon ID:		0x3E7

Object:
	Object Server:		Security
	Object Type:		File
	Object Name:		C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt
	Handle ID:		0x9ac
	Resource Attributes:	-

Process Information:
	Process ID:		0x2514
	Process Name:		C:\Program Files\AdGuard\AdguardSvc.exe

Access Request Information:
	Transaction ID:		{00000000-0000-0000-0000-000000000000}
	Accesses:		READ_CONTROL
				SYNCHRONIZE
				WriteData (or AddFile)
				AppendData (or AddSubdirectory or CreatePipeInstance)
				WriteEA
				ReadAttributes
				WriteAttributes

	Access Reasons:		READ_CONTROL:	Granted by	D:(A;ID;FA;;;BA)
				SYNCHRONIZE:	Granted by	D:(A;ID;FA;;;BA)
				WriteData (or AddFile):	Granted by	D:(A;ID;FA;;;BA)
				AppendData (or AddSubdirectory or CreatePipeInstance):	Granted by	D:(A;ID;FA;;;BA)
				WriteEA:	Granted by	D:(A;ID;FA;;;BA)
				ReadAttributes:	Granted by	D:(A;ID;FA;;;BA)
				WriteAttributes:	Granted by	D:(A;ID;FA;;;BA)

	Access Mask:		0x120196
	Privileges Used for Access Check:	-
	Restricted SID Count:	0

  <TimeCreated SystemTime="2023-12-12T23:31:00.0953197Z" />

----

An attempt was made to access an object.

Subject:
	Security ID:		SYSTEM
	Account Name:		[COMPUTER_NAME]$
	Account Domain:		[DOMAIN_NAME]
	Logon ID:		0x3E7

Object:
	Object Server:		Security
	Object Type:		File
	Object Name:		C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt
	Handle ID:		0x9ac
	Resource Attributes:	S:AI

Process Information:
	Process ID:		0x2514
	Process Name:		C:\Program Files\AdGuard\AdguardSvc.exe

Access Request Information:
	Accesses:		WriteAttributes

	Access Mask:		0x100
  1. There's no actual file content change in filter file itself before the filter file change notification (or even before the filter file added to AdGuard) and after it's modified by AdGuard. I verified it by checking its file hash/file checksum. This seems like a false positive file change notification triggered by FileSystemWatcher.

File hash/file checksum before and after AdGuard modified the filter file

AdGuard URL Tracking Filter - Test - #111 Good.txt
SHA-256: 6DB3C19BB57C38BAF1FDE6A1B6160B5AFE1EEA13850FA8DF6091CE8390BC04CC

mahara avatar Dec 13 '23 11:12 mahara

@mahara Hi! Thanks for the investigation, I found the problem, yes FileSystemWatcher does not work correctly and the event causes even when there was no change, it was possible to fix this problem, in the next nightly it will be fixed

Danila-Arg avatar Dec 13 '23 18:12 Danila-Arg

@Danila-Arg OK, that's great to hear!

And yes, I can confirm this issue as well after playing around FileSystemWatcher as Windows Service using latest .NET 8.0.

I'm not sure it's by design, a bug, or a feature, but I find it's weirder that I can't find any references to this issue in Google/SO/GitHub before (or perhaps I simply missed it).

And it behaves exactly as I expected, even every time I restart WIndows...

[2023-12-15 07:28:07.0101 | INFO | Microsoft.Hosting.Lifetime] -> Application started. Hosting environment: Production; Content root path: C:\Program Files\mahara\FileWatcherService\
[2023-12-15 07:28:34.9229 | INFO | FileWatcherService.FileWatcherBackgroundService] -> File change notification triggered at: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt (Changed)
[2023-12-15 07:28:34.9229 | INFO | FileWatcherService.FileWatcherBackgroundService] -> No file content change detected at: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt (XxHash3: 23F6EB372841D0C6)
[2023-12-15 07:28:34.9229 | INFO | FileWatcherService.FileWatcherBackgroundService] -> File change notification dismissed for: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt
[2023-12-15 07:29:09.0049 | INFO | Microsoft.Hosting.Lifetime] -> Application is shutting down...
[2023-12-15 07:29:51.0375 | INFO | Microsoft.Hosting.Lifetime] -> Application started. Hosting environment: Production; Content root path: C:\Program Files\mahara\FileWatcherService\
[2023-12-15 07:30:29.2422 | INFO | FileWatcherService.FileWatcherBackgroundService] -> File change notification triggered at: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt (Changed)
[2023-12-15 07:30:29.2422 | INFO | FileWatcherService.FileWatcherBackgroundService] -> No file content change detected at: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt (XxHash3: 23F6EB372841D0C6)
[2023-12-15 07:30:29.2422 | INFO | FileWatcherService.FileWatcherBackgroundService] -> File change notification dismissed for: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt
[2023-12-15 07:31:05.0329 | INFO | Microsoft.Hosting.Lifetime] -> Application is shutting down...
[2023-12-15 07:31:47.0980 | INFO | Microsoft.Hosting.Lifetime] -> Application started. Hosting environment: Production; Content root path: C:\Program Files\mahara\FileWatcherService\
[2023-12-15 07:32:46.7366 | INFO | FileWatcherService.FileWatcherBackgroundService] -> File change notification triggered at: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt (Changed)
[2023-12-15 07:32:46.7366 | INFO | FileWatcherService.FileWatcherBackgroundService] -> No file content change detected at: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt (XxHash3: 23F6EB372841D0C6)
[2023-12-15 07:32:46.7366 | INFO | FileWatcherService.FileWatcherBackgroundService] -> File change notification dismissed for: C:\TEMP\TEMP\AdGuard\AdGuard URL Tracking Filter - Test - #111 Good.txt

mahara avatar Dec 15 '23 00:12 mahara