PowerShell – Error – “Missing closing ‘)’ in expression” – Param // Set-StrictMode

Background

Getting an error when I try to run a PowerShell script.

The PowerScript accepts parameters and thus it includes the Param Statement.

It also enforces a Strict Mode; principally it requires that all variables should be explicitly declared.

Error Message

Here is the error message:


Missing closing ')' in expression.
+     <<<< [alias("F")]
    + CategoryInfo          : ParserError: (CloseParenToken:TokenId) [], ParseException
    + FullyQualifiedErrorId : MissingEndParenthesisInExpression

 

Code

Original Code

Here is the original code:

Set-StrictMode -Version 1
[CmdletBinding()]
Param
(
   [Parameter(Mandatory=$true, position=0, HelpMessage="Filename input")]
   [alias("F")]
   [string]$filename="services.txt"
)

Revised Code


[CmdletBinding()]
Param
(
	[Parameter(Mandatory = $false, ValueFromPipeline = $true, ValueFromPipelineByPropertyName = $true)]
	[alias("f")]
	[string]$filename="services.txt"
)

Set-StrictMode -Version 1

Explanation

  1. The very first line needs to be the Function argument definition
    • Param
  2. And, the “Set-StrictMode -Version #” can then follow
    • Set-StrictMode -Version 1
    • Or  “Set-StrictMode -Version 2

Scheduled Task – Powershell Starts, but does not complete

Background

Scheduled a Task, but it is not completing.

 

Task Scheduler

Let us review the Task…

Task Overview

 

Task – Action

TroubleShooting

Task Manager

Launched Task Manager and looked for the Task.

One pointed to do so is to look at Command Line Column.

Image

 

Findings

  1. Command Line
    • C:\Windows\System32\notepad.exe “E:\Scripts\Service\ServiceMgmt\serviceStart.ps1”

 

Interpretation

It seems that ps1 files are attached to notepad.exe

 

Why Notepad?

 

Jacob Zinicola // How To Geek
How to Configure Windows to Work with PowerShell Scripts More Easily
Link

PowerShell is not associated to the .PS1 file extension by default.
Windows sets the default action for .PS1 files to open them in Notepad, instead of sending them to the PowerShell command interpreter.
This is to directly prevent accidental execution of malicious scripts when they’re simply double-clicked.

 

Workaround?

Associate PS1 with Powershell.exe

It is easy enough to associate ps1 files with Powershell.exe and get PS1 files to run directly from the command line.

 

Scheduled Task

But, even after this change, was still unable to get PS1 to run directly as a scheduled task.

 

True Solution

The only true solution is the one where we  a write a command file and invoke the PS1 script in the cmd file…


set "_app=c:\windows\system32\WindowsPowerShell\v1.0\powershell.exe"
set "_PSExecutionPolicy=bypass"

set "_currentFolder=%cd%"
set "_script=serviceStart.ps1"
set "_scriptFullName=%cd%\%_script%"

%_app% -NoProfile -Executionpolicy %_PSExecutionPolicy% -file %_scriptFullName%

 

References

  1. Warren Frame // Cookie Monster
    • Troubleshooting PowerShell Based Scheduled Tasks
      Link
  2. Stack Overflow
    • Powershell script does not run via Scheduled Tasks
      Link
  3. Weekend Scripter: Use the Windows Task Scheduler to Run a Windows PowerShell Script
    Link
  4. How to Geek
    • Jacob Zinicola
      • How to Configure Windows to Work with PowerShell Scripts More Easily
        Link

 

Windows – Start Services thru Powershell

Background

I wish I can be like the rest of these guys who write scripts just for fun.

Oh No, Not yours truly.

Windows Patches were applied to our computers and unfortunately SQL Server Services did not start.

I mean they are set for auto-start, but that didn’t help me out this time.

Code

And, so need to develops scripts that can be ran manually or scheduled.

outline

  1. service.txt
    • Text file that contains the list of Services
  2. serviceStart.ps1
    • PowerShell script that starts each service in above list if service is not running
  3. invoke.cmd
    • Invoke PowerShell Script

service.txt

MSSQLSERVER
SQLSERVERAGENT

