Search code examples
powershellemailloggingalerttail

Tail log file with Powershell and email but only on first occurrence until next time


I've found the following script to send an email when a string is found in a log file

Get-Content C:\temp\server.log -Wait -Last 0 |
Where-Object { $_ -match "ERROR \[STDERR\]" } |
ForEach-Object {
Send-MailMessage -SmtpServer x.x.x.x -From ALERT@com -To alert.com -Subject 'Error' -Body $_
}

This works well but I'd like to take it a couple of steps further. When exceptions are thrown in the log file you can have multiple lines with the matched string thus triggering multiple email alerts for each line, what would be better is a single email to catch the whole block of the error message ( or x number of lines before and after)

Is this possible with Powershell?

Thanks in advance

Donald

I tried the block of code above and got multiple emails when I only want a single email

Sample log:

09:14:01,407 ERROR         [org.apache.struts.action.RequestProcessor]
09:21:34,649 ERROR [stderr] (default task-    554java.io.IOException:
09:21:34,650 ERROR [stderr] (default task-554)  at java.base/
09:21:34,650 ERROR [stderr] (default task-554)  at java.base/
12:18:53,286 ERROR     [org.apache.struts.action.RequestProcessor] (default task-    949) Invalid path 
12:24:06,441 ERROR     [org.apache.struts.action.RequestProcessor] (default task-    957) Invalid path
14:23:57,661 ERROR [stderr] (default task-1114at         [email protected]//org.
[email protected].
14:23:57,661 ERROR [stderr] (default task-1114)     at             [email protected]

Solution

  • The following solution:

    • Uses the Start-ThreadJob cmdlet for thread-based parallelism (a faster and lighter-weight alternative to the child-process-based regular background jobs created with Start-Job).

      • It comes with PowerShell (Core) 7+ and in Windows PowerShell can be installed on demand with, e.g., Install-Module ThreadJob -Scope CurrentUser.
    • The thread job the solution creates monitors a concurrent, i.e. thread-safe queue (System.Collections.Concurrent.ConcurrentQueue<T>), filled by the main thread with the log messages of interest.

    • Once the thread job detects a message in the queue, it collects up to 9 additional ones, but only within a 1-second window; in other words: it considers up to 10 messages received within a 1-second interval to belong to the same error, and emails them together (sending of the email is only simulated below).

      • Note that this heuristic is suboptimal; a reliable way to detect the last message in a block of related based on its content would be preferable.
    • Note: A bug in Get-Content in PowerShell 7.4.0 and 7.4.1 prevents -Tail 0 from working in combination with -Wait (no waiting occurs). This is expected to get fixed in 7.4.2 - see GitHub PR #20734. To work around the bug, the code below uses -Tail 1

    # Create a concurrent (thread-safe) queue.
    $msgQueue = [System.Collections.Concurrent.ConcurrentQueue[string]]::new()
    
    # Start a thread job that will monitor the queue and send
    # blocks of error lines per email.
    $job = Start-ThreadJob {
      
      # Get a reference to the concurrent queue from the caller's scope.
      $msgQueue = $using:msgQueue 
      # Helper variables.
      $msg = $null
      $msgs = [System.Collections.Generic.List[string]] @()
      $sw = [System.Diagnostics.Stopwatch]::new()
    
      while ($true) {
    
        # Poll for new queue items every N milliseconds; adjust as needed.
        # Note that Get-Content -Wait itself polls once every second.
        Start-Sleep -Milliseconds 500
    
        # Collect queued messages, up to 10 at a time, if received within
        # a 1-second window.
        if ($msgQueue.TryDequeue([ref] $msg)) {
          $msgs.Add($msg)
          # Wait for up to 9 more messages for at most (roughly) 1 second, 
          # whichever comes first.
          $sw.Restart()
          while ($msgs.Count -lt 10 -and $sw.Elapsed.TotalSeconds -le 1) {
            if ($msgQueue.TryDequeue([ref] $msg)) { $msgs.Add($msg) }        
            Start-Sleep -Milliseconds 50 # Sleep a little, to avoid a tight loop.
          }
          # Simulate sending the email with the collected lines.
          # Place your Send-MailMessage call here.
          # Note: 
          #  [Console]::WriteLine() must be used in order to print to the screen
          #  from a thread job.
          [Console]::WriteLine("--- Emailing the following lines:`n$($msgs -join "`n")")
          $msgs.Clear()
        } 
    
      }
    
    }
    
    # Start the tailing operation (Get-Content -Wait).
    # Stopping it requires Ctrl-C.
    try {
      $logFile = 'C:\temp\server.log'
      Get-Content $logFile -Wait -Last 1 |
        Where-Object { $_ -match 'ERROR \[STDERR\]' } |
        ForEach-Object {
          # Enqueue lines of interest, to be processed by the thread job.
          $msgQueue.Enqueue($_)
        }
    }
    finally {
      # Ctrl-C was pressed: clean up the thread job before exiting.
      if ($job) { $job | Remove-Job -Force }
    }
    

    Self-contained example with debugging:

    Note:

    • The following requires PowerShell (Core) 7+, because Windows PowerShell seemingly doesn't support debugging thread jobs (those started with Start-ThreadJob as opposed to (child process-based) background jobs started with Start-Job) via Debug-Job

    • Due to a bug in version 2.3.4 of the PSReadLine module (the one that ships with PowerShell 7.4.1), it must be (temporarily) unloaded before running debugging with Debug-Job, which the code automatically does - see GitHub issue #3954.

    • To ensure that the debugger reliably breaks into the thread job every time Debug-Job is called, a dummy Set-PSBreakpoint call is used; as of PowerShell 7.4.1, placing a Wait-Debugger call inside a thread job seemingly cause a hang when Debug-Job is called; see the source-code comments for details, and GitHub issue #21257.

    Instructions:

    • For simplicity, a sample_log.txt file in the current directory is created and tailed, which is automatically removed on exit.

    • When you run the script, it prints instructions on how to append lines of interest to log.txt on demand, from a separate session, so as to trigger processing (be sure to run the other session in the same directory or target log.txt by its full path).

    • Once the debugger is entered and you're done debugging, use d to continue execution, which detaches the debugger and resumes foreground execution; it is re-entered every time new lines of interest are received.

      • However, note that debugging can interfere with the logic of the 1-second time window for collecting messages, so that a single block of related lines can result in multiple debugger invocations and multiple simulated emails.

      • For instructions on how to use the debugger, see the conceptual about_Debuggers help topic.

    • Use Ctrl-C to terminate execution overall.

    # To work around a PSReadLine bug, unload it for the duration of this script.
    if ($psrlWasLoaded = [bool] (Get-Module PSReadLine)) {
      Remove-Module PSReadLine
    }
    
    # Initialize the file to be tailed.
    # For simplicity, the path is hard-coded to 'sample_log.txt' in the current dir.
    1 | Set-Content sample_log.txt
    
    # To trigger activity, repeat the following on demand from a separate session:
    $sb = {
    $ExecutionContext.InvokeCommand.ExpandString(@'
    $([datetime]::now.Tostring('HH:mm:ss.ffff')) 1 ERROR [stderr](default task-    554java.io.IOException: 
    $([datetime]::now.Tostring('HH:mm:ss.ffff')) 2 ERROR [stderr] (default task-    555java.io.IOException:
    $([datetime]::now.Tostring('HH:mm:ss.ffff')) 3 ERROR [stderr](default task-    556java.io.IOException:
    '@)  | Add-Content sample_log.txt
    }
    
    Write-Verbose -Verbose @"
    To trigger activity, run the following from a separate session:
    $sb
    "@
    
    # Create a concurrent (thread-safe) queue.
    $msgQueue = [System.Collections.Concurrent.ConcurrentQueue[string]]::new()
    
    # Start a thread job that will monitor the queue and send
    # blocks of error lines per email.
    $job = Start-ThreadJob {
      
      # Get a reference to the concurrent queue from the caller's scope.
      $msgQueue = $using:msgQueue 
      # Helper variables.
      $msg = $null
      $msgs = [System.Collections.Generic.List[string]] @()
      $sw = [System.Diagnostics.Stopwatch]::new()
      
      # !! This is necesary in order to reliably break into the debugger
      # !! on repeat invocations with Debug-Job.
      # !! Breaks whenever $breakHere is assigned to, set in the loop below.
      Set-PSBreakpoint -Variable breakHere
      # !! Wait-Debugger SHOULD work, but as of v7.4.1 doesn't in THREAD jobs.
    
      while ($true) {
    
        $breakHere = 1 # Trigger breaking into the debugger when run with Debug-Job.
    
        # Poll for new queue items every N milliseconds; adjust as needed.
        # Note that Get-Content -Wait itself polls once every second.
        Start-Sleep -Milliseconds 500
    
        # Collect queued messages, up to 10 at a time, if received within
        # a 1-second window.
        if ($msgQueue.TryDequeue([ref] $msg)) {
          $msgs.Add($msg)
          # Wait for up to 9 more messages for at most (roughly) 1 second, 
          # whichever comes first.
          $sw.Restart()
          while ($msgs.Count -lt 10 -and $sw.Elapsed.TotalSeconds -le 1) {
            if ($msgQueue.TryDequeue([ref] $msg)) { $msgs.Add($msg) }        
            Start-Sleep -Milliseconds 50 # Sleep a little, to avoid a tight loop.
          }
          # Simulate sending the email with the collected lines.
          # Place your Send-MailMessage call here.
          # Note: 
          #  [Console]::WriteLine() must be used in order to print to the screen
          #  from a thread job.
          [Console]::WriteLine("--- Emailing the following lines:`n$($msgs -join "`n")")
          $msgs.Clear()
        } 
    
      }
    
    }
    
    # Start the tailing operation (Get-Content -Wait).
    # Stopping it requires Ctrl-C.
    try {
    
      # Set this to $true to turn on debugging.
      $launchDebugger = $true
      # If debugging, wait until the job is ready to be debugged.
      if ($launchDebugger) { while ($job.State -notin 'Running', 'AtBreakPoint') { Start-Sleep -Milliseconds 100 } }
      
      Write-Verbose -Verbose 'Starting to tail sample_log.txt...'
    
      # Main loop: Tail a file and add lines of interest to a queue that is
      #            processed by the thread job.
      Get-Content sample_log.txt -Wait -Last 1 |
        Where-Object { $_ -match 'ERROR \[STDERR\]' } |
        ForEach-Object {
    
          # Enqueue lines of interest, to be processed by the thread job.
          "Received locally: [$_]"
          Write-Verbose -Verbose "Enqueuing..."
          $msgQueue.Enqueue($_)
    
          # If requested, break into the debugger in the thread job.
          if ($launchDebugger) { 
            Write-Verbose -Verbose 'Invoking the debugger on the thread job...'
            $job | Debug-Job # This is a blocking call.
            Write-Verbose -Verbose 'Resuming tailing...'
          }
        }
    }
    finally {
      # Ctrl-C was pressed: clean up the thread job before exiting.
      if ($job) { $job | Remove-Job -Force }
      if ($psrlWasLoaded) { Import-Module PSReadLine }
      Remove-Item -LiteralPath sample_log.txt
    }