FileSystemWatcher works reliably, unless I write to a log file

Question

I am using a fileSystemWatcher to watch for a xlsx to be saved. This is registered as a renamed event, on which I want to execute a python script. I then want to save this action to a log file created for the current session of the watcher.

### Set local variables and and wrap important ones to send to action
$watch_path = Split-Path -parent $pwd
$watch_file = "test.xlsx"
$script_file = "test.py"
$log_file = "$pwd" + "\log\watcher_$(get-date -f yyyyMMdd-HHmmss).log"
$passed_vars = @{watch_path = $watch_path; watch_file = $watch_file; script_file = $script_file; log_file = $log_file}
 
### SET FOLDER TO WATCH + FILES TO WATCH + SUBFOLDERS YES/NO
$Global:watcher = New-Object System.IO.FileSystemWatcher
$Global:watcher.Path = $watch_path
$Global:watcher.EnableRaisingEvents = $true
$Global:watcher.Filter = $watch_file
$Global:watcher.InternalBufferSize = 65536
### DEFINE ACTION TO RUN SCRIPT AFTER A SAVE IS DETECTED
$action = {
 $old_name = Split-Path -leaf $event.SourceEventArgs.OldFullPath
 $path = Split-Path -parent $event.SourceEventArgs.FullPath
 $name = $event.SourceEventArgs.Name
 $changetype = $event.SourceEventArgs.ChangeType
 $log_line = "File '$old_name' at path '$path' was $changetype to '$name' at $(Get-Date)"
 
 ### Avoids double firing the event
 if ( $name -eq $Event.MessageData.watch_file) {
 python $event.MessageData.script_file
 $log_line = $log_line + "`nScript '$($event.MessageData.script_file)' in working directory '$pwd' was ran at time $(Get-Date)"
 
 }
 Write-Host $log_line
 #Write-Host "Wrote line: $log_line `nto file: $($event.MessageData.log_file) `nat time: $(get-date)"
 ### SAVES EVENT AND ACTION TO LOG FILE, PROBLEM LINES.
 #Add-content $log_file -value $log_line
 #Add-content ($EventArgs | format-list * | out-string)
 
 }
### LINK EVENT ACTION TO WATCHER
$rename_event = Register-ObjectEvent $Global:watcher "Renamed" -Action $action -SourceIdentifier "rename_action" -messagedata $passed_vars
### CREATE NEW LOG FILE; LOG WATCHER CREATION AND PROPERTIES
$log = New-Item $log_file -ItemType File -Force
$log_line = "Started to monitor $watch_file at $watch_path from $(get-date) with the following settings:"
Add-content $log_file -value $log_line
Add-content $log_file -value ($Global:watcher | format-list | out-string)
Add-content $log_file -value ("With events:" + (Get-EventSubscriber | format-list * | out-string))
Add-content $log_file -value ("Each event will be passed variables:" + ($passed_vars | format-list * | out-string))
Write-Host $log_line
Write-Host ($Global:watcher | format-list | out-string)

Everything works as intended if I do not save to the log file as in the above code. However, if I uncomment either of the two Add-Content lines the watcher stops firing after 1 event trigger.

Console output after intialisation and two saves add-content:

PS pwd .\start_fileWatcher.ps1
>>
Started to monitor test.xlsx at pwd.parent from 03/26/2024 14:25:24 with the following settings:
NotifyFilter : FileName, DirectoryName, LastWrite
EnableRaisingEvents : True
Filter : test.xlsx
IncludeSubdirectories : False
InternalBufferSize : 65536
Path : pwd.parent
Site :
SynchronizingObject :
Container :
PS pwd>
>> File 'test.xlsx' at path 'pwd.parent' was Renamed to 'B5D84B60.tmp' at 03/26/2024 14:25:30
File 'AC0B5930' at path 'pwd.parent' was Renamed to 'test.xlsx' at 03/26/2024 14:25:30
Script 'test.py' in working directory 'pwd' was ran at time 03/26/2024 14:25:31
>> File 'test.xlsx' at path 'pwd.parent' was Renamed to 'C66413E1.tmp' at 03/26/2024 14:25:32
File '331B5930' at path 'pwd.parent' was Renamed to 'test.xlsx' at 03/26/2024 14:25:32
Script 'test.py' in working directory 'pwd' was ran at time 03/26/2024 14:25:32

Console output after intialisation and two saves with add-content:

PS pwd> .\start_fileWatcher.ps1
>>
Started to monitor test.xlsx at pwd.parent from 03/26/2024 14:20:06 with the following settings:
NotifyFilter : FileName, DirectoryName, LastWrite
EnableRaisingEvents : True
Filter : test.xlsx
IncludeSubdirectories : False
InternalBufferSize : 65536
Path : pwd.parent
Site :
SynchronizingObject :
Container :
PS pwd>
>> File 'test.xlsx' at path 'pwd.parent' was Renamed to '60EC4C02.tmp' at 03/26/2024 14:20:10

I changed the directory names to pwd and pwd.parent as I prefer to have this anonymous.

I thought the buffer size could have been the limiting factor, but increasing that from 8kb to 64kb, the maximum, seemed to have no effect. So what is causing fileSystemWatcher to stop triggering events? And what can I do to force/fix it?

Cheers

• mclayton: Guessing a bit - I think both your calls to Add-Content might be throwing exceptions - in the first, $log_file doesn’t have a value as it’s not inheriting from the top-level script scope so is $null and in the second call you’re only passing one parameter. Try adding some write-host "before add-content 1" / write-host "after add-content 1" trace calls and check if they actually execute during the first event that gets triggered...
• Orange Pukeko: Yes, unfortunately it was this basic, something I have done right multiple other times in this script. If you add an answer, I'd happily accept.
• Santiago Squarzon: @mclayton in case you didnt get OP's response above