serviceStart.ps1

Set-StrictMode -Version 1

[System.Collections.ArrayList] $listofServices = $null;
[string] $log = $null;
[string] $filename =$null;
[string] $fileLog =$null;


[object] $objService=$null;

$listofServices = New-Object System.Collections.ArrayList;

$filename = "services.txt"
$fileLog = "log\serviceAutomation.log";


function folderMgmt($fileLog) 
{

	[string] $logFolder = $null;
	[boolean]$folderExist= $false;
	

	## prepare diagnostic statement
	$log = "Reviewing file {0} ..." -f $fileLog;

	## write debug statement
	Write-Debug -message $log
	Write-Host $log
	
	## Get Log Folder from filename
	$logFolder = Split-Path -Path $fileLog;


	## prepare diagnostic statement
	$log = "Log Folder is  {0} ..." -f $logFolder;

	## write debug statement
	Write-Debug $log
	
	## prepare diagnostic statement
	$log = "Check if folder {0} exist!" -f $logFolder;

	## write debug statement
	Write-Debug -message $log

	
	## Check Folder, if exists
	$folderExist = Test-Path $logFolder
	
	
	# if folder does not exist
	if ($folderExist -eq $false )
	{
	
		## prepare diagnostic statement
		$log = "Find File {0}, create folder {1}" -f $fileLog, $logFolder;

		## write debug statement
		Write-Debug -message $log

		## Create Folder
		New-Item $logFolder -type directory >$null;

	} ## if folder does not exist
	
} ## function folderMgmt


function readFile($filename)
{

	foreach ($service in get-content $filename)
	{

		## Add read line into $listofServices Array
		$listofServices.Add($service) >$null;

		$log = "Read {0}" -f $service;

		Write-Debug -message $log
		
	}

}
 

function processFile($fileLog)
{

	## Iterate list of Services
	$listofServices | ForEach-Object {

		# get service Name
		$service = $_;
		
		# get Service Node
		$objService = Get-Service $service;
		
		# get Service Status
		$serviceStatus = $objService.Status;
		
		# Display Current Step
		$log = "Processing Service {0}, Status {1}" -f $service, $serviceStatus;

		Write-Host $log
		
		# If Service is stopped
		if ($serviceStatus -eq "Stopped")
		{
		
			# Start Service
			Start-Service -InputObject $objService  -PassThru | Format-List >> $fileLog
		
		}

		
	}

}

folderMgmt($fileLog);
  
readFile($filename) >$null;

processFile($fileLog) >$null; 

	

invoke.cmd


set "_app=c:\windows\system32\WindowsPowerShell\v1.0\powershell.exe"
set "_PSExecutionPolicy=bypass"

set "_currentFolder=%cd%"
set "_script=serviceStart.ps1"
set "_scriptFullName=%cd%\%_script%"

%_app% -NoProfile -Executionpolicy %_PSExecutionPolicy% -file %_scriptFullName%

Source Code Control

GitHub

Availed on GitHub here.

References

  1. Microsoft – Developer Network
    • Microsoft.PowerShell.Management
      • Split-Path
        Link
      • Service
  2. Microsoft Technet
    • Hey, Scripting Guy! Blog
      • Avoid PowerShell Errors by Initializing Variables
        Link
    • Technet Magazine
      • Windows PowerShell Scripting One Line at a Time
        Link
  3. Windows IT Pro
    • Creating your own PowerShell Functions
      Link
    • Arrays & Functions
      Link
  4. PwrShell.Net
    • Array
      • Back to Basics Arrays
        Link
  5. ss64.com
    • Arrays
      • Syntax Arrays
        Link

Xpath Query – Compare Positional Versus Condition

Background

As always too much time on my hands.

I wanted to compare the query generated by XMLToolBox against one I tweaked gently.

Here is the post that introduces XMLToolBox.

 

Lab

Queries

XPath – Position


set nocount on;
go

declare @xml XML

