2008 (R2), 2012, 2014 Extended events (RML, Performance, Wait Analysis)
책 구매는 교보문고에서 sqltag 를 검색 후 찾으시면 됩니다.
PC
http://www.kyobobook.co.kr/product/detailViewKor.laf?ejkGb=KOR&mallGb=KOR&barcode=9791195328307&orderClick=LAG&Kc=
Mobile
http://m.kyobobook.com/showcase/book/KOR/9791195328307?orderClick=mX1
SQL Server 2012 버전 지원
sqltag_extended_events_2012_v3.zip
이번 2012 버전에서는 매뉴얼을 좀 강화 했습니다. 2012 프로젝트 파일로 되어 있습니다.
매뉴얼은 프로젝트 파일에 같이 포함 했습니다. 혹시 써보시고 개선사항이 있으면 꼭 알려주세요~
2012 버전은 wait 관련 이벤트를 제외하고 모두 us 로 변경되었습니다.
SQL Server 2014 prepare 쿼리 버전
Extended Events 를 이용한 SQL Server 성능 모니터링
아래 프로그램은 개인사용자나 회사에서 완전히 무료 입니다.
소스 수정은 할 수 없으며, 소스 수정이 필요한 부분은 리플 주시면 수정해 드리겠습니다.
현재는 procedure 나 prepared 쿼리의 성능만 나옵니다. 결과중 함수가 사용되면 함수의 성능은 체크되지 않습니다.
(좋은 솔루션으로 계속 발전시키기 위해)
본 성능 모니터링 솔루션은 SQLTAG Book 2 의 Extended Events 의 예제 프로그램으로 개발되었습니다.
Extended Events의 자세한 개념과 사용방법은 책(출판사 SQLTAG)을 통해 학습하시면 좋을듯 합니다. (책은 2014년 2분기 중으로 발간 됩니다.)
작성자
도움 주신분들 (순서없음) : 김상일(엔트리브소프트), 박숙봉(마이크로소프트), 이덕현(Naver Business Platform)
분석을 위한 시스템 최소 요구사항
SQL Server 2012 Express
Excel 2013 Pro 이상
분석가능 서버
SQL Server 2008 (2008 버전의 파일 다운로드, 아래 있어요)
SQL Server 2008 R2 (2008 버전 파일 다운로드, 아래 있어요)
SQL Server 2012 (2012 버전의 경우, 상단의 2012버전의 zip 파일을 다운받아 사용하세요)
SQL Server 2014 (2012 버전으로 동작합니다.)
성능 영향도
1만 BatchRequests/Sec 에서 성능상 거의 영향도가 없었습니다.
몇 몇 옵션은 수정이 필요할 수 있습니다.
대상 서버의 파일은 6GB 이상의 HDD 저장공간이 필요합니다. (50MB 파일 100개 Rollover 함)
수정해야 할 리스트 (민석이 나중에 작업할 것)
* column 이름 및 전체적인 이름
* 메모리 파티션 모드 추가 할 것(20코어 이상 서버에서)
* 코어 파티션 모드 추가 할 것 (40코어 이상 서버에서)
수정 히스토리
20140326
1. 쿼리 검수를 위한 몇몇 조건절 삭제
2. plan_handle action 삭제
3. max_dispatch_latency = 1 초에서 10초로 늘임
20140327
1. opcode end filter 추가
2. 대상 테이블 이름 변경
3. 대상 target 이름 변경
20140331
1. 쿼리 검수를 위한 몇몇 조건절 삭제
2. 분석을 위한 쿼리에 설명 추가
후원
도움이 필요한 사람에게 조금씩 기부하시고 알려주세요~
수정할 사항을 알려주세요~
<RML ReadTrace, 쿼리별 요청수, 쿼리별 cpu 사용량, 쿼리별 실행시간, 쿼리별 페이지 읽기수, 쿼리별 페이지 쓰기수>
<쿼리 요청수를 제외한 CPU (가로축), Duration (세로축), Page Reads (원의 크기)>
<페이지 읽기가 많은 쿼리를 해당 쿼리의 쿼리 요청수 및 cpu, duration, write 의 연관관계를 볼 수 있음>
<checksum_query_mod 를 위에서 확인 한 후 시간별 다른 쿼리와 리소스 사용율을 검사 할 수 있음, 분산을 알수 있음>
<쿼리를 클릭하면 쿼리별 대기를 확인 할 수 있고, 대기타입을 클릭하면 영향받은 쿼리를 확인 할 수 있음>
1. 테이블 이름으로 로그데이터를 넣을것 sqltag_baseline_01_b_2008
1) ssms > 파일 > 열기 > 확장 이벤트 파일 병합
2) ssms > 확장 이벤트 > 내보내기 > 테이블 (sqltag_baseline_01_b_2008)
3) 해당 데이터베이스에 아래 view 생성
2. Excel 의 데이터 Source 수정 할 것 (Sheet1 에서)
3. PowerView 탭> 새로 고침 > 모두 새로 고침
4. PowerView 오른쪽 필터 탭에서 적절히 필터 조정
sqltag_baseline_01_b_2008.sql
Excel 오른쪽에 있는 필터를 모두 uncheck 하고 봐야 한다.
xe_view_final.xlsx
-- 채팅 로그 --
XeventExcel 은 프러덕션 서버에 만들필요 없습니다.
그냥 XEvent 만 폴더 맞추어서 로그를 남기구요
그 로그폴더 전체를 압축해서 분석할 서버로 가져가고
분석할 서버에는 2012 가 깔려있어야 합니다.
거기에 XEventExcel 데이터베이스가 필요합니다.
해당 데이터베이스에서
XEvent Log 를 SSMS 메뉴를 이용해 로딩 합니다.
로딩되면 Exevent 탭에서 내보내기 테이블을 선택하고
테이블 이름을 블라블라에 넣습니다. (view 의 원본 테이블)
그런다음 view 를 생성 합니다.
Excel 을 열고 Data 탭에서 속성을 수정 합니다.
저랑 같은 이름의 커넥션 속성이 아닐꺼니깐요
밀어넣은 데이터베이스의 커넥션 속성으로 변경 합니다.
그런 후 powerview 탭에서 모두 새로고침
끝!
다음 분석은 로그를 테이블에 밀어넣기 후 바로 새로고침만 하면 분석이 됩니다.
-- TS 사례 소개 1 --
성능트라블슈팅 의뢰내용
특정시간마다 한번씩 쿼리가 25초 이상의 응답시간을 보입니다.
Query 의 Reads (메모리 페이지 요청수) 는 10~20개 정도인데, 도저히 어떤 이유로 이렇게 오래 걸리는지 모르겠습니다.
의뢰 고객이 느린 쿼리를 발견한 방법
SQL Server 2008 (R2) DBMS에 Profiler를 통해 2초 이상 응답이 걸리는 쿼리에 대해 모니터링 중이였음
결과에는 25초 이상의 응답시간을 보이는 쿼리가 가끔 찍히고 있음 (4시간 ~ 5시간에 한번씩)
문제의 해결
Day 1
1. DBA가 흔히 하는 sysprocess 를 수차례 조회 해보니 가끔 수십ms의 응답을 보이는 쿼리가 있는데 logwrite (로그를 기록) 대기가 보이는 정도 였음
2. ldf (로그파일) 이 자동 확장되는 환경이였고 수 GB 수준으로 커져있음 (데이터는 수백메가 수준 이였음)
3. ldf 를 비우고 다시 만들어서 물리적 로그체인 갯수를 줄여 로그를 더 잘 쓸 수 있게 처리함
4. 다음날 같은 현상 또 발생
5. Trace 파일에는 왜 느렸는지는 안 나오니까요, 그리고 그 프로시저를 다시 동작시키면 수 ms 만에 동작이 완료 됩니다. 이제부터 사람이 미칩니다.
Day 2
1. 개발한 Extended Events 를 24Hour * 7Day로 동작시킴
2. 이벤트 분석 결과 (그림 1) 한번씩 느려지는 이유는 TraceWrite 라는 Wait Type 으로 원격서버에서 GUI 로 동작시킨 Profiler가 문제의 원인 이였음
3. 원격 Profiler 제거 후 한번씩 쿼리가 22초 이상 걸리던 현상이 없어짐
프로파일링을 원격에서 GUI 로 걸 경우 Block 현상이 발생 할 수 있습니다. (Profiler 는 Sync 방식으로 로그를 씁니다. 반면 Extended Events 의 파일 대상은 ASync 입니다.)
문제의 고찰
Waitstats 을 주기별로 모아 통계를 봤을때 위 상황에서 문제를 찾기 매우 힘듭니다. (현재 MSSQL Baseline Monitoring Tool)
반면, Extended Events 는 정확하게 언제 무슨원인으로 어떤 쿼리가 느려졌는지 원인을 찾을 수 있었습니다.
Extended Events를 상시 WebServer군 별로 걸어놓고 문제 발생시 Log가 사라지기 전까지만 (계속 Rollover 함) 해당 로그를 Copy 해두면
시간이 지난 후에도 문제의 원인을 정확하게 팩트와 숫자로 증명할 수 있습니다.
이번 사례는 index 억세스패턴과 같은 초보적인 쿼리지연이 아니라 원인 미상으로 종결될뻔 했는데
정확하게 숫자로 증명한 것이지요
장애가 지나가고 로그가 없을때 DBA 는 참 힘들어요 소설 쓰느라....
(그림 1)
1. 그림의 가장 상단은 쿼리 타입별 요청 수 입니다. (요청수의 특별한 변화는 없음)
2. 그림의 좌측은 가장 상단의 쿼리요청수와 대응되는 그래프로, 특정시간 대부분의 쿼리가 응답이 느려진것을 볼 수 있습니다. (중앙 좌측 그래프에서 특정시간에만 그래프가 매우 높음)
3. 중앙 우측그림은 해상시간의 wiat type 입니다. 노란색은 TRACEWRITE 대기 입니다.
4. 상세 근거 데이터는 (그림 2) 를 살펴 보세요
(그림 2)
1. USP_MercenaryInfoWinAddition 이라는 프로시저의 총 수행시간이 22초임
2. 수행의 대기는 TRACEWRITE 대기가 2012 mS * 10개 나옴 (20초)
3. WriteLog 17ms 걸림
4. 실제 쿼리구문(sp_statement_completed) 는 17ms 만에 끝났지만, module_end 는 (전체 수행시간은) 22초가 넘음
5. 다른 쿼리도 조사했을때 같은 현상임
-- TS 사례 소개 2 --
성능트라블슈팅 의뢰내용
우리는 BatchRequests/Sec 가 2만 이상이며, Storage Server 를 쓰고 있으며 코어는 24개에 메모리는 64GB인 SQL Server 를 가지고 있습니다. 전체적으로 성능 점검을 받고 싶습니다.
고객 시스템 상황
문제의 해결
sysprocess 를 쿼리 해봤을때 액티브 세션이 10여개에서 20개 내외로 일을 좀 하는 서버 입니다. Extended Evensts 를 걸었습니다.
빨간선이 Extended Events 를 Start 한 시점 입니다. 별 문제가 없었으며, 무사히 데이터 수집을 완료 했으며 다음과 같은 결과를 얻었습니다.
아래 연두색은 sp_procedure_params_rowset 이라는 시스템 프로시저이며, 파라메터를 명시적으로 선언하지 않으면 내부적으로 호출되는 프로시저 입니다. 해당 프로시저가 호출되지 않도록 어플리케이션 콜 형태를 바꾸어 주기로 했습니다.
결과는 나중에 언급 하도록 하겠습니다.
XEView (Excel) 로 CPU 를 가장 많이 소모하고 Duration 도 가장 많이 소모되는 문제의 원인 쿼리가 메터데이터 쿼리라는 것을 대단히 직관적으로 분석할 수 있었습니다.
문제의 고찰
프로시저 호출할때 변수들 꼭 바인딩해서 쓰세요~
수정내용
1. sp_procedure_params_rowset 제거
2. 클러스터 인덱스 1개 튜닝
3. -k 를 이용한 checkpoint i/o 제한
4. tempdb 튜닝 (24개 -> 4개)
5. log file 1개로 수정
6. 테이블 변수 -> 템프 테이블로 변경 (통계 사용 못하는 쿼리)
7. traceflag 추가
8. maxdop 1 변경
9. tempdb 드라이브 변경
10. 함수 사용 문제점 알림
결과
cpu 사용량 : 50% -> 14%
page read : 1/10 (배치를 빼서 read 가 준게 아니라, 클러스터 인덱스 조정을 이용해 튜닝함)
batchRequests/Sec : 1/10 (메터 쿼리 제거 및 유효하지 않는 쿼리 제거)
아래 그래프는 위 before 결과보다 더 Peak 시간에 측정한 after 결과 입니다.
SQLTAG 의 온라인 컨설팅은 언제나 무료 입니다.
기술이 없어서 무료냐구요? 아닙니다. 기술은 전세계에서 최고라고 생각합니다. (쿨럭~)