SQL Server 트랜잭션 로그 복원시 복원 시간이 오래 걸리는 현상

 

·       Version : SQL Server 2016 Enterprise Edition

 

SQL Server에서 트랜잭션 로그를 사용하여 데이터를 복원시평소와 다르게 매우 오래 걸리는 현상이 발생하였다처음에는 I/O 서브 시스템을 의심하고 물리장비 까지 교체하였으나증상을 동일하였다여러가지 가설을 세웠고원인 분석 결과, Slow query 트랜잭션 로그의 복원시간과 관련이 있다는 것을 발견할  있었다.

 

필자의 운영 환경은 10 마다 트랜잭션 로그 백업을 진행하고백업된 로그는 다른 서버에서 Read Only(STAND BY) 복원하여  부서에서 사용할  있도록 로그 쉬핑을 구성하였다. 10 마다 발생하는 로그의 양은  10MB~ 20MB 정도로 평상시 복원하는데  1 정도 소요되었다그런데 어느날 부터 복원시간이 증가하여 30분정도 걸렸다그러다 보니연관된 여러 ETL 시스템  리포트 시스템에 영향을 주게 되었었다.

아래 그래프는 트랜잭션로그 복원시 디스크의 Idle Time 캡처한 것으로 파란색이 평상시의 상태이고 빨간색과 노란색이 문제가 발생했던 때의 상태이다 트랜잭션 로그 복원이 진행되는  동안 엄청난 I/O 발생하는 것을 확인할  있다.

 

트랜잭션 복원이 진행되는 동안  단계에 대한 작업시간을 확인하기 위해서 DBCC TRACE 명령을 사용하여 Inter log SQL Server이벤트 로그에 기록하도록 하였다.

DBCC TRACEON(3004, -1)

DBCC TRACEON(3605, -1)

DBCC TRACEON(3213, -1)

 

트레이스 적용  트랜잭션로그 복원을 진행하고아래와 같은 이벤트 로그를 확인할  있었다.

 

