Wednesday, October 2, 2013

Powershell Script - Using EMS Get-MessageTrackingLog + LogParser to Retrieve Top-Traffic Metrics for the Hubs in a Site

10/02/2013:All mail admins will occasionally see "odd" Exchange HubTransport queuing behavior for "unknown" reasons (I'll generally notice these type of events in response to monitoring alerts or via a looping get-queue monitoring script I run 24/7).

In most cases these little 'surges' come and go in a matter of minutes with no material impact or footprint. But on other occasions, you see something about the queuing that warrants further investigation into exactly what occurred:
  • Possibly your interest is piqued due to the amount of mail that queued up (say a sudden spike into hundreds if not thousands of messages in normal delivery queues)
  • Or possibly you want to check further due to mail rapidly piling up in queues where you traditionally should see little to no traffic (e.g. in the Unreachable queue).
This is a bit more complicated than my usual posting. It represents a full-scale script I use to parse through and report on Exchange 2007 or Exchange 2010 HubTransport Message Tracking Logs, on the following filtered subsets of data to try to identify exactly what was the source of the odd queuing behavior.
It's a longish script but it's process can be summarized as follows:
  1. Interactively prompt for filtering criteria:
    • Exchange Site to analyze [SiteName: US | EU | AP ]
    • Exchange Revision to target: [ExTargVers: 2007 | 2010 ]
    • 'Top' event type to filter: [TrkTarget: SENDER | RECIPIENT | BOUNCE | DEFERRED]  
    • Minutes of recent traffic to filter: [TrkMins: [integer]]
  2. Run an Exchange Management Shell get-messagetrackinglog pass on all HubTransport servers in the specified Site & Exchange revision, to export all traffic in the specified recent number of recent minutes, into a csv file.
  3. Run a Microsoft LogParser query at the output file above, to return a report on the Top-20 Senders or Recipients (depending on the filter), related to the matching traffic.Export the results to CSV report file, and console.

Here's a Gist with the key chunks of code (see the full Git copy of the script for more details)

Static-source follows (for folks in RSS readers, or disabling scripting):
(check the linked Gist/Github links below for _current_ versions).

get-HT-MsgTrk-TopTraffic-LastXMin.ps1 :

// <# TRIMMED GIST #>

#*----------------v Function ProcessLogs() v----------------
Function ProcessLogs {
 
<# TRIMMED GIST #>
  write-host -ForegroundColor White ((get-date).ToString("HH:mm:ss") + ": Site: " + $SiteName)

  foreach ($Hub in $Hubs) {
    write-host -foregroundcolor White ("-" * 10)
    If ($bDebug -eq $TRUE) {write-host ((get-date).ToString("HH:mm:ss") + ": `$Hub: " + $Hub)}
    $ServerName = $Hub
    write-host -foregroundcolor yellow ((get-date).ToString("HH:mm:ss") + ": Parsing Server: " + $ServerName + " for the Top " + $TopUsers + " MsgTracking users in the last " + $TrkMins + " minutes (" + (get-date -format "yyMMdd") + ")...")
    
    $TimeStampEnd= get-date -uformat "%m/%d/%Y %I:%M:%S %p"
    if (($TimeStampEnd.ToSTring()).StartsWith('0')) {$TimeStampEnd=$TimeStampEnd.substring(1,$TimeStampEnd.length-1)}
    $TimeStampEndFN= get-date -uformat "%Y%m%d-%H%M"
    
    $TimeStampStart=(get-date).AddMinutes((-1 * $TrkMins))
    # and format it into the format necessary for the get-messagetrackinglog cmdlet
    $TimeStampStart=get-date ($TimeStampStart.ToString()) -uformat "%m/%d/%Y %I:%M:%S %p"
    
    if ($bDebug) { write-host -foregroundcolor darkgray ((get-date).ToString("HH:mm:ss") + ":`$TimeStampStart: " + $TimeStampStart + "`n`$TimeStampEnd: " + $TimeStampEnd ) }
    if (($TimeStampStart.ToSTring()).StartsWith('0')) {$TimeStampStart=$TimeStampStart.substring(1,$TimeStampStart.length-1)}
    $TimeStampStartFN=get-date ($TimeStampStart.ToString()) -uformat "%Y%m%d-%H%M"
    $TimeStampNow = get-date -uformat "%Y%m%d-%H%M"
    $outTrkFile=$HTTempDir + $ServerName + "-TRACK-" + $TimeStampStartFN + "to" + $TimeStampEndFN + ".csv"
    $outRptFile = $HTTempDir + $ServerName + "-" + $TimeStampStartFN + "to" + $TimeStampEndFN + "-top" + $TopUsers + "-" + $TrkTarget + "Addrs.csv"
    
    # echo the settings to console
    write-host ((get-date).ToString("HH:mm:ss") + ": TimeStampStart:" + $TimeStampStart)
    write-host ((get-date).ToString("HH:mm:ss") + ": TimeStampEnd:" + $TimeStampEnd)
    write-host ((get-date).ToString("HH:mm:ss") + ": `$outTrkFile:" + $outTrkFile)
    write-host ((get-date).ToString("HH:mm:ss") + ": `$outRptFile:" + $outRptFile)

    #2. Use msgtrack to pull out the time range of receive events (make sure to use no-type):
    $sExcCmd = 'get-messagetrackinglog -ResultSize Unlimited -server ' + $ServerName + ' -Start "' + $TimeStampStart + '" -End "' + $TimeStampEnd + '" |  select Timestamp,ClientIp,ClientHostname,ServerIp,ServerHostname,SourceContext,ConnectorId,Source,EventId,InternalMessageId,MessageId,@{Name="Recipient-Addrs";Expression={$_.recipients}},RecipientStatus,TotalBytes,RecipientCount,RelatedRecipientAddress,Reference,MessageSubject,Sender,ReturnPath,MessageInfo | export-csv ' + $outTrkFile + ' â??notype' 
    
    write-host -foregroundcolor Yellow "---"
    write-host -foregroundcolor Yellow ((get-date).ToString("HH:mm:ss") + ": Running initial messagetracking query(collect " + $TrkMins + "min traffic)...")
    
    # start a stopwatch to time the the process
    $sw = [Diagnostics.Stopwatch]::StartNew()
    write-host " " 
    write-host ((get-date).ToString("HH:mm:ss") + ": get-messagetracking query at Invoke:" ); $sExcCmd 
    
    # clear any existing errors
    $error.clear() 
    # Invoke the get-messagetrackinglog command to retrieve the raw traffic for the specified number of minutes
    Invoke-Expression $sExcCmd -verbose

    # check for errors
    if($error.count -gt 0){
      write-host -foregroundcolor red ((get-date).ToString("HH:mm:ss") + ": " + $error )
      if ($error -like '*The task has failed with an exception. The error message is: The parameter is incorrect*') {write-host -foregroundcolor yellow ((get-date).ToString("HH:mm:ss") + ": *** You cannot run Exch2010 MessageTracks from Exch2007 EMS.`nMove execution of this script to a machine with Exch2010 EMS installed***") ; exit 1}
    } # if-block end

    # confirm that the CSV tracking output file was produced, before moving on to logparsing
    if (!(test-path $outTrkFile)){
      write-warning ("NO " + $outTrkFile + " file written! ABORTING logparser pass on this system")
    } else {
      If ($bDebug -eq $TRUE) {write-host -ForegroundColor Yellow ((get-date).ToString("HH:mm:ss") + ": `$outTrkFile: " + $outTrkFile + " file present") }
      
      #3. Logparse out the top-20 items from the messagetracking csv output:
      switch ($TrkTarget) {
        "SENDER" {
          $sSQL =  "SELECT TOP 10 Sender, Count(*) AS Msgs INTO " + $outRptFile + " FROM " + $outTrkFile + " WHERE eventid = 'RECEIVE' GROUP BY Sender ORDER BY Msgs DESC"
        }
        "RECIPIENT" {
         # 12:50 PM 10/1/2013 using the new Recipient-Addrs custom field from the msgtrack
         $sSQL =  "SELECT TOP 20 Recipient-Addrs, Count(*) AS Msgs INTO " + $outRptFile + " FROM " + $outTrkFile + " WHERE eventid = 'DELIVER' OR eventid = 'SEND' OR eventid = 'FAIL' OR eventid = 'DSN' GROUP BY Recipient-Addrs ORDER BY Msgs DESC"
          
        }
        "BOUNCE" {
         # 12:50 PM 10/1/2013 using the new Recipient-Addrs custom field from the msgtrack
         $sSQL = "SELECT TOP 20 Recipient-Addrs, Count(*) AS Msgs INTO " + $outRptFile + " FROM " + $outTrkFile + " WHERE eventid = 'FAIL' OR eventid = 'DSN' GROUP BY Recipient-Addrs ORDER BY Msgs DESC"
        }
        "DEFERRED"  {
          # 12:50 PM 10/1/2013 using the new Recipient-Addrs custom field from the msgtrack
          $sSQL =  "SELECT TOP 20 Recipient-Addrs, Count(*) AS Msgs INTO " + $outRptFile + " FROM " + $outTrkFile + " WHERE eventid = 'DEFER' GROUP BY Recipient-Addrs ORDER BY Msgs DESC"
        }
      } # if-block end
       
      # build the LogParser commandline syntax, wrapping the SQL sytnax in double-quotes
      $sExcCmd =  $LOGPAREXE + ' -headerRow ON -iDQuotes APto ' + $sQot + $sSQL + $sQot + ' -i:CSV -o:csv'
      
      write-host -foregroundcolor Yellow "---"
      write-host -foregroundcolor Yellow ((get-date).ToString("HH:mm:ss") + ": Running secondary LogParser query(Top " + $TopUsers + ",on " + $TrkTarget + ")...")
      
      write-host ((get-date).ToString("HH:mm:ss") + ": " + $TrkTarget + " Query at Invoke:" ); $sExcCmd 
      
      # Invoke the LogParser command
      Invoke-Expression $sExcCmd -verbose

      # evaluate that the proper Logparser output csv file was produced (exit the script if no output)
      if (!(test-path $outRptFile)){
          write-warning ("NO " + $outRptFile + " file written!")
          exit 1
      } else {
        If ($bDebug -eq $TRUE) {write-host -ForegroundColor Yellow ((get-date).ToString("HH:mm:ss") + ": `$outRptFile: " + $outRptFile + " file present")}
      } # if-block end
      
      # if we're using CSV output of the report, pull the report csv in and redisplay it to console...
      if ($bOutputToCSV -eq $TRUE) {
        import-csv $outRptFile | ft -wrap | out-defAPlt
      } # if-block end
      
    } # if-block end (logparser block)
    
    # then move the processing files ($outTrkFile & $outRptFile csv's to the permanent reporting $DestDir
    write-host -foregroundcolor Yellow "---"
    write-host ((get-date).ToString("HH:mm:ss") + ": Pass Results..." )
    write-host ((get-date).ToString("HH:mm:ss") + ": input file: " + $outTrkFile )
    write-host ((get-date).ToString("HH:mm:ss") + ": output file: " + $outRptFile)
    write-host ((get-date).ToString("HH:mm:ss") + ": Moving output file to : " + $DestDir)
    
    # Only copy if not already running on the reporting archive server 
    if ($ComputerName -eq $runsServer) {
      write-host ((get-date).ToString("HH:mm:ss") + ": Script is executing on " + $runsServer + " skipping move of result files.")
    } else {
      # remote server pass, move results & processing files to central storage location.
        $error.clear() 
        move-item $outTrkFile $DestDir #-whatif
        move-item $outRptFile $DestDir #-whatif
    } # if-block end
    
    
    write-host -foregroundcolor green ((get-date).ToString("HH:mm:ss") + ": PASS COMPLETED")
   # stop stopwatch & echo time
    $sw.Stop()
    # simple output
    write-host -foregroundcolor green ((get-date).ToString("HH:mm:ss") + ": Elapsed Time: (HH:MM:SS.ms)" + $sw.Elapsed.ToString())
    write-host -foregroundcolor Yellow ("=" * 10)
        
  } # for-loop end HUBS

} #*----------------^ END Function ProcessLogs() ^----------------

<# TRIMMED GIST #>

And the current revision can always be found at Github: get-HT-MsgTrk-TopTraffic-LastXMin.ps1

No comments:

Post a Comment