InnoDB redo log는 MySQL이 꺼져도 데이터를 어떻게 지킬까?

Q: InnoDB redo log는 MySQL이 꺼져도 데이터를 어떻게 지킬까?

InnoDB가 변경을 redo log에 먼저 적고 재시작 때 checkpoint부터 다시 적용하기 때문이다. 용량 1GB에서는 SIGKILL 뒤 redo 6454건을 약 1.9초에 적용했다.

이번 시간에는 MySQL에 쓰기 부하를 주고 SIGKILL로 서버를 죽여 보며, InnoDB의 redo log가 크래시에서 커밋한 데이터를 지키는 과정을 배워가는 시간입니다. 쓰기가 몰릴 때 checkpoint가 어떻게 따라오는지, 크래시 뒤에 redo를 얼마나 다시 적용하는지, 그리고 크래시 뒤에 redo log 파일을 지우면 어떻게 되는지를 직접 확인해 볼게요.

예를 들어서 쓰기가 몰리던 중에 DB 서버가 갑자기 꺼졌다고 해볼게요. 다시 켜 보니 방금 커밋한 주문까지 모두 남아 있어요.

MySQL은 데이터를 바꿀 때마다 데이터 파일에 바로 쓰지 않는데도 이런 일이 가능합니다. 어떻게 그럴까요? InnoDB가 변경 내용을 redo log에 먼저 적어 두기 때문이에요.

데이터 파일보다 로그를 먼저 쓰는 이 방식을 WAL(Write-Ahead Logging)이라고 합니다. 세 로그(Binlog, redo log, undo log)의 차이와 커밋할 때 redo log를 디스크에 쓰는 설정(innodb_flush_log_at_trx_commit)이 더 궁금하면 Binlog, redo log, undo log를 비교한 글을 참고하세요.

실습 준비

이 글의 명령은 모두 실습 코드의 mysql-redo-log/ 디렉터리에서 실행합니다.

compose.yaml: MySQL 8.4 컨테이너(버퍼 풀 1GB, Error log 상세)
setup.sql: 행 30만 개짜리 테이블을 만드는 SQL
watch.sql: checkpoint age와 dirty page 수(둘 다 아래에서 설명)를 한 줄 찍는 SQL
watchload.sh: UPDATE를 돌리면서 watch.sql을 1초마다 실행하는 스크립트
slowflush.sql: 바뀐 페이지를 데이터 파일에 쓰는 속도를 늦추는 설정 SQL
trial.sh: 용량을 바꾸고 flush를 늦춘 채 UPDATE 뒤 크래시를 내는 스크립트

복구 과정이 Error log에 자세히 남도록 log-error-verbosity를 3으로 올렸어요. 그리고 버퍼 풀에서 바뀌었지만 아직 데이터 파일에 쓰지 않은 페이지(dirty page)가 충분히 쌓일 수 있게 버퍼 풀을 1GB로 잡았습니다. compose.yaml은 이렇게 생겼어요.

services:
  mysql:
    image: mysql:8.4
    command: --log-error-verbosity=3 --innodb-buffer-pool-size=1G
    environment:
      MYSQL_ROOT_PASSWORD: root
    ports:
      - "3401:3306"
    volumes:
      - data:/var/lib/mysql

volumes:
  data:

setup.sql은 lab.t(id, n, pad CHAR(200)) 테이블을 만들고 재귀 CTE로 행 30만 개를 넣어요. 이 테이블 전체를 UPDATE하면 한 번에 redo log가 많이 생깁니다.

자주 쓰는 명령은 셸 함수로 만들어 놓을게요. MYSQL_PWD 환경 변수로 비밀번호를 넘기는 방식은 실습에서만 써 주세요. 아래 블록은 파일로 만들지 말고 실습 디렉터리에서 연 터미널에 그대로 붙여 넣어 주세요. 이후 명령은 모두 이 터미널에서 실행하고, 터미널을 새로 열면 다시 붙여 넣으시면 됩니다.

docker compose -p redo up -d
export COMPOSE_PROJECT_NAME=redo

sql() { docker compose exec -T -e MYSQL_PWD=root mysql mysql -uroot "$@"; }

up() { until sql -e "SELECT 1" >/dev/null 2>&1; do sleep 1; done; }

up
sql < setup.sql

실습 1: 쓰는 동안 checkpoint가 따라옵니다

redo log는 용량이 정해져 있어요. 그래서 오래된 부분을 다시 써야 계속 기록할 수 있고, 어떤 redo 기록을 덮어써도 되려면 그 기록이 바꾼 페이지가 이미 데이터 파일에 쓰여 있어야 하겠죠.

그래서 InnoDB는 page cleaner 스레드로 dirty page를 조금씩 데이터 파일에 쓰고, 어디까지 썼는지를 checkpoint LSN으로 기록해요. 크래시 복구는 여기서 시작합니다.

