확장 이벤트를 사용한 CPU 고부하 쿼리 추적

 

  • Version : SQL Server 2005, 2008, 2008R2, 2012

 

 

SQL Server를 운영 할 때 일부 쿼리에서 과도한 자원을 점유하여 성능에 문제를 발생 시킨다. 다음은 CPU를 많이 사용하는 쿼리를 추적 하는 기술에 대해서 알아본다.

 

다음 스크립트를 사용하여 실습용 데이터베이스 및 테이블을 생성한다. 데이터베이스 ID는 사용자마다 다를 수 있다.

CREATE DATABASE production;

GO

 

USE production;

GO

 

CREATE TABLE t1 (c1 INT IDENTITY, c2 UNIQUEIDENTIFIER ROWGUIDCOL DEFAULT NEWID(), c3 CHAR (5000) DEFAULT 'a');

CREATE CLUSTERED INDEX t1_CL ON t1 (c1);

CREATE NONCLUSTERED INDEX t1_NCL ON t1 (c2);

GO

 

SET NOCOUNT ON;

 

INSERT INTO t1 DEFAULT VALUES;

GO 1000

 

--Get the database ID to plug into the event session

SELECT DB_ID ('production');

GO

 

 

확장 이벤트 조건을 정의 할 때 데이터베이스 ID를 지정한다.

IF EXISTS (SELECT * FROM sys.server_event_sessions WHERE name = 'EE_ExpensiveQueries')

    DROP EVENT SESSION EE_ExpensiveQueries ON SERVER;

GO

 

CREATE EVENT SESSION EE_ExpensiveQueries ON SERVER

ADD EVENT sqlserver.sql_statement_completed

(ACTION (sqlserver.sql_text, sqlserver.plan_handle)

WHERE sqlserver.database_id = 14 /*DBID*/ AND CPU_time > 10 /*total ms of CPU time*/)

ADD TARGET package0.asynchronous_file_target

(SET FILENAME = N'C:\SQL_Data\EE_ExpensiveQueries.xel', METADATAFILE = N'C:\SQL_Data\EE_ExpensiveQueries.xem')

WITH (max_dispatch_latency = 1 seconds);

GO

 

 

이벤트 세션을 시작하고 이벤트 조건에 만족하도록 쿼리를 실행 한다.

ALTER EVENT SESSION EE_ExpensiveQueries ON SERVER STATE = START;

GO

 

USE production;

GO

 

SELECT COUNT (*) FROM t1 WHERE c1 > 500;

GO

 

SELECT SUM (c1) FROM t1 WHERE c3 LIKE 'a';

GO

 

ALTER INDEX t1_CL ON t1 REORGANIZE;

GO

 

 

쿼리 실행이 완료 되었으면 캡처 된 쿼리가 있는지 확이 한다. 실습에서는 2개의 쿼리가 캡처 되었다.

USE master;

GO

 

SELECT COUNT (*) FROM sys.fn_xe_file_target_read_file

('C:\SQL_Data\EE_ExpensiveQueries*.xel', 'C:\SQL_Data\EE_ExpensiveQueries*.xem', NULL, NULL);

GO

 

 

 

캡처된 쿼리를 다음의 스크립트를 사용하여 확인 할 수 있다. 결과는 XML로 반환 된다.

SELECT data FROM

(SELECT CONVERT (XML, event_data) AS data FROM sys.fn_xe_file_target_read_file

('C:\SQL_Data\EE_ExpensiveQueries*.xel', 'C:\SQL_Data\EE_ExpensiveQueries*.xem', NULL, NULL)

) entries;

GO

 

 

 

다음 스크립트를 사용하여 XML BLOB 정보를 확인 할 수 있다.

SELECT

data.value (

'(/event[@name=''sql_statement_completed'']/@timestamp)[1]', 'DATETIME') AS [Time],

data.value (

'(/event/data[@name=''cpu'']/value)[1]', 'INT') AS [CPU (ms)],

CONVERT (FLOAT, data.value ('(/event/data[@name=''duration'']/value)[1]', 'BIGINT')) / 1000000

AS [Duration (s)],

data.value (

'(/event/action[@name=''sql_text'']/value)[1]', 'VARCHAR(MAX)') AS [SQL Statement],