set @xml=
'
<event name="sql_batch_completed" package="sqlserver" timestamp="2017-05-01T16:44:02.507Z">
  <data name="cpu_time">
    <value>250000</value>
  </data>
  <data name="duration">
    <value>226002957</value>
  </data>
  <data name="physical_reads">
    <value>16349</value>
  </data>
  <data name="logical_reads">
    <value>16197</value>
  </data>
  <data name="writes">
    <value>0</value>
  </data>
  <data name="row_count">
    <value>0</value>
  </data>
  <data name="result">
    <value>2</value>
    <text>Abort</text>
  </data>
  <data name="batch_text">
    <value>SELECT "dbo"."basetblb"."base_social" FROM "dbo"."basetblb" WHERE (("base_payroll_status" = ''A'' ) AND ("base_service_credit" &gt; 10 ) ) </value>
  </data>
  <action name="sql_text" package="sqlserver">
    <value>SELECT "dbo"."basetblb"."base_social" FROM "dbo"."basetblb" WHERE (("base_payroll_status" = ''A'' ) AND ("base_service_credit" &gt; 10 ) ) </value>
  </action>
  <action name="session_server_principal_name" package="sqlserver">
    <value>tracie</value>
  </action>
  <action name="session_id" package="sqlserver">
    <value>72</value>
  </action>
  <action name="server_principal_name" package="sqlserver">
    <value>tracie</value>
  </action>
  <action name="server_instance_name" package="sqlserver">
    <value>HRDBDEV</value>
  </action>
  <action name="is_system" package="sqlserver">
    <value>false</value>
  </action>
  <action name="database_name" package="sqlserver">
    <value>rbpivr1</value>
  </action>
  <action name="database_id" package="sqlserver">
    <value>10</value>
  </action>
  <action name="client_hostname" package="sqlserver">
    <value>WEBSERVER01</value>
  </action>
  <action name="client_app_name" package="sqlserver">
    <value>Microsoft® Windows® Operating System</value>
  </action>
  <action name="collect_system_time" package="package0">
    <value>2017-05-01T16:44:02.508Z</value>
  </action>
  <action name="attach_activity_id_xfer" package="package0">
    <value>E2EDC810-A11C-4C62-988D-2420F86D8EAD-0</value>
  </action>
  <action name="attach_activity_id" package="package0">
    <value>008E9A10-DF7E-4C85-9C85-95629D3B647F-1</value>
  </action>
</event>

'

select

		  [resultValueUsingPosition] 
			= cast
				(
					@xml.query('/event[@name="sql_batch_completed"]/data[7]/value/text()[1]' )
						as varchar(10)
				)

		, [resultTextUsingPosition] 
			= cast
				(
					@xml.query('/event[@name="sql_batch_completed"]/data[7]/text/text()[1]' )
						as varchar(30)
				)




 

XPath – Condition


set nocount on;
go

declare @xml XML

set @xml=
'
<event name="sql_batch_completed" package="sqlserver" timestamp="2017-05-01T16:44:02.507Z">
  <data name="cpu_time">
    <value>250000</value>
  </data>
  <data name="duration">
    <value>226002957</value>
  </data>
  <data name="physical_reads">
    <value>16349</value>
  </data>
  <data name="logical_reads">
    <value>16197</value>
  </data>
  <data name="writes">
    <value>0</value>
  </data>
  <data name="row_count">
    <value>0</value>
  </data>
  <data name="result">
    <value>2</value>
    <text>Abort</text>
  </data>
  <data name="batch_text">
    <value>SELECT "dbo"."basetblb"."base_social" FROM "dbo"."basetblb" WHERE (("base_payroll_status" = ''A'' ) AND ("base_service_credit" &gt; 10 ) ) </value>
  </data>
  <action name="sql_text" package="sqlserver">
    <value>SELECT "dbo"."basetblb"."base_social" FROM "dbo"."basetblb" WHERE (("base_payroll_status" = ''A'' ) AND ("base_service_credit" &gt; 10 ) ) </value>
  </action>
  <action name="session_server_principal_name" package="sqlserver">
    <value>tracie</value>
  </action>
  <action name="session_id" package="sqlserver">
    <value>72</value>
  </action>
  <action name="server_principal_name" package="sqlserver">
    <value>tracie</value>
  </action>
  <action name="server_instance_name" package="sqlserver">
    <value>HRDBDEV</value>
  </action>
  <action name="is_system" package="sqlserver">
    <value>false</value>
  </action>
  <action name="database_name" package="sqlserver">
    <value>rbpivr1</value>
  </action>
  <action name="database_id" package="sqlserver">
    <value>10</value>
  </action>
  <action name="client_hostname" package="sqlserver">
    <value>WEBSERVER01</value>
  </action>
  <action name="client_app_name" package="sqlserver">
    <value>Microsoft® Windows® Operating System</value>
  </action>
  <action name="collect_system_time" package="package0">
    <value>2017-05-01T16:44:02.508Z</value>
  </action>
  <action name="attach_activity_id_xfer" package="package0">
    <value>E2EDC810-A11C-4C62-988D-2420F86D8EAD-0</value>
  </action>
  <action name="attach_activity_id" package="package0">
    <value>008E9A10-DF7E-4C85-9C85-95629D3B647F-1</value>
  </action>
