SQL Server Scheduling and Yielding 트러블슈팅

 

·         Version : SQL Server

 

SQL Server 다중 스레드및 다중 태스크 시스템으로 SQLOS라고 불리는 자체 스레드 스케줄링 메커니즘을 가지고 있다. SQLOS 대한 내용은 아래 링크를 참조 한다.

·         A new platform layer in SQL Server 2005 to exploit new hardware capabilities and their trends : https://blogs.msdn.microsoft.com/slavao/2005/07/20/platform-layer-for-sql-server

·         Inside the SQL Server 2000 User Mode Scheduler : https://msdn.microsoft.com/library/aa175393.aspx

·         How To Diagnose and Correct Errors 17883, 17884, 17887, and 17888 : https://technet.microsoft.com/en-us/library/cc917684.aspx

 

SQL  Server 소스 코드에는 다중 스레드가 효율적이고 협조적으로 실행되도록 하는 많은 자발적인 Yield포인트(한국어로 번역하기엔 적당한 용어가 없어 양보하는” 정도로 해석할  있다.) 있다. SQL Server작업자 스레드가 자발적으로 양보하지 않으면 동일한 스레드에서 다른 스레드가 실행되지 않을 가능성이 높다스케줄러의 소유자가 60 이내에 결과를 보지 못하고 보류중인 요청(작업) 지연되면 SQL Server 다음과 같이 오류는 발생하지 않지만스케줄러 오류를 기록한다.

2018-03-10 21:16:35.89 Server      ***********************************************

2018-03-10 21:16:35.89 Server      *

2018-03-10 21:16:35.89 Server      * BEGIN STACK DUMP:

2018-03-10 21:16:35.89 Server      *   03/10/18 21:16:35 spid 22548

2018-03-10 21:16:35.89 Server      *

2018-03-10 21:16:35.89 Server      * Non-yielding Scheduler

2018-03-10 21:16:35.89 Server      *

2018-03-10 21:16:35.89 Server      ***********************************************

 

SQL Server 작업자는 4ms(밀리초) 퀀텀 타임으로 동작하지만 현실적으로 스케줄링은 매우 복잡하기 때문에 자발적인 양보를 하기전에 예기치 않게 스케줄이 실행되는 곳이 있을 수도 있다일반적으로 이러한 행동은 thread  실행할 thread 리스트에서  기아상태(굶주린 상태) 되지 않기 때문에 문제가 되지 않는다아래 그림은 스케줄러와 태스크가 어떻게 스케줄링 되는지 나타낸다.

 

다음 순서는 스케줄링이 작동하는 순서이다.

1.       작업이 실행중이면 “Running” 상태

2.       작업이 대기 상태가 되면 CPU 큐에 스케줄을 “Runnable” 등록

3.       작업이 무엇인가(lock, disk I/O ) 기다리고 있을때 그것은 “Suspended” 상태로 등록

4.       일시 중단  작업의 대기가 끝나고 실행할 준비가 되면 Runnable 큐의  부분에 등록

5.       실행중의 thread 자발적인 양보로 Runnable큐의 끝으로 이동한다.

6.       실행중인 스레드가 무엇인가를 기다려야할 경우 스케줄러에서”Suspended” 상태로 전환

7.       실행중의thread 끝나면 실행 가능한 큐의 최상단에  “Running”상태로 thread 등록된다.

 

SQL Server에서는 sys.dm_os_waiting_tasks또는 sys.dm_exec_requests  DMV 사용하여 wait_time, wait_resource등과 같은 대기 관련 정보를 확인할  있다.

SELECT session_id,status,wait_time,wait_type,wait_resource,last_wait_type

FROM sys.dm_exec_requests

WHERE session_id=52

 

 

sys.dm_os_wait_stats 실행하면 신호 대기 시간을 포함하여  대기 유형에 대한 전체 대기 시간을 확인할  있다특히 “signal_wailt_time_ms”라는 열의 값은 스레드가 스케줄러의 “Runnable”상태로 리스트에 머문 시간으로 CPU 올라가서 다시 실행될때 까지 기다린 시간이다.  개별 세션에 대한 신호 대기 시간의 자세한 정보를 확인하려면 XEvent wait_info wait_info_external 활용할  있다아래 링크는 wait_info 이벤트를 사용하여 REDO 대기 시간을 추적하는 방법이다.