SUBSTRING (data.value ('(/event/action[@name=''plan_handle'']/value)[1]', 'VARCHAR(100)'), 0, 100)

AS [Plan Handle]

FROM

(SELECT CONVERT (XML, event_data) AS data FROM sys.fn_xe_file_target_read_file

('C:\SQL_Data\EE_ExpensiveQueries*.xel', 'C:\SQL_Data\EE_ExpensiveQueries*.xem', null, null)

) entries

ORDER BY [Time] DESC;

GO

 

 

 

위의 PlanHandle 값을 사용하여 sys.dm_exec_query_plan DMV에서 쿼리 플랜을 확인 할 수 있다. (Plan handle 값에서 0x를 붙여 사용한다.)

SELECT [query_plan] FROM sys.dm_exec_query_plan (0x06000e00faf5b11e80166a4e0200000001000000000000000000000000000000000000000000000000000000);

GO

 

 

CPU를 많이 사용한 쿼리의 실행 계획을 확인 할 수 있다.

 

 

확장 이벤트를 사용하면 서버에서 발생하는 여러 가지 상황들을 캡처하여 분석 할 수 있다.

 

 

[참고자료]

http://www.sqlskills.com/blogs/paul/tracking-expensive-queries-with-extended-events-in-sql-2008/

 


강성욱 / jevida@naver.com
Microsoft SQL Server MVP
Blog : http://sqlmvp.kr
Facebook : http://facebook.com/sqlmvp

No. Subject Author Date Views
Notice 2023년 1월 - SQLER의 업데이트 강좌 리스트 코난(김대우) 2023.01.02 2134
1946 성능분석 12탄 – 문제 쿼리 식별 jevida(강성욱) 2016.10.15 2236
1945 성능분석 11탄 – 실행 계획 분석 jevida(강성욱) 2016.10.15 4257
1944 성능분석 10탄 – 쿼리 실행 대기 시간 분석(xevent) jevida(강성욱) 2016.10.15 1970
1943 성능분석 9탄 – 쿼리 실행 분석 jevida(강성욱) 2016.10.15 4176
1942 성능분석 8탄 – IO 통계 (DISK 활동 분석) jevida(강성욱) 2016.10.15 1500
1941 성능분석 7탄 – 프로파일러 대기 유형 및 PREEMPTIVE_OS_WRITEFILEGATHER jevida(강성욱) 2016.10.15 1693
1940 성능분석 6탄 – CPU 경합 및 동시성 관련 대기 유형 jevida(강성욱) 2016.10.15 1942
1939 성능분석 5탄 – 메모리 및 네트워크 관련 대기 유형 jevida(강성욱) 2016.10.15 2100
1938 성능분석 4탄 – 디스크 및 IO 관련 대기 유형 jevida(강성욱) 2016.10.15 2243
1937 성능분석 3탄 – 집계 대기 통계 jevida(강성욱) 2016.10.15 1968
1936 성능분석 2탄 – 실행 요청을 기다리는 작업 확인 및 분석 (병렬 처리 대기 확인) jevida(강성욱) 2016.10.15 1415
1935 성능분석 1탄 – 실행 요청을 기다리는 작업 확인 및 분석 jevida(강성욱) 2016.10.15 2062
1934 확장이벤트를 사용하여 데드락 정보 확인 jevida(강성욱) 2016.10.15 1602
» 확장 이벤트를 사용한 CPU 고부하 쿼리 추적 [1] jevida(강성욱) 2016.10.15 2182
1932 데이터에 대한 이해와 spill in tempdb jevida(강성욱) 2016.10.13 1805
1931 로그 파일이 많으면 왜 안 좋은가 jevida(강성욱) 2016.10.13 2104
1930 트랜잭션 백업 실패와 전체 백업 성공 그리고 대처 방안 jevida(강성욱) 2016.10.13 1583
1929 Fast recovery 와 로그 잠금 jevida(강성욱) 2016.10.13 2056
1928 고스트 클린업 jevida(강성욱) 2016.10.13 2307
1927 페이지 분할이 발생 하였을 때 롤백을 하면 어떻게 될까? jevida(강성욱) 2016.10.13 1683





XE Login