이벤트 로그를 확인해보면 redo, undo  관한 시간이 표시되어 있는데, Slow 쿼리가 발생할 경우 트랜잭션 커밋이나 롤백이 발생하지 않은 상태(더티페이지)에서 백업이 진행되고 다음에 쿼리 실행이 완료되어 다름 트랜잭션 로그에 반영되었을때해당 쿼리의 결과에 따라데이터가 롤백되거나 커밋을 해야해서 (특히 롤백이 문제다데이터 페이지인덱스 페이지등에 반영하느라 디스크 I/O 오버헤드가 발생하고 전체적인 복원 시간이 느려졌다 아래와 같은 단계로 진행된다.

 

단계 : 분석트랜잭션 로그의 마지막 체크 포인트에서 시작한다 단계는 SQL Server 중지   더티 페이지 테이블 (DPT) 확인하고 구성한다활성 트랜잭션 테이블은 SQL Server 중지   커밋되지 않은 트랜잭션으로 구성된다.

 

단계 : 다시 실행 단계는 데이터베이스를 SQL 서비스가 중지  시점의 상태로 되돌린다가장 오래된 커밋되지 않은 트랜잭션이 롤백의 시작점 이다. DPT 최소 로그 시퀀스 이름 ( 로그 레코드에 LSN으로 레이블이 지정됨) SQL Server 페이지에서 작업을 다시 실행해야하는  번째 시간이며 가장 오래된 열린 트랜잭션에서 다시 시작하여 기록  작업을 다시 실행해야 한다필요한 잠금 장치를 확보 한다.

 

단계 : 실행 취소여기에서 1 단계에서 식별  활성 트랜잭션 (SQL Server 중단   커밋되지 않은) 목록이 개별적으로 롤백된다. SQL Server  트랜잭션에 대한 트랜잭션 로그 항목 간의 링크를 따른다. SQL Server 중지   커밋되지 않은 트랜잭션은 모두 취소된다.

 

 

정리하면, Slow 쿼리 증가로 인해 활성 트랜잭션이 많아졌고트랜잭선 로그 백업이 진행될때 더티페이지가 증가함에 따라 해당 로그 파일로 복원시 롤백  커밋 작업이 진행되어 이때 I/O 오버헤드가 발생하여 전체적인 복원이 느려졌다.

 

[참고자료]

·       Understanding How Restore and Recovery of Backups Work in SQL Server  https://docs.microsoft.com/en-us/previous-versions/sql/sql-server-2008-r2/ms191455(v=sql.105)?redirectedfrom=MSDN

·       SQL Server Mysteries: The Case of the Not 100% RESTORE : https://docs.microsoft.com/en-us/archive/blogs/sql_server_team/sql-server-mysteries-the-case-of-the-not-100-restore

·       SQLskills SQL101: Why is restore slower than backup : https://www.sqlskills.com/blogs/paul/sqlskills-sql101-why-is-restore-slower-than-backup/

·       SQL Server Database Recovery Process Internals – database STARTUP Command : https://www.sqlshack.com/sql-server-database-recovery-process-internals-database-startup-command/

 

 

2012-02-27/ Sungwook Kang / http://sungwookkang.com

 

 

 

SQL Server, MS SQL, Database Restore, Log shipping, 트랜잭션 로그 복원, SQL Server Recovery Step, 데이터베이스 복원로그 전달로그쉬핑, Database Recovery Process



출처: https://sungwookkang.com/1402 [Database Lab]
No. Subject Author Date Views
Notice SQL강좌: 챗GPT와 함께 배우는 SQL Server 무료 강좌 목차와 소개 (2023년 9월 업데이트) 코난(김대우) 2023.08.18 38622
Notice Python 무료 강좌 - 기초, 중급, 머신러닝(2023년 6월 업데이트) 코난(김대우) 2021.01.01 20784
2194 Azure purview - data governance, compliance 솔루션에 대해 file 코난(김대우) 2022.10.16 139
2193 Azure Synapse - COPY INTO로 대용량 데이터 분산 로드 코난(김대우) 2021.10.21 383
2192 Azure SQL Database로 CSV 파일 BULK INSERT - Python 코난(김대우) 2021.09.27 452
2191 Azure Synapse - Spark와 SQL Data warehouse 서비스 file 코난(김대우) 2021.09.16 371
2190 Azure에서 제공하는 데이터베이스 서비스 종류, AWS 및 GCP와 제품 비교 코난(김대우) 2020.12.25 997
» SQL Server 트랜잭션 로그 복원시 복원 시간이 오래 걸리는 현상 jevida(강성욱) 2020.02.28 1638
2188 SQL Server 2019 temp table을 사용한 워크로드에서 recompile 감소 jevida(강성욱) 2019.09.24 1851
2187 Azure SQL Managed Instance 및 SQL Server 2016 Later에서 대기 통계 분석 jevida(강성욱) 2019.09.24 1364
2186 SQL Server 2019에서 동기 통계 업데이트시 발생하는 쿼리 Blocking 확인 jevida(강성욱) 2019.09.21 1379
2185 SQL Server 2019 Log Writer Workers jevida(강성욱) 2019.09.21 1545
2184 SQL Server Login Timeout 디버깅 jevida(강성욱) 2019.09.19 2083
2183 SQL Server Worker Thread 기본 계산 jevida(강성욱) 2019.09.18 1507
2182 SQL Linux의 fsync 및 버퍼된 IO (버퍼된 쓰기중 오류가 발생하였을때 파일은 유효할까?) jevida(강성욱) 2019.09.17 1330
2181 SQL Server와 SQL Linux에서 인스턴스 파일 초기화 차이점 jevida(강성욱) 2019.09.14 1367
2180 BCP 실행시 동일 세션에서 여러개의 BULK INSERT 문으로 표시되는 이유 jevida(강성욱) 2019.09.13 1440
2179 삭제된 AD 그룹 계정으로 SQL Server 로그인 사례 (로그인 그룹 삭제 후 조치해야할 사항) jevida(강성욱) 2019.09.12 1243
2178 QPI(Query Performance Insights) 라이브러리를 사용하여 Azure SQL Managed Instance의 로그쓰기 사용량 확인 jevida(강성욱) 2019.09.11 1140
2177 ODBC 드라이버를 사용하여 SQL Server에서 Azure CosmosDB 쿼리 실행 jevida(강성욱) 2019.09.10 1211
2176 Azure SQL Managed Instance에서 로컬 스토리지 사용량 모니터링 jevida(강성욱) 2019.09.09 1283
2175 SQL Server Enterprise Edition 에서 CPU를 40 Core 이상 사용하지 못하는 현상 jevida(강성욱) 2019.09.04 1364





XE Login