info@techdevops.com
|
437-991-3573
|
Data Engineering Services
|
TechDevOps.com
|
| | | |
|
Experts in Microsoft SQL Server on Windows, Linux, Containers | Clusters, Always On, FCI | Migrations, Cloud, Performance
|
| | | |
|
Using Extended Events to capture Stored Procedure calls, Log & Extract Duration Buckets of % and/or #
by BF (Principal Consultant; Architecture; Engineering)
2018-03-10
Extended Events:
CREATE EVENT SESSION XEvent_All ON SERVER
ADD EVENT sqlserver.rpc_completed
(
ACTION (
sqlserver.database_id,
sqlserver.session_id,
sqlserver.client_app_name,
sqlserver.client_hostname,
sqlserver.username,
sqlserver.client_hostname,
sqlserver.sql_text,
sqlserver.tsql_stack
)
WHERE
[statement] not like N'%exec sp_reset_connection%'
--AND
--[duration] > 250000 --Greater that 1/4 sec
)
ADD TARGET package0.asynchronous_file_target
(
SET FILENAME = 'I:\XEventsAllSQL\XEvent.xet', metadatafile = 'I:\XEventsAllSQL\XEvent.xem'
)
WITH (MAX_DISPATCH_LATENCY=300SECONDS) --300 sec
ALTER EVENT SESSION XEvent_All ON SERVER STATE = START
WAITFOR DELAY '00:05:00'; --Allow flush buffer cache to target file
ALTER EVENT SESSION XEvent_All ON SERVER STATE = STOP
SET QUOTED_IDENTIFIER OFF
Insert into OPS.dbo.LOG_ALL_SQL
([DB_Name],[Client_App_Name],[Client_HostName],[End_Time],[Duration],[CPU],[Logical_Reads],[Writes],[Row_Count],[RPC])
SELECT
[db_name] = DB_NAME(x.value('(event/action[@name="database_id"])[1]', 'INT'))
, client_app_name = x.value('(event/action[@name="client_app_name"])[1]', 'NVARCHAR(100)')
, client_hostname = x.value('(event/action[@name="client_hostname"])[1]', 'NVARCHAR(100)')
, end_time = dateadd(hh,-4,x.value('(event/@timestamp)[1]', 'DATETIME'))
, duration_ms = x.value('(event/data[@name="duration"])[1]', 'INT') --/ 1000 --miliseconds
, cputime_ms = x.value('(event/data[@name="cpu_time"])[1]', 'INT') --/ 1000 --miliseconds
, logical_reads = x.value('(event/data[@name="logical_reads"])[1]', 'INT')
, writes = x.value('(event/data[@name="writes"])[1]', 'INT')
, row_count = x.value('(event/data[@name="row_count"])[1]', 'INT')
, rpc = x.value('(event/data[@name="statement"])[1]', 'NVARCHAR(MAX)')
FROM (
SELECT x = CAST(event_data AS XML).query('.')
FROM sys.fn_xe_file_target_read_file('I:\XEventsAllSQL\XEvent*.xet','I:\XEventsAllSQL\XEvent*.xem', NULL, NULL)
) t
--order by duration_ms desc
SET QUOTED_IDENTIFIER ON
DROP EVENT SESSION XEvent_All ON SERVER
Create Table #tmpdir (directoryinfo varchar(500))
Insert into #tmpdir exec master.dbo.xp_cmdshell 'dir I:\XEventsAllSQL\'
If exists (Select 1 from #tmpdir where directoryinfo like '%xet%')
Begin
exec master..xp_cmdshell 'Del /Q I:\XEventsAllSQL\*.*';
End
Drop Table #tmpdir
T-SQL:
Logging Table:
/****** Object: Table [dbo].[LOG_All_SQL] Script Date: 3/10/2018 2:43:05 PM ******/
SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
CREATE TABLE [dbo].[LOG_All_SQL](
[LogID] [int] IDENTITY(1,1) NOT NULL,
[DB_Name] [varchar](50) NULL,
[Client_App_Name] [varchar](150) NULL,
[Client_HostName] [varchar](150) NULL,
[End_Time] [datetime] NULL,
[Duration] [int] NULL,
[CPU] [int] NULL,
[Logical_Reads] [int] NULL,
[Writes] [int] NULL,
[Row_Count] [int] NULL,
[RPC] [varchar](max) NULL,
[InsertedDate] [datetime] NULL,
CONSTRAINT [PK_LOG_All_SQL] PRIMARY KEY CLUSTERED
(
[LogID] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY]
GO
ALTER TABLE [dbo].[LOG_All_SQL] ADD CONSTRAINT [DF_LOG_All_SQL_InsertedDate] DEFAULT (getdate()) FOR [InsertedDate]
GO
T-SQL Report:
/****** Object: StoredProcedure [dbo].[Admin_All_SQL_v3] Script Date: 3/10/2018 2:42:05 PM ******/
SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
Create Procedure [dbo].[Admin_All_SQL]
@NumHours int = -1,
@Format int = 2 --0 = %, 1= #, 2 = Both
as
set nocount on
SELECT
'A1-VM-SQL-NYC' as 'Server',
datepart(yy,InsertedDate) as 'Year', datepart(mm,InsertedDate) as 'Month', datepart(dd,InsertedDate) as 'Day', datepart(hh,InsertedDate) as 'Hour', convert(varchar(25),[DB_NAME]) as 'DB_Name', convert(varchar(40),Client_App_name) as 'Client_App_name',
SUM(CASE WHEN duration > 0 AND duration <= 100 THEN 1 else '' end) as '0µs-100µs',
SUM(CASE WHEN duration > 100 AND duration <= 250 THEN 1 else '' end) as '100µs-250µs',
SUM(CASE WHEN duration > 250 AND duration <= 500 THEN 1 else '' end) as '250µs-500µs',
SUM(CASE WHEN duration > 500 AND duration <= 1000 THEN 1 else '' end) as '500µs-1000µs',
SUM(CASE WHEN duration > 1000 AND duration <= 100000 THEN 1 else '' end) as '0ms-100ms',
SUM(CASE WHEN duration > 100000 AND duration <= 250000 THEN 1 else '' end) as '100ms-250ms',
SUM(CASE WHEN duration > 250000 AND duration <= 500000 THEN 1 else '' end) as '250ms-500ms',
SUM(CASE WHEN duration > 500000 AND duration <= 1000000 THEN 1 else '' end) as '500ms-1000ms',
SUM(CASE WHEN duration > 1000000 THEN 1 else '' end) as '>1000ms',
count(*) AS 'TotalSPCalls'
INTO #LOG_ALL_SQL_VM11
from [A1-VM-SQL-NYC].ops.dbo.LOG_ALL_SQL with (nolock)
where (Client_App_Name not like '%Agent%' and Client_App_Name not like '%Studio%' and Client_App_Name not like '%-VM-%'
and Client_App_Name <> '.Net SqlClient Data Provider' and Client_App_name <> 'Microsoft ® Windows Script Host' and Client_App_Name <> 'Microsoft SQL Server')
and InsertedDate > DATEADD(HOUR, @NumHours, GETDATE())
group by
datepart(yy,InsertedDate), datepart(mm,InsertedDate), datepart(dd,InsertedDate), datepart(hh,InsertedDate), [DB_Name], Client_App_name
order by
datepart(yy,InsertedDate), datepart(mm,InsertedDate), datepart(dd,InsertedDate), datepart(hh,InsertedDate), [DB_Name], Client_App_name
If @Format = 0 or @Format = 2
Begin
SELECT
[Server], [Year], [Month], [Day], [Hour], [DB_Name], [Client_App_Name],
(convert(varchar(10),convert(decimal(18,2),l.[0µs-100µs]*100/ convert(decimal(18,2),l.TotalSPCalls)))) + ' %' as '0µs-100µs',
(convert(varchar(10),convert(decimal(18,2),l.[100µs-250µs]*100/ convert(decimal(18,2),l.TotalSPCalls)))) + ' %' as '100µs-250µs',
(convert(varchar(10),convert(decimal(18,2),l.[250µs-500µs]*100/ convert(decimal(18,2),l.TotalSPCalls)))) + ' %' as '250µs-500µs',
(convert(varchar(10),convert(decimal(18,2),l.[500µs-1000µs]*100/ convert(decimal(18,2),l.TotalSPCalls)))) + ' %' as '500µs-1000µs',
(convert(varchar(10),convert(decimal(18,2),l.[0ms-100ms]*100/ convert(decimal(18,2),l.TotalSPCalls)))) + ' %' as '0ms-100ms',
(convert(varchar(10),convert(decimal(18,2),l.[100ms-250ms]*100/ convert(decimal(18,2),l.TotalSPCalls)))) + ' %' as '100ms-250ms',
(convert(varchar(10),convert(decimal(18,2),l.[250ms-500ms]*100/ convert(decimal(18,2),l.TotalSPCalls)))) + ' %' as '250ms-500ms',
(convert(varchar(10),convert(decimal(18,2),l.[500ms-1000ms]*100/ convert(decimal(18,2),l.TotalSPCalls)))) + ' %' as '500ms-1000ms',
(convert(varchar(10),convert(decimal(18,2),l.[500ms-1000ms]*100/ convert(decimal(18,2),l.TotalSPCalls)))) + ' %' as '>1000ms'
FROM #LOG_ALL_SQL_VM11 l
End
If @Format = 1 or @Format = 2
Begin
Select * from #LOG_ALL_SQL_VM11
End
Drop Table #LOG_ALL_SQL_VM11
|
|
|
|
|
|
|
|
|
|