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이벤트 로그에 기록하도록 하였다.

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

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

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

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

3 단계 : 실행 취소. 여기에서 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