</event>

'



select

		  [resultValueUsingCondition] 
			= cast
				(
					@xml.query('/event[@name="sql_batch_completed"]/data[@name="result"]/value/text()[1]' )
						as varchar(10)
				)

		, [resultTextUsingCondition] 
			= cast
				(
					@xml.query('/event[@name="sql_batch_completed"]/data[@name="result"]/text/text()[1]' )
						as varchar(30)
				)


 

Compare Queries

Let us have the queries together and compare them.

 

Queried Together

Code



set nocount on;
go

declare @xml XML

set @xml=
'
<event name="sql_batch_completed" package="sqlserver" timestamp="2017-05-01T16:44:02.507Z">
  <data name="cpu_time">
    <value>250000</value>
  </data>
  <data name="duration">
    <value>226002957</value>
  </data>
  <data name="physical_reads">
    <value>16349</value>
  </data>
  <data name="logical_reads">
    <value>16197</value>
  </data>
  <data name="writes">
    <value>0</value>
  </data>
  <data name="row_count">
    <value>0</value>
  </data>
  <data name="result">
    <value>2</value>
    <text>Abort</text>
  </data>
  <data name="batch_text">
    <value>SELECT "dbo"."basetblb"."base_social" FROM "dbo"."basetblb" WHERE (("base_payroll_status" = ''A'' ) AND ("base_service_credit" &gt; 10 ) ) </value>
  </data>
  <action name="sql_text" package="sqlserver">
    <value>SELECT "dbo"."basetblb"."base_social" FROM "dbo"."basetblb" WHERE (("base_payroll_status" = ''A'' ) AND ("base_service_credit" &gt; 10 ) ) </value>
  </action>
  <action name="session_server_principal_name" package="sqlserver">
    <value>tracie</value>
  </action>
  <action name="session_id" package="sqlserver">
    <value>72</value>
  </action>
  <action name="server_principal_name" package="sqlserver">
    <value>tracie</value>
  </action>
  <action name="server_instance_name" package="sqlserver">
    <value>HRDBDEV</value>
  </action>
  <action name="is_system" package="sqlserver">
    <value>false</value>
  </action>
  <action name="database_name" package="sqlserver">
    <value>rbpivr1</value>
  </action>
  <action name="database_id" package="sqlserver">
    <value>10</value>
  </action>
  <action name="client_hostname" package="sqlserver">
    <value>WEBSERVER01</value>
  </action>
  <action name="client_app_name" package="sqlserver">
    <value>Microsoft® Windows® Operating System</value>
  </action>
  <action name="collect_system_time" package="package0">
    <value>2017-05-01T16:44:02.508Z</value>
  </action>
  <action name="attach_activity_id_xfer" package="package0">
    <value>E2EDC810-A11C-4C62-988D-2420F86D8EAD-0</value>
  </action>
  <action name="attach_activity_id" package="package0">
    <value>008E9A10-DF7E-4C85-9C85-95629D3B647F-1</value>
  </action>
</event>

'

