데이터베이스 개발자 Tip & 강좌

SQLER의 개발자들이 만들어가는 데이터베이스 사용자 Tip & 강좌 게시판입니다. SQL서버, Oracle, MySQL 등 여러 클라우드/오픈소스 기반 데이터베이스 개발 및 운영 관련 팁과 쿼리 노하우를 이곳에서 가장 먼저 접하실 수 있습니다. 많은 도움 되시길 바랍니다.

성능분석 10탄 – 쿼리 실행 대기 시간 분석(xevent)

 

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

 

쿼리 또는 저장프로시저에 대한 가장 좋은 대기 유형 정보는 실행 시간과 IO 정보이다. 이 정보는 확장이벤트(XEvent)를 사용하여 모니터링을 할 수 있다.

다음 스크립트는 Sqlos.wait_info 정보를 캡처하고 특정 실행 세션(SPID)에 대한 확장 이벤트 세션을 필터링하는 확장이벤트 세션 생성 작업이다.

 

create event session session_waits on server

add event sqlos.wait_info

(WHERE sqlserver.session_id= 54/*execution_spid*/ and duration>0)

, add event sqlos.wait_info_external

(WHERE sqlserver.session_id = 54/*execution_spid*/ and duration>0)

add target package0.asynchronous_file_target

(SET filename=N'c:\temp\wait_stats.xel', metadatafile=N'c:\temp\wait_stats.xem');

go

 

alter event session session_waits on server state= start;

go

 

 

 

이벤트 세션을 시작하고 분석할 쿼리나 프로시저를 실행 한다. 그 후 확장 이벤트 서비스를 중지하고 캡처된 데이터를 확인 한다.

alter event session session_waits on server state= stop;

go

 

with x as (

select cast(event_data as xml) as xevent

from sys.fn_xe_file_target_read_file

('c:\temp\wait_stats*.xel', 'c:\temp\wait_stats*.xem', null, null))

select * from x;

go

 

 

이벤트 세션을 중단하고 캡처된 이벤트를 클릭하면 XML 정보를 확인 할 수 있다.

 

4밀리세컨드의 IX 잠금이 발생하였다. 그리고 작업이 재개 될 때까지 또 다른 2밀리세컨드 보냈다. 다음 스크립트를 이용하ㅕㅁㄴ XML 데이터를 테이블 형식으로 확인할 수 있다.

with x as (

select cast(event_data as xml) as xevent

from sys.fn_xe_file_target_read_file

('c:\temp\wait_stats*.xel', 'c:\temp\wait_stats*.xem', null, null))

select xevent.value(N'(/event/data[@name="wait_type"]/text)[1]', 'sysname') as wait_type,

    xevent.value(N'(/event/data[@name="duration"]/value)[1]', 'int') as duration,

    xevent.value(N'(/event/data[@name="signal_duration"]/value)[1]', 'int') as signal_duration

from x;

 

다음 스크립트는 XML의 정보를 대기 유형에 따라 집계한 것이다.

with x as (

select cast(event_data as xml) as xevent

from sys.fn_xe_file_target_read_file

('c:\temp\wait_stats*.xel', 'c:\temp\wait_stats*.xem', null, null)),

s as (select xevent.value(N'(/event/data[@name="wait_type"]/text)[1]', 'sysname') as wait_type,

    xevent.value(N'(/event/data[@name="duration"]/value)[1]', 'int') as duration,

    xevent.value(N'(/event/data[@name="signal_duration"]/value)[1]', 'int') as signal_duration

from x)

select wait_type,

    count(*) as count_waits,

    sum(duration) as total__duration,

    sum(signal_duration) as total_signal_duration,

    max(duration) as max_duration,

    max(signal_duration) as max_signal_duration

from s

group by wait_type

order by sum(duration) desc

 

 

이 결과를 바탕으로 쿼리가 실행되는 동안 어떤 일이 있었는지를 확인 할 수 있다. 이 로그를 보면 742번의 WRITELOG가 발생하였으며, 12번의 잠금이 발생, 그리고 2개의 PAGELATCH가 발생하였다.

 

 

[참고자료]

http://rusanu.com/2014/02/24/how-to-analyse-sql-server-performance/

 




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

No. Subject Author Date Views
1950 성능분석 16탄 – 메모리 / CPU 관련 성능 카운터 jevida(강성욱) 2016.10.15 5068
1949 성능분석 15탄 – I/O 관련 성능 카운터 jevida(강성욱) 2016.10.15 4001
1948 성능분석 14탄 – SQL Server 사용 성능 카운터 jevida(강성욱) 2016.10.15 3953
1947 성능분석 13탄 – 누락된 인덱스(missing index) jevida(강성욱) 2016.10.15 2343
1946 성능분석 12탄 – 문제 쿼리 식별 jevida(강성욱) 2016.10.15 2122
1945 성능분석 11탄 – 실행 계획 분석 jevida(강성욱) 2016.10.15 4145
» 성능분석 10탄 – 쿼리 실행 대기 시간 분석(xevent) jevida(강성욱) 2016.10.15 1909
1943 성능분석 9탄 – 쿼리 실행 분석 jevida(강성욱) 2016.10.15 3868
1942 성능분석 8탄 – IO 통계 (DISK 활동 분석) jevida(강성욱) 2016.10.15 1460
1941 성능분석 7탄 – 프로파일러 대기 유형 및 PREEMPTIVE_OS_WRITEFILEGATHER jevida(강성욱) 2016.10.15 1590
1940 성능분석 6탄 – CPU 경합 및 동시성 관련 대기 유형 jevida(강성욱) 2016.10.15 1882
1939 성능분석 5탄 – 메모리 및 네트워크 관련 대기 유형 jevida(강성욱) 2016.10.15 1927
1938 성능분석 4탄 – 디스크 및 IO 관련 대기 유형 jevida(강성욱) 2016.10.15 2066
1937 성능분석 3탄 – 집계 대기 통계 jevida(강성욱) 2016.10.15 1916
1936 성능분석 2탄 – 실행 요청을 기다리는 작업 확인 및 분석 (병렬 처리 대기 확인) jevida(강성욱) 2016.10.15 1352
1935 성능분석 1탄 – 실행 요청을 기다리는 작업 확인 및 분석 jevida(강성욱) 2016.10.15 1980
1934 확장이벤트를 사용하여 데드락 정보 확인 jevida(강성욱) 2016.10.15 1549
1933 확장 이벤트를 사용한 CPU 고부하 쿼리 추적 [1] jevida(강성욱) 2016.10.15 2115
1932 데이터에 대한 이해와 spill in tempdb jevida(강성욱) 2016.10.13 1761
1931 로그 파일이 많으면 왜 안 좋은가 jevida(강성욱) 2016.10.13 2051





XE Login