MySQL 로그 보관 기간, 길게 잡을수록 안전할까?

Q: MySQL 로그 보관 기간, 길게 잡을수록 안전할까?

Binlog는 Replica나 CDC 커넥터가 멈춰 있을 수 있는 가장 긴 시간보다 길게 둬야 하며(기본 30일), 읽지 않은 Binlog를 지우자 Replica가 오류 13114로 멈췄다.

이번 시간에는 MySQL 로그를 종류별로 나눠 각각 얼마나 남겨야 하는지 정하는 기준을 살펴보고, Source와 Replica에서 로그를 직접 지우고 넘겨 보며 실제로 어떤 일이 생기는지 확인하며 배워가는 시간입니다.

로그를 오래 남겨 디스크가 가득 차면 MySQL은 더 이상 쓰지 못해요. 반대로 로그를 너무 빨리 지우면 사고가 났을 때 되돌아갈 방법이 사라집니다.

가장 신경 써야 할 로그는 Binlog예요. Binlog는 데이터 변경을 순서대로 남기는 로그이고, Replica(Source 서버의 변경을 받아 따라 하는 서버)와 CDC 커넥터(변경을 읽어 다른 시스템으로 보내는 프로그램)가 이 로그를 읽습니다.

실습 준비

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

compose.yaml: Source와 Replica로 연결할 MySQL 8.4 두 대(General log·Slow query log 파일 이름 고정)

먼저 Docker Compose로 MySQL 8.4 두 대를 띄워 Source와 Replica로 연결할게요.

복제는 GTID(트랜잭션마다 붙는, 서버 UUID와 번호로 된 고유 ID)로 위치를 맞추는 방식을 써요. General log와 Slow query log는 파일 이름을 고정해 두었습니다. Slow query log 파일은 이 글에서는 쓰지 않아요. compose.yaml은 이렇게 생겼어요.

services:
  source:
    image: mysql:8.4
    command: >
      --server-id=1 --gtid-mode=ON --enforce-gtid-consistency=ON
      --general-log-file=/var/lib/mysql/general.log
      --slow-query-log-file=/var/lib/mysql/slow.log
    environment:
      MYSQL_ROOT_PASSWORD: root
    ports:
      - "3321:3306"

  replica:
    image: mysql:8.4
    command: --server-id=2 --gtid-mode=ON --enforce-gtid-consistency=ON
    environment:
      MYSQL_ROOT_PASSWORD: root

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

docker compose up -d

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

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

컨테이너가 뜨면 Source에 복제용 계정과 테이블을 만들고, Replica를 Source에 연결해 주세요.

src -e "CREATE USER 'repl'@'%' IDENTIFIED BY 'repl'; GRANT REPLICATION SLAVE ON *.* TO 'repl'@'%'; CREATE DATABASE shop; CREATE TABLE shop.orders (id INT AUTO_INCREMENT PRIMARY KEY, amount INT);"
rep -e "CHANGE REPLICATION SOURCE TO SOURCE_HOST='source', SOURCE_USER='repl', SOURCE_PASSWORD='repl', SOURCE_AUTO_POSITION=1, GET_SOURCE_PUBLIC_KEY=1; START REPLICA;"

이제 각 로그의 현재 설정을 확인해 볼게요.

src -e "SHOW VARIABLES WHERE Variable_name IN ('log_bin', 'binlog_expire_logs_seconds', 'log_error', 'slow_query_log', 'long_query_time', 'general_log');"

+----------------------------+-----------+
| Variable_name              | Value     |
+----------------------------+-----------+
| binlog_expire_logs_seconds | 2592000   |
| general_log                | OFF       |
| log_bin                    | ON        |
| log_error                  | stderr    |
| long_query_time            | 10.000000 |
| slow_query_log             | OFF       |
+----------------------------+-----------+

rep -e "SHOW VARIABLES LIKE 'relay_log_purge';"

+-----------------+-------+
| Variable_name   | Value |
+-----------------+-------+
| relay_log_purge | ON    |
+-----------------+-------+