checkpoint가 앞으로 움직여야 redo 로그 공간을 다시 쓸 수 있습니다.

현재 LSN에서 checkpoint LSN을 뺀 값을 checkpoint age라고 불러요. 데이터 파일에 아직 반영되지 않은 redo log의 양이고, 크래시가 나면 다시 적용해야 하는 구간입니다.

watch.sql은 현재 시간, Innodb_redo_log_current_lsn에서 Innodb_redo_log_checkpoint_lsn을 뺀 checkpoint age, Innodb_buffer_pool_pages_dirty를 한 줄로 찍고 1초 쉬어요. 두 LSN 상태 변수는 MySQL 8.0.30부터 볼 수 있어요.

테이블 전체를 UPDATE하는 문장을 백그라운드로 세 번 돌리면서, 한 세션에서 watch.sql을 14번 실행해 볼게요. watchload.sh가 이 과정을 담고 있어요.

아래는 기본 용량 100MB에서 실행한 결과예요. 열은 시간, checkpoint age(바이트), dirty page 수입니다.

source watchload.sh

2026-09-30 05:01:36.673	0	7
2026-09-30 05:01:37.675	26073043	3
2026-09-30 05:01:38.679	26073043	0
2026-09-30 05:01:39.682	0	0
2026-09-30 05:01:40.684	0	0
2026-09-30 05:01:41.687	24283591	1395
2026-09-30 05:01:42.689	25761076	1540
2026-09-30 05:01:43.694	9057221	1408
2026-09-30 05:01:44.697	0	0
2026-09-30 05:01:45.699	12709178	1598
2026-09-30 05:01:46.701	25761231	2786
2026-09-30 05:01:47.704	25762392	1991
2026-09-30 05:01:48.706	9291283	1459
2026-09-30 05:01:49.710	0	0

UPDATE가 돌 때마다 checkpoint age가 25MB 안팎까지 올라가고 dirty page가 쌓였다가, page cleaner가 페이지를 쓰면 다시 0으로 돌아와요.

실습 2: 크래시가 나면 checkpoint부터 다시 적용합니다

재시작한 InnoDB는 마지막 checkpoint를 찾고, 거기서부터 redo log를 앞에서 뒤로 차례대로 읽으며 페이지에 다시 적용해요. 그다음 커밋되지 않은 트랜잭션을 undo log로 롤백합니다.

다시 적용할 양은 checkpoint age에 달려 있어요. 실습 1처럼 평소에는 page cleaner가 빨라서 age가 크지 않아요. 그래서 여기서는 일부러 flush를 늦춘 상태를 만드는 방식으로 가볼게요.

redo log 용량은 innodb_redo_log_capacity로 정해요. MySQL 8.0.30부터는 서버를 재시작하지 않고 바꿀 수 있습니다.

slowflush.sql은 innodb_io_capacity를 100, innodb_io_capacity_max를 200, innodb_max_dirty_pages_pct_lwm을 0으로 두고 innodb_adaptive_flushing을 꺼요.

innodb_io_capacity, innodb_io_capacity_max: page cleaner가 초당 쓰는 페이지 수의 기준이에요. 가장 작은 값으로 낮췄습니다.
innodb_max_dirty_pages_pct_lwm: dirty page 비율이 이 값을 넘으면 미리 flush를 시작해요. 0이면 이 동작을 끕니다.
innodb_adaptive_flushing: redo log가 쌓이는 속도에 맞춰 flush 양을 조절하는 기능이에요. 끄면 flush가 redo 생성 속도를 따라가지 않습니다.

운영 서버에서는 이렇게 설정하시면 안 돼요. dirty page를 일부러 쌓기 위한 실습용 설정입니다.

서버를 SIGKILL로 죽이고 다시 시작한 뒤, 복구 관련 Error log만 보는 함수를 만들어 둘게요.

age() { sql -N < watch.sql | head -1; }

crash() {
  docker kill "$(docker compose ps -q mysql)" >/dev/null
  since=$(date -u +%Y-%m-%dT%H:%M:%SZ)
  docker compose start >/dev/null 2>&1
  up
  docker compose logs --no-log-prefix --since "$since" mysql | grep -E "not shutdown normally|latest found checkpoint|redo log records|Apply batch completed|mysqld: ready for connections"
}

trial.sh는 용량(MB)을 인자로 받아 innodb_redo_log_capacity를 바꾸고, slowflush.sql을 적용한 뒤 UPDATE 세 번을 돌려요. 그다음 age로 checkpoint age를 찍고 crash로 크래시를 냅니다. 용량 1GB로 해 볼게요.

source trial.sh 1024