select

		  [resultValueUsingPosition] 
			= cast
				(
					@xml.query('/event[@name="sql_batch_completed"]/data[7]/value/text()[1]' )
						as varchar(10)
				)

		, [resultTextUsingPosition] 
			= cast
				(
					@xml.query('/event[@name="sql_batch_completed"]/data[7]/text/text()[1]' )
						as varchar(30)
				)




select

		  [resultValueUsingCondition] 
			= cast
				(
					@xml.query('/event[@name="sql_batch_completed"]/data[@name="result"]/value/text()[1]' )
						as varchar(10)
				)

		, [resultTextUsingCondition] 
			= cast
				(
					@xml.query('/event[@name="sql_batch_completed"]/data[@name="result"]/text/text()[1]' )
						as varchar(30)
				)

Query Plan Comparison – Query Inline

 

Query Plan Comparison – Side by Side

Using SQL Server Management Studio (SSMS) v2016, we can run both queries individually and compare the saved Query Plan

Image

Tabulated
Item Position  Condition
 Cached Plan Size  152 KB  192 KB
 CompileCPU  25  118
 CompileMemory  1736  2664
 CompileTime  25  118
 EstimatedSubtreeCost  806.458  410.401
 MemoryGrant  16128  17920
 OptimizationLevel  FULL  FULL
 RetrievedFromCache  true  true

 

 

Execution Time – Comparison

Image

 

Explanation
  1. Consistently the query with hardcoded position came in around 40 ms while the conditional one came in around 160ms

Summary

It appears from this one test, generated queries that rely on an element’s fixed position are less taxing on the system.

Interestingly, positional queries are costed higher.

On the other hand, queries generated via Conditions are likely less performant.

 

 

XPath Query Tools – XmlToolBox

Background

Lately I have been working more and more with Extended Events and prior to that Cached Plans exploration.

And, has both are stored as XML, it makes sense to see what tools are available for accurately querying XML data.

 

Body

Here is the collected event.


<event name="sql_batch_completed" package="sqlserver" timestamp="2017-05-01T16:44:02.507Z">
  <data name="cpu_time">
    <value>250000</value>
  </data>
  <data name="duration">
    <value>226002957</value>
  </data>
  <data name="physical_reads">
    <value>16349</value>
  </data>
  <data name="logical_reads">
    <value>16197</value>
  </data>
  <data name="writes">
    <value>0</value>
  </data>
  <data name="row_count">
    <value>0</value>
  </data>
  <data name="result">
    <value>2</value>
    <text>Abort</text>
  </data>
  <data name="batch_text">
    <value>SELECT "dbo"."basetblb"."base_social" FROM "dbo"."basetblb" WHERE (("base_payroll_status" = 'A' ) AND ("base_service_credit" &gt; 10 ) ) </value>
  </data>
  <action name="sql_text" package="sqlserver">
    <value>SELECT "dbo"."basetblb"."base_social" FROM "dbo"."basetblb" WHERE (("base_payroll_status" = 'A' ) AND ("base_service_credit" &gt; 10 ) ) </value>
  </action>
  <action name="session_server_principal_name" package="sqlserver">
    <value>tracie</value>
  </action>
  <action name="session_id" package="sqlserver">
    <value>72</value>
  </action>
  <action name="server_principal_name" package="sqlserver">
    <value>tracie</value>
  </action>
  <action name="server_instance_name" package="sqlserver">
    <value>HRDBDEV</value>
  </action>
  <action name="is_system" package="sqlserver">
    <value>false</value>
  </action>
  <action name="database_name" package="sqlserver">
    <value>rbpivr1</value>
  </action>
  <action name="database_id" package="sqlserver">
    <value>10</value>
  </action>
  <action name="client_hostname" package="sqlserver">
    <value>WEBSERVER01</value>
  </action>
  <action name="client_app_name" package="sqlserver">
    <value>Microsoft® Windows® Operating System</value>
  </action>
  <action name="collect_system_time" package="package0">
    <value>2017-05-01T16:44:02.508Z</value>
  </action>
  <action name="attach_activity_id_xfer" package="package0">
    <value>E2EDC810-A11C-4C62-988D-2420F86D8EAD-0</value>
  </action>
  <action name="attach_activity_id" package="package0">
    <value>008E9A10-DF7E-4C85-9C85-95629D3B647F-1</value>
  </action>