출력은 이렇게 읽으시면 됩니다.

binlog_expire_logs_seconds: Binlog 보관 기간이에요. 기본값 2592000초는 30일입니다.
log_error: 공식 Docker 이미지에서는 파일이 아니라 stderr로 나가요. 이 경우 Error log는 docker logs로 보고, 보관 기간은 Docker의 로그 설정이 정합니다.
slow_query_log, general_log: 기본으로 꺼져 있어요.
relay_log_purge: 켜져 있으면 적용을 마친 Relay log(Replica가 받아 온 Binlog를 적용하기 전에 쌓아 두는 로그)를 MySQL이 지워요.

실습 1: Replica가 아직 읽지 않은 Binlog를 지우면

Replica는 Source의 Binlog를 받아 가며 데이터를 맞춰요. 그럼 Replica가 잠시 멈춘 사이 Source에서 Binlog를 지우면 어떻게 될까요? 직접 확인해 볼게요.

Replica를 멈추고, 그동안 Source에 데이터를 넣으며 Binlog를 두 번 넘겨 볼게요. FLUSH BINARY LOGS는 지금 쓰고 있는 Binlog 파일을 닫고 새 파일을 여는 명령이에요.

rep -e "STOP REPLICA;"
src -e "INSERT INTO shop.orders (amount) VALUES (1000); FLUSH BINARY LOGS; INSERT INTO shop.orders (amount) VALUES (2000); FLUSH BINARY LOGS; SHOW BINARY LOGS;"

+---------------+-----------+-----------+
| Log_name      | File_size | Encrypted |
+---------------+-----------+-----------+
| binlog.000001 |   2996309 | No        |
| binlog.000002 |      1472 | No        |
| binlog.000003 |       520 | No        |
| binlog.000004 |       198 | No        |
+---------------+-----------+-----------+

이 상태에서 Source가 알고 있는 Replica 목록을 보면 비어 있어요.

src -e "SHOW REPLICAS;"

SHOW REPLICAS는 지금 연결된 Replica만 보여 주거든요. 멈춰 있는 Replica는 목록에 나오지 않아요.

그래서 Source만 보고서는 아직 Binlog가 필요한 Replica가 있는지 알 수 없습니다.

이제 binlog.000004 이전의 Binlog를 지우고 Replica를 다시 시작해 볼게요.

src -e "PURGE BINARY LOGS TO 'binlog.000004'; SHOW BINARY LOGS;"

+---------------+-----------+-----------+
| Log_name      | File_size | Encrypted |
+---------------+-----------+-----------+
| binlog.000004 |       198 | No        |
+---------------+-----------+-----------+

rep -e "CHANGE REPLICATION SOURCE TO SOURCE_HOST='source', SOURCE_USER='repl', SOURCE_PASSWORD='repl', SOURCE_AUTO_POSITION=1, GET_SOURCE_PUBLIC_KEY=1; START REPLICA;"
rep -e "SHOW REPLICA STATUS\G" | grep -E "Replica_IO_Running|Last_IO_Errno|Last_IO_Error"

           Replica_IO_Running: No
                Last_IO_Errno: 13114
                Last_IO_Error: Got fatal error 1236 from source when reading data from binary log: 'Cannot replicate because the source purged required binary logs. Replicate the missing transactions from elsewhere, or provision a new replica from backup. Consider increasing the source's binary log expiration period. The GTID set sent by the replica is '3e3fad0e-bbc8-11f1-8821-0242ac190002:1-5,
      Last_IO_Error_Timestamp: 260929 05:41:13

Replica는 다시 연결했지만 이어 받을 Binlog가 없어서 멈췄어요. Replica가 마지막으로 읽은 파일을 확인해 보시면 이유가 보입니다.

rep -e "SHOW REPLICA STATUS\G" | grep -E " Source_Log_File| Relay_Source_Log_File|Replica_IO_Running|Replica_SQL_Running:"

              Source_Log_File: binlog.000002
        Relay_Source_Log_File: binlog.000002
           Replica_IO_Running: No
          Replica_SQL_Running: Yes