·         Troubleshooting REDO queue build-up (data latency issues) on AlwaysOn Readable Secondary Replicas using the WAIT_INFO Extended Event : https://blogs.msdn.microsoft.com/alwaysonpro/2015/01/06/troubleshooting-redo-queue-build-up-data-latency-issues-on-alwayson-readable-secondary-replicas-using-the-wait_info-extended-event/

 

아래 실습을 통해서 신호 대기를 확인할  있다.

1.       실습할 테이블을 tempdb 생성한다.

USE tempdb

CREATE TABLE t1 (c1 int)

 

2.       SQL Server에서 사용할  CPU수를 조정한다. (절대 실서버에서 하지 말것)

EXEC SP_CONFIGURE  'affinity mask',--use only the second CPU of the system

RECONFIGURE WITH OVERRIDE

 

3.       XEvent 생성하고 실행한다.

IF EXISTS(SELECT * FROM sys.server_event_sessions WHERE name LIKE'SignalWaitDemo')

DROP EVENT SESSION [SignalWaitDemo] ON SERVER

GO

CREATE EVENT SESSION [SignalWaitDemo] ON SERVER

ADD EVENT sqlos.wait_info(

    ACTION(sqlos.scheduler_id,sqlserver.database_id,sqlserver.session_id)

    --Capture End event (opcode=1) only

WHERE ([package0].[equal_uint64]([opcode],(1))

--Only capture user sessions (session_id>=50)

AND [package0].[greater_than_equal_uint64]([sqlserver].[session_id],(50))

--You can change duration to bigger value, say, change below 10 ms to 3000ms

AND [duration]>=(10)))

ADD TARGET package0.event_file(SET filename=N'E:\temp\Wait_Info_Demo.xel')

WITH (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=OFF,STARTUP_STATE=OFF)

 

GO

 

 ALTER EVENT SESSION [SignalWaitDemo] ON SERVER STATE=START;

 