</event>

 

Googled

Googled on XML Query XPath and found many tools.

In this post we will discuss XMLToolBox.

 

XMLToolBox

I liked XMLToolBox has unlike many other tools one does not have to start with a query, just paste the the XML body unto the canvas, and point at the XML element or attribute you want to generate the query on.

 

Usage

Here is what happens when we :

  1. Copy and paste the XML noted above unto the XML field textarea
  2. Find the result element and click on the text element

Analysis

Here is the generated Xpath:

/event[@name=”sql_batch_completed”]/data[7]/text/text()

 

Interpretation

  1. Parse using event ( /event )
  2. Look for the attribute name matching sql_batch_completed
  3. Transverse to the 7th data element
  4. Find the text element within the the 7th element and return the text portion of that element

 

Summary

XMLToolBox is easy to use and capable.

Unfortunately, it lacks flexibility because it is based on the position of elements.

If the schema changes a bit, the XPath might return the wrong element as it would refer to the original position.

 

Extended Events – Data Analysis – XML Indexes

Background

Once one starts looking at Extended Events and realize that data is stored in XML, one will likely think will it be beneficial to index the collected XML column.

 

 

Data Model

Image

 

Code

Steps

The basic steps is that we use sys.fn_xe_file_target_read_file to read the XML file and place it in the eventStaging table.

We then use XPath to parse data from the eventStaging table into the event table.

 

Load Data From Extended Event File Into Staging Table

Code



	truncate table [extendedEvent].[eventStaging];

	insert into [extendedEvent].[eventStaging] WITH (TABLOCK)
	(
		  [objectName]	
		, [eventData]	
	)
	SELECT
 
		  [objectName] = tblFNXE.[object_name]
		, [eventData] = cast(tblFNXE.event_data as xml)
 
	FROM sys.fn_xe_file_target_read_file
		(

				case
				when (@folderXEL like '%xel%') then @folderXEL
				else @folderXEL + '' + '*.xel'
				end

			, case
					when (@folderXEM is null) then null
					when (@folderXEM like '%xe%') then @folderXEM
					else isNull(@folderXEM, @folderXEL) + '' + '*.xem'
				end	

			, null

			, null

		) tblFNXE

Load Data From Staging Table into DB Column Table

Code




select top ( 
				  isNull(@maxNumberofRecords, 1E10)
			   )
 
			  [objectName] = isNull(cte.[objectName], '')
 
			, [eventData] = cast(cte.eventData as xml)
			--, [XMLFragment] = [event].[node].query('.')
 
 
			--collect system time
			, [systemTSAsUTC]
				= 	(
						[event].[node].value
							(
								'(action[@name="collect_system_time"])[1]'
								, 'datetime'
							)
					)

			-- collect system time to locale time
			, [systemTSAsLocale] 
				 = dateadd
					(
						  minute
						, @timeDifferenceBetweenUTCAndSystemTimeInMinutes
						, (
							[event].[node].value
							(
									'(action[@name="collect_system_time"])[1]'
								, 'datetime'
							)
						)
					)

			--is system
			, [isSystem] 
				= case 
						[event].[node].value
						(	
							  '(action[@name="is_system"])[1]'
							, 'char(10)'
						)
							when 'true' then 'Y'
							else 'N'
				end
				
			--session ID
			, [sessionID] 
				= [event].[node].value
				  (
					  '(action[@name="session_id"])[1]'
					, 'int'
				  )

			-- database name
			, [dbname] 
				= [event].[node].value
				  (
					  '(action[@name="database_name"])[1]'
					, 'sysname'
				  )
 
			-- client Host Name
			, [clientHostName] 
				= [event].[node].value
				  (
					  '(action[@name="client_hostname"])[1]'
					, 'sysname'
				  )
 
			-- username
			, [username] 
				= [event].[node].value
				  (
					  '(action[@name="session_server_principal_name"])[1]'
					, 'sysname'
				  )

			-- client App Name
			, [clientAppName] 
				= [event].[node].value
				  (
					  '(action[@name="client_app_name"])[1]'
					, 'sysname'
				  )
 
			-- SQL Text
			, [sqlText] 
				= [event].[node].value
				  (
					  '(action[@name="sql_text"])[1]'
					, 'nvarchar(max)'
				  )

			-- Result
			, [result]
				= [event].[node].value
				  (
					  '(data[@name="result"]/text/text())[1]'
					, 'sysname'
				  )

			-- Error Number
			, [errorNumber]
				= [event].[node].value
				  (
					  '(data[@name="error_number"])[1]'
					, 'int'
				  )

			-- severity
			, [severity]
				= [event].[node].value
				  (
					  '(data[@name="severity"])[1]'
					, 'int'
				  )
 
			-- Message
			, [message] 
				= [event].[node].value
				  (
					  '(data[@name="message"])[1]'
					, 'nvarchar(max)'
				  )


 			, [attachActivityID]
				= [event].[node].value
				  (
					  '(event/action[@name="attach_activity_id"]/value)[1]'
					, 'varchar(50)'
				  )


			--duration
			, [duration] 
				= [event].[node].value
				  (
					  '(data[@name="duration"]/value/text())[1]'
					, 'bigint'
				  )

			--cputime
			, [cputime] 
				= [event].[node].value
				  (
					  '(data[@name="cpu_time"]/value/text())[1]'
					, 'bigint'
				  )
	from   [extendedEvent].[eventStaging] cte
 
	cross apply cte.eventData.nodes(N'//event') event(node)

