How to run substring on the message field of Get-Winevent-CodePudding

This is the PowerShell query I'm starting with:

$CRM_Serverlist = 'Server-114', 'Server-115', 'Server-118', 'Server-P119'
$CRM_Account = 'domain\svcCRM'
$svcCRM_cred = Get-Credential -Credential $CRM_Account
ForEach ($CRM_Server in $CRM_Serverlist) {
   Get-WinEvent -ComputerName $CRM_Server -Credential $svcCRM_cred -FilterHashtable @{
       LogName = 'Application'
       ProviderName='MSCRMPlatform'
       Level = 3 # 1 Critical, 2 Error, 3 Warning, 4 Information
       } | select-object message | Format-List -Property message
   }

It produces output like similar to this. (I've truncate the SQL queries for brevity.)

Message : Query execution time of 14.6 seconds exceeded the threshold of 10 seconds. Thread: 283; 
          Database: CRM_MSCRM; Server:Server-SQL1; Query: IF EXISTS (SELECT * FROM sys.objects ...

Message : Query execution time of 10.9 seconds exceeded the threshold of 10 seconds. Thread: 54; Database: 
          CRM_MSCRM; Server:Server-SQL1; Query: select "a360_connectionrule0".a360_ConnectionId ...
    
Message : Query execution time of 19.3 seconds exceeded the threshold of 10 seconds. Thread: 272; 
          Database: CRM_MSCRM; Server:Server-SQL1; Query: WITH "incident0Security" as (...
    
Message : Query execution time of 53.6 seconds exceeded the threshold of 10 seconds. Thread: 276; 
          Database: CRM_MSCRM; Server:Server-SQL1; Query: select "incident0".a360_EscalationDate2...

What I want to do is extract the time from all the messages from all the servers, sort by the time so that the longest running SQL statements are listed first, then output them for so they can be tuned to run faster. Outputting the time would be nice but is not strictly required. It would be great if I could end up with something like this:

Time: 53.6
Message : Query execution time of 53.6 seconds exceeded the threshold of 10 seconds. Thread: 276; 
          Database: CRM_MSCRM; Server:Server-SQL1; Query: select "incident0".a360_EscalationDate2...

Time: 19.3
Message : Query execution time of 19.3 seconds exceeded the threshold of 10 seconds. Thread: 272; 
          Database: CRM_MSCRM; Server:Server-SQL1; Query: WITH "incident0Security" as (...

Time: 14.6
Message : Query execution time of 14.6 seconds exceeded the threshold of 10 seconds. Thread: 283; 
          Database: CRM_MSCRM; Server:Server-SQL1; Query: IF EXISTS (SELECT * FROM sys.objects ...

Time: 10.9
Message : Query execution time of 10.9 seconds exceeded the threshold of 10 seconds. Thread: 54; Database: 
          CRM_MSCRM; Server:Server-SQL1; Query: select "a360_connectionrule0".a360_ConnectionId ...

Any suggestions would be appreciated.

CodePudding user response：

This will probably work however as stated in comments, it would be a better idea to not do it via regex and try looking into the Properties property of the EventLogRecord objects to see if the execution time value is there.

$re = [regex] '(?<=Query execution time of )[\d.] '

$CRM_Serverlist | ForEach-Object {
    Get-WinEvent -ComputerName $_ -Credential $svcCRM_cred -FilterHashtable @{
        LogName      = 'Application'
        ProviderName = 'MSCRMPlatform'
        Level        = 3 # 1 Critical, 2 Error, 3 Warning, 4 Information
    }
} |
Select-Object @{
    Name       = 'Time'
    Expression = { [timespan]::FromSeconds($re.Match($_.Message).Value) }
}, Message | Sort-Object Time -Descending

How to know if you can get the execution time by looking into the Properties property of one of the events:

Pick one event from one of your servers:

$evt = Get-WinEvent -ComputerName pickOneServer -Credential $cred -FilterHashtable @{
    LogName      = 'Application'
    ProviderName = 'MSCRMPlatform'
    Level        = 3 # 1 Critical, 2 Error, 3 Warning, 4 Information
} -MaxEvents 1

Inspect it's Properties property:

$evt.Properties

If you see the decimal value for elapsed time here, then you can pick it by index, for example let's say the elapsed time is in index 2:

$evt.Properties.Value[1] # since index starts in 0 in pwsh

Then assuming we could find this value there, the whole script would change to this instead of using regex to pick the value:

$CRM_Serverlist | ForEach-Object {
    Get-WinEvent -ComputerName $_ -Credential $svcCRM_cred -FilterHashtable @{
        LogName      = 'Application'
        ProviderName = 'MSCRMPlatform'
        Level        = 3 # 1 Critical, 2 Error, 3 Warning, 4 Information
    }
} | Select-Object @{
    Name       = 'Time'
    Expression = { [timespan]::FromSeconds($_.Properties.Value[1]) }
}, Message | Sort-Object Time -Descending