2026-09-30 05:06:34.804	75563075	6202
2026-09-30T05:06:40.556330Z 1 [Note] [MY-013883] [InnoDB] The latest found checkpoint is at lsn = 1122372139 in redo log file ./#innodb_redo/#ib_redo1860.
2026-09-30T05:06:40.556405Z 1 [Note] [MY-012551] [InnoDB] Database was not shutdown normally!
2026-09-30T05:06:41.412451Z 1 [Note] [MY-012532] [InnoDB] Applying a batch of 6454 redo log records ...
2026-09-30T05:06:42.495196Z 1 [Note] [MY-012535] [InnoDB] Apply batch completed!
2026-09-30T05:06:43.468665Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.4.11'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server - GPL.

죽이기 직전 checkpoint age가 약 75MB, dirty page가 6202개였고, 재시작한 InnoDB는 마지막 checkpoint를 찾아 redo 기록 6454건을 다시 적용했어요.

checkpoint를 찾은 뒤 적용이 끝날 때까지 약 1.9초가 걸렸습니다.

실습 3: 크래시 뒤에 redo log를 지우면 안 됩니다

서버가 뜨지 않을 때 로그 파일부터 지우는 경우가 있어요. 하지만 redo log에는 데이터 파일에 아직 반영되지 않은 커밋이 들어 있으니, 크래시 직후에 지우면 그 변경을 잃습니다.

실습 2에서 다시 띄운 서버를 SIGKILL로 죽이고, 이번에는 #innodb_redo 안의 파일만 지운 뒤 다시 시작해 볼게요.

docker kill "$(docker compose ps -q mysql)" >/dev/null
docker compose run --rm --no-deps --entrypoint sh mysql -c 'rm "/var/lib/mysql/#innodb_redo/"*'
since=$(date -u +%Y-%m-%dT%H:%M:%SZ)
docker compose start >/dev/null 2>&1
sleep 15
docker compose ps -a --format '{{.Service}} {{.State}}'
docker compose logs --no-log-prefix --since "$since" mysql | grep -E "New redo log files|is in the future" | head -3
docker compose logs --no-log-prefix --since "$since" mysql | grep -c "is in the future"

mysql exited
2026-09-30T05:08:29.224339Z 1 [Note] [MY-012893] [InnoDB] New redo log files created, LSN=29540876
2026-09-30T05:08:29.232046Z 1 [ERROR] [MY-011971] [InnoDB] Tablespace 'innodb_system' Page [page id: space=0, page number=5] log sequence number 1300493258 is in the future! Current system log sequence number 29540876.
2026-09-30T05:08:29.241426Z 0 [ERROR] [MY-011971] [InnoDB] Tablespace 'innodb_undo_002' Page [page id: space=4294967278, page number=42] log sequence number 1092867885 is in the future! Current system log sequence number 29540876.
860

InnoDB가 빈 디렉터리에 새 redo log 파일을 만들고 시작을 이어 갔어요.

그런데 새 redo log의 LSN은 29540876인데, 시스템 테이블스페이스와 undo 테이블스페이스의 페이지에는 10억이 넘는 LSN이 적혀 있습니다. 페이지가 로그보다 미래에 있다는 오류가 860번 찍혔고, 서버는 결국 종료됐어요. 크래시 직전의 변경은 적용할 방법이 없어진 거죠.

그러니 서버가 뜨지 않으면 파일을 지우지 말고 Error log부터 봐 주세요. 용량을 바꾸고 싶다면 8.0.30 이후에는 innodb_redo_log_capacity를 바꾸면 되니, 파일을 직접 건드릴 이유가 없습니다.

정리

범위: MySQL 8.4.11(mysql:8.4 이미지), 버퍼 풀 1GB, 행 30만 개 테이블 전체 UPDATE, 노트북 Docker.

기본 용량 100MB에서 UPDATE가 돌 때마다 checkpoint age가 25MB 안팎까지 올랐다가 page cleaner가 페이지를 쓰면 0으로 돌아왔어요. checkpoint age는 Innodb_redo_log_current_lsn에서 Innodb_redo_log_checkpoint_lsn을 빼서 보세요.
flush를 늦추고 SIGKILL을 보내자 1GB는 checkpoint age 약 75MB에서 redo 6454건을 약 1.9초에 다시 적용했어요.
이 글에 싣지 않은 추가 측정에서는 같은 방법으로 8MB가 checkpoint age 약 3MB에서 redo 0건을 약 0.15초에 적용했습니다. 복구 시간이 걱정되면 용량보다 실제 checkpoint age가 얼마나 커지는지를 보세요.
크래시 뒤 #innodb_redo 안의 파일만 지우면 새 redo log가 만들어지고 "is in the future" 오류 860번 뒤 서버가 종료됐습니다. 서버가 뜨지 않으면 redo log 파일을 지우지 말고 Error log부터 보세요.
innodb_redo_log_capacity는 8.0.30부터 재시작 없이 바꿀 수 있으니, 용량을 바꾸려고 redo log 파일을 건드리지 마세요.