4.       Ostress 도구를 사용하여 작업 부하를 시뮬레이션 한다.

 ostress -n1000 -r200 -S. –isignal_wait.sql (쿼리는 아래 박스

SET NOCOUNT ON

USE tempdb

DECLARE @I int=0,@k int=0

 

BEGIN

IF(rand()>0.9)update t1 set c1=c1+10*(rand()-0.5)

DECLARE @document varchar(64); 

SELECT @document = 'Reflectors are vital safety' + 

                   ' components of your bicycle.'; 

DECLARE @j int

SET @j=CHARINDEX('bicycle', @document);

SET @j=CHARINDEX('are', @document);

SET @j=CHARINDEX('vital', @document);

SET @j=CHARINDEX('dd', @document);

SET @j=CHARINDEX('your', @document);

END

 

ostress 실행 중일때 아래 스크립트를 실행하면  실행 가능한 스레드와 일시 중단된 스레드가 많은 것을 확인할  있다결과를 살펴보면 suspended스레드는 runnable 스레드가 스케줄러가 실행되기를 기다리는 동안 UPDATE 잠금을 대기중인 스레드이다.

select * from sys.dm_exec_requests where session_id>50

 

 

위에서 실행중인 XEvent 추적을 멈추고 확인하면 매우  duration세션이 있는 것을 확인할  있다 실행 가능한 대기열에 있었음을   있다.

 


지금까지의 설명은 자원 대기 시간  신호 대기 시간을 확인하는 방법에 대해서 알아보았다이제 스레드가 주어진 스케줄러에서 양보하지 않고 얼마나 오랫동안 실행되었는지 확인하는(비정상  스케줄러방법에 대해서 알아본다응답하지(non-yielding)않은 스케줄러 시간은 스레드가 아무런 양보(yielding)없이 스케줄러를 점유하는 시간을 의미한다따라서 항상 CPU  실행 시간을 의미하는것은 아니다스케줄러를 점유하는 스레드는 다른 어플리케이션이  시점에서 동일한 CPU 사용하는 경우 운영체제에 의해 점유   있다.대부분의 경우 SQL Server 전용으로 운영되기 때문에 이러한 상황은 일반적이지 않다아래 스크립트를 실행하여 yield_count  컬럼에서 yield 횟수를 확인할  있다주기적으로 해당 스크립트를 실행하여 델타값을 산출하였을때  yield_count 변경되지 않으면 누군가  기간동안 스케줄러에서 실행중인 것을   있다 

select yield_count, runnable_tasks_count, * from sys.dm_os_schedulers wherescheduler_id<1024

 

 

 

아래 스크립트는 yield 횟수  관련 정보를 수집하여 저장하는 스크립트이다.

USE <yourdb>

 CREATE TABLE yields

 (runtime datetime, scheduler_id bigint,yield_count bigint,runnable int, session_idint,start_time datetime,command varchar(200),database_id int)

 

 GO  

 

 SET NOCOUNT ON

 WHILE(1=1)

 BEGIN

 INSERT INTO yields

 SELECT getdate() 'runtime', a.scheduler_id, a.yield_count, runnable_tasks_count,session_id,start_time, command,database_id

 FROM sys.dm_os_schedulers a

inner join sys.dm_os_workers b on a.active_worker_address=b.worker_address

left join sys.dm_exec_requests c on c.task_address=b.task_address

--Most system has less than 1024 cores, use this to ignore those HIDDEN schedulers

WHERE a.scheduler_id<1024

 --Monitor it every 5 seconds. you can change it to meet your needs

 WAITFOR DELAY '00:00:05'

 END

 

아래 스크립트는 저장된 yield 정보를 조회한다.

DECLARE scheduler_cur CURSOR 

FOR SELECT scheduler_id from yields group by scheduler_id order by scheduler_id

OPEN scheduler_cur

DECLARE @id bigint

FETCH NEXT  FROM scheduler_cur INTO @id

WHILE (@@FETCH_STATUS=0)

BEGIN

 DECLARE delta_cur CURSOR

 FOR SELECT runtime, yield_count,scheduler_id,runnable,session_id,start_time,command,database_id

 FROM yields WHERE scheduler_id=1  ORDER BY runtime ASC

 OPEN delta_cur

 DECLARE @runtime_previous datetime,@yieldcount_previous bigint

 DECLARE @runtime datetime,@yieldcount bigint,@scheduler_id bigint,@runnableint,@session_id int,@start_time datetime,@command varchar(200),@database_id int

 

 FETCH NEXT FROM delta_cur INTO  @runtime ,@yieldcount ,@scheduler_id,@runnable,@session_id ,@start_time,@command,@database_id

 SET @runtime_previous=@runtime;SET @yieldcount_previous=@yieldcount

 FETCH NEXT FROM delta_cur INTO  @runtime ,@yieldcount ,@scheduler_id,@runnable,@session_id ,@start_time,@command ,@database_id 

 

 WHILE(@@FETCH_STATUS=0)

 BEGIN

--We find one non-yielding scheduler during the runtime delta

IF(@yieldcount=@yieldcount_previous)

BEGIN

PRINT 'Non-yielding Scheduler Time delta found!'

  SELECT @runtime_previous 'runtime_previous', @runtime 'runtime', datediff(second,@runtime_previous,@runtime) 'non_yielding_scheduler_time_second', @yieldcount_previous'yieldcount_previous',

  @yieldcount 'yieldcount' ,@scheduler_id 'scheduler_id',@runnable 'runnable_tasks',@session_id 'session_id' ,@start_time 'start_time',

 

  @command 'command' ,@database_id  'database_id'

END

 

-- print @id

SET @runtime_previous=@runtime;SET @yieldcount_previous=@yieldcount

FETCH NEXT FROM delta_cur INTO  @runtime ,@yieldcount ,@scheduler_id,@runnable,@session_id ,@start_time,@command ,@database_id   

 

 END

 

 CLOSE delta_cur

 DEALLOCATE delta_cur

 FETCH NEXT  FROM scheduler_cur INTO @id

 

END

CLOSE scheduler_cur

DEALLOCATE scheduler_cur

 

 

이외에 응용프그램호스트명과 같은 사용자 세션에 대한 자세한 정보를 확인하려면 프로파일러 XEvent 동시에 실행하여 해당 이벤트를 캡처한다음 상관 관계를 분석   있다.

 

[참고자료]

https://blogs.msdn.microsoft.com/psssql/2018/04/05/troubleshooting-sql-server-scheduling-and-yielding/

 

 

2018-07-03 / Sungwook Kang / http://sqlmvp.kr

 

SQL Server, SQLOS, SQL Scheduler, yielding, non-yielding, MS SQL, CPU scheduler, CPU Quantum



출처: https://sqlmvp.tistory.com/1261?category=618825 [Database Lab]
No. Subject Author Date Views
Notice 2023년 1월 - SQLER의 업데이트 강좌 리스트 코난(김대우) 2023.01.02 1240
2146 In-memory optimized table에 사용되는 Hash Index jevida(강성욱) 2019.03.26 433
2145 VM환경에서 AG를 구성하였을때VSS 백업 동작 변경 jevida(강성욱) 2019.03.25 435
2144 SQL Server 2016 향상된 가용성 그룹 – 데이터베이스 수준의 상태 탐지 장애조치 jevida(강성욱) 2019.03.25 464
2143 SQL Server 2016 대용량 데이터 로드시 최소 로깅(minimal logging) 과Batch Size jevida(강성욱) 2019.03.25 375
2142 SQL Server 설치시 발생하는 1638 오류 jevida(강성욱) 2019.03.25 573
2141 SQL Server 666코드의 고유 식별자 오류 jevida(강성욱) 2019.03.25 337
2140 SQL Server AlwaysOn synchronous-commit 환경에서 동기화 레이턴시 트러블슈팅 jevida(강성욱) 2019.03.25 400
» SQL Server Scheduling and Yielding 트러블슈팅 jevida(강성욱) 2019.03.25 405
2138 SQL Server 2016 Tempdb 경합(contention) 최적화 jevida(강성욱) 2019.03.25 520
2137 XEvent를 사용하여 Auto tuning 작업 모니터링 jevida(강성욱) 2019.03.25 527
2136 SQL Server In-Memory OLTP에 ASP.NET 세션 상태 저장하기 jevida(강성욱) 2019.03.25 413
2135 SQL Server에서 JSON 데이터 저장하기 jevida(강성욱) 2019.03.25 546
2134 Azure SQL에서 네트워크를 구성하는 방법 jevida(강성욱) 2019.03.25 268
2133 SQL Server 네이티브 컴파일된 저장 프로시저 성능 모니터링 jevida(강성욱) 2019.03.25 520
2132 SQL Server 2017 소규모 시스템에서 향상된 리소스 사용 jevida(강성욱) 2019.03.25 300
2131 클러스터 컬럼스토어 인덱스(Clusterd Columnstore Index)에서 대량 인서트 작업시 발생하는 래치 경합 최소화 트릭 jevida(강성욱) 2019.03.25 449
2130 클러스터 컬럼스토어 인덱스(Clusterd Columnstore Index)에서 대량 인서트 작업시 발생하는 래치 경합 최소화 트릭 jevida(강성욱) 2019.03.25 429
2129 SQL Server 2016 향상된 복제 기능 – 배포 데이터베이스 클린업 향상 jevida(강성욱) 2019.03.25 335
2128 SQL Server 2017향상된 복제 기능 – 배포 데이터베이스의 AG 지원 jevida(강성욱) 2019.03.25 493
2127 SQL Server 2017 향상된 복제 기능 - 복제에이전트 프로필 매개변수의 동적 새로 고침 jevida(강성욱) 2019.03.25 534





XE Login