Benchmark

XML Indexes

Statistics I/O & Timing

Image

Trial #1

Trial #2

Trial #3

Tabulate

 

Trial# Step IO Stats Time Taken
#1  
Import data from xml file into staging table  182 secs.
 Table ‘xml_index_nodes_373576369_256000’. Scan count 0, logical reads 24969927, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
 Table ‘Worktable’. Scan count 3, logical reads 268066, physical reads 0, read-ahead reads 0, lob logical reads 143904, lob physical reads 0, lob read-ahead reads 5.
 Table ‘eventStaging’. Scan count 0, logical reads 167819, physical reads 0, read-ahead reads 0, lob logical reads 4, lob physical reads 0, lob read-ahead reads 0.
Copy Data from staging table to actual table  207 secs.
 Table ‘eventFile’. Scan count 0, logical reads 72752, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
 Table ‘event’. Scan count 0, logical reads 420862, physical reads 0, read-ahead reads 0, lob logical reads 1, lob physical reads 0, lob read-ahead reads 0.
 Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 3400, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
 Table ‘xml_index_nodes_373576369_256000’. Scan count 3707011, logical reads 15613316, physical reads 0, read-ahead reads 0, lob logical reads 1, lob physical reads 0, lob read-ahead reads 0.
 Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
 Table ‘eventStaging’. Scan count 0, logical reads 109128, physical reads 0, read-ahead reads 0, lob logical reads 3, lob physical reads 0, lob read-ahead reads 2.
#2  
Import data from xml file into staging table  169 secs.
Table ‘xml_index_nodes_373576369_256000’. Scan count 0, logical reads 24969927, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 3, logical reads 268066, physical reads 0, read-ahead reads 0, lob logical reads 143904, lob physical reads 0, lob read-ahead reads 5.
Table ‘eventStaging’. Scan count 0, logical reads 167819, physical reads 0, read-ahead reads 0, lob logical reads 4, lob physical reads 0, lob read-ahead reads 0.
Copy Data from staging table to actual table  196 secs.
 Table ‘eventFile’. Scan count 0, logical reads 72752, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob
Table ‘event’. Scan count 0, logical reads 420862, physical reads 0, read-ahead reads 0, lob logical reads 1, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 3400, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘xml_index_nodes_373576369_256000’. Scan count 3707011, logical reads 15613315, physical reads 0, read-ahead reads 0, lob logical reads 1, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
 Table ‘eventStaging’. Scan count 0, logical reads 109128, physical reads 0, read-ahead reads 0, lob logical reads 3, lob physical reads 0, lob read-ahead reads 2.