Replica는 binlog.000002까지 읽은 상태였는데, 우리가 그 파일부터 지웠어요.

이렇게 되면 로그를 다시 만들 수 없으니, 백업에서 Replica를 새로 만들어야 합니다.

Replica뿐 아니라 CDC 커넥터도 같은 이유로 멈춰요. 커넥터가 멈춰 있던 동안 Binlog가 지워지면 처음부터 다시 받아야 합니다.

그러니 Binlog 보관 기간은 Replica나 커넥터가 멈춰 있을 수 있는 가장 긴 시간보다도 길게 잡아 주셔야 해요.

실습 2: General log는 필요한 시간에만 켭니다

General log는 들어온 쿼리를 모두 남겨요. 그러면 얼마나 쌓일까요? 켜 둔 상태에서 짧은 조회 쿼리를 2000번 실행해 볼게요.

src -e "SET GLOBAL general_log = ON;"
for i in $(seq 1 2000); do echo "SELECT * FROM shop.orders WHERE id = $i;"; done | docker compose exec -T -e MYSQL_PWD=root source mysql -uroot > /dev/null
docker compose exec source ls -lh /var/lib/mysql/general.log

-rw-r----- 1 mysql mysql 160K Sep 29 05:42 /var/lib/mysql/general.log

출력을 보면 짧은 쿼리 2000개에 160KB가 쌓였어요. 초당 수천 개의 쿼리를 받는 운영 서버라면 하루에 수십 GB가 쌓일 수 있습니다.

그래서 General log는 문제를 재현하는 동안에만 켜고, 확인이 끝나면 바로 꺼 주세요.

src -e "SET GLOBAL general_log = OFF;"

정리

범위: MySQL 8.4(mysql:8.4 이미지, 서버 8.4.11) Source 1대와 GTID 복제 Replica 1대, 기본 설정에서 시작.

기본값은 binlog_expire_logs_seconds 2592000초(30일), long_query_time 10초였고, Slow query log와 General log는 꺼져 있었으며, Docker 이미지의 Error log는 stderr로 나갔어요. Docker로 띄운 MySQL의 Error log 보관 기간은 Docker 로그 설정으로 정해 주세요.
Replica를 멈춘 동안 Source의 SHOW REPLICAS는 빈 목록을 돌려줬습니다. Binlog를 지우기 전에는 Source가 아니라 각 Replica의 SHOW REPLICA STATUS에서 Source_Log_File을 확인하세요.
Replica가 binlog.000002까지 읽은 상태에서 binlog.000004 이전을 지우자 Replica는 오류 13114(source purged required binary logs)로 멈췄고, 백업에서 새로 만들어야 했어요. Binlog 보관 기간은 Replica나 CDC 커넥터가 멈춰 있을 수 있는 가장 긴 시간보다 길게 잡아 주세요.
이 글에 싣지 않은 추가 측정에서는 binlog_expire_logs_seconds를 60으로 줄이고 1분 넘게 기다려도 기간이 지난 Binlog가 남아 있었고, Binlog를 한 번 더 넘긴 뒤에야 지워졌습니다. MySQL은 기간이 지난 Binlog를 새 Binlog 파일을 열 때와 서버가 시작될 때 지우니, 쓰기가 적은 서버에서는 설정한 기간보다 오래된 파일이 남는 것을 디스크 계산에 넣어 두세요.
General log를 켜고 짧은 조회 쿼리 2000개를 실행하자 160KB가 쌓였어요. General log는 문제를 재현하는 동안에만 켜고 바로 꺼 주세요.

MySQL 로그 보관 기간, 길게 잡을수록 안전할까?

환경

실습 준비

실습 1: Replica가 아직 읽지 않은 Binlog를 지우면

실습 2: General log는 필요한 시간에만 켭니다

정리

이 글과 함께 보면 좋은 콘텐츠

이 글과 함께 보면 좋은 콘텐츠