#3  
Import data from xml file into staging table  169 secs.
Table ‘xml_index_nodes_373576369_256000’. Scan count 0, logical reads 24969927, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 3, logical reads 268066, physical reads 0, read-ahead reads 0, lob logical reads 143904, lob physical reads 0, lob read-ahead reads 5.
Table ‘eventStaging’. Scan count 0, logical reads 167819, physical reads 0, read-ahead reads 0, lob logical reads 4, lob physical reads 0, lob read-ahead reads 0.
Copy Data from staging table to actual table  199 secs.
Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘eventFile’. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘event’. Scan count 0, logical reads 428556, physical reads 0, read-ahead reads 0, lob logical reads 1, lob physical reads 0, lob read-ahead reads 0.
Table ‘xml_index_nodes_373576369_256000’. Scan count 3707011, logical reads 15613333, physical reads 0, read-ahead reads 0, lob logical reads 1, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
 Table ‘eventStaging’. Scan count 1, logical reads 12130, physical reads 0, read-ahead reads 0, lob logical reads 3, lob physical reads 0, lob read-ahead reads 2.

 

 

Query Plan

Insert Data from Extended Event Into Staging DB

Image

Explanation
  1. Maintaining XML Indexes is most expensive
    • Clustered Index Insert (xml_index_nodes_*)
  2. Table Spools
    • Reading File from XML File into staging table
    • Prepare data in preparation for XML Index maintenance

 

No XML Indexes

Image

Trial #1

Trial #2

Trial #3

Tabulate

 

Trial# Step IO Stats Time Taken
#1  
Import data from xml file into staging table  41 secs.
Table ‘eventStaging’. Scan count 0, logical reads 167819, physical reads 0, read-ahead reads 0, lob logical reads 1, lob physical reads 0, lob read-ahead reads 0.
 Table ‘Worktable’. Scan count 1, logical reads 74512, physical reads 0, read-ahead reads 0, lob logical reads 143904, lob physical reads 0, lob read-ahead reads 5.
Copy Data from staging table to actual table  178 secs.
 Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
 Table ‘eventFile’. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘event’. Scan count 0, logical reads 428556, physical reads 0, read-ahead reads 0, lob logical reads 1, lob physical reads 0, lob read-ahead reads 0.
Table ‘eventStaging’. Scan count 1, logical reads 12130, physical reads 0, read-ahead reads 0, lob logical reads 77, lob physical reads 0, lob read-ahead reads 2.
#2  
Import data from xml file into staging table  19 secs.
Table ‘eventStaging’. Scan count 0, logical reads 167819, physical reads 0, read-ahead reads 0, lob logical reads 1, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 1, logical reads 74512, physical reads 0, read-ahead reads 0, lob logical reads 143904, lob physical reads 0, lob read-ahead reads 5.
Copy Data from staging table to actual table  137 secs.
Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘eventFile’. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘event’. Scan count 0, logical reads 428556, physical reads 0, read-ahead reads 0, lob logical reads 1, lob physical reads 0, lob read-ahead reads 0.
Table ‘eventStaging’. Scan count 1, logical reads 12130, physical reads 0, read-ahead reads 0, lob logical reads 77, lob physical reads 0, lob read-ahead reads 2.
#3  
Import data from xml file into staging table  35 secs.
Table ‘eventStaging’. Scan count 0, logical reads 167819, physical reads 0, read-ahead reads 0, lob logical reads 1, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 1, logical reads 74511, physical reads 0, read-ahead reads 0, lob logical reads 143904, lob physical reads 0, lob read-ahead reads 5.
Copy Data from staging table to actual table  115 secs.
Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘eventFile’. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘event’. Scan count 0, logical reads 428556, physical reads 0, read-ahead reads 0, lob logical reads 1, lob physical reads 0, lob read-ahead reads 0.
Table ‘eventStaging’. Scan count 1, logical reads 12130, physical reads 0, read-ahead reads 0, lob logical reads 77, lob physical reads 0, lob read-ahead reads 2.

 

 

 

Summary

Having XML Indexes on the staging table resulted in much more IO.

We ran two trials and timed 182 and 169 seconds.

Without indexes, our timing was 41 and 19 seconds.

Querying the XML Column was only slightly more performant with Indexes.