이번 시간에는 MySQL에서 데이터를 바꾼 뒤 Binlog에 어떤 이벤트가 어떤 순서로 남는지 한 줄씩 읽어 보며 배워가는 시간입니다.
예를 들어서 주문 테이블에서 행 하나가 바뀌었다고 해볼게요. 그러면 MySQL은 어떤 행이 어떤 값으로 바뀌었는지를 따로 기록해 둡니다.
이 기록이 Binlog(바이너리 로그)예요. Replica는 이 기록을 받아 같은 변경을 따라 하고, 특정 시점 복구와 CDC(DB의 변경을 읽어 다른 시스템으로 보내는 일)도 이 기록을 읽어요.
실습 준비
이 글의 명령은 모두 실습 코드의 mysql-binlog/ 디렉터리에서 실행합니다.
compose.yaml: MySQL 8.4 Source와 Replica 두 컨테이너 정의setup.sql: Source에 복제용 계정,shop.orders,shop.stock(1만 행)을 만드는 SQL
Docker Compose로 MySQL 8.4 두 대를 띄워서 Source와 Replica로 연결할게요(compose.yaml). Source는 변경을 기록해서 내보내는 원본 서버라고 보시면 됩니다.
GTID(트랜잭션마다 붙는, 서버 UUID와 번호로 된 고유 ID)는 두 서버 모두 켜 둡니다.
services:
source:
image: mysql:8.4
command: --server-id=1 --gtid-mode=ON --enforce-gtid-consistency=ON
environment:
MYSQL_ROOT_PASSWORD: root
ports:
- "3371:3306"
replica:
image: mysql:8.4
command: --server-id=2 --gtid-mode=ON --enforce-gtid-consistency=ON
environment:
MYSQL_ROOT_PASSWORD: root
ports:
- "3372:3306"
setup.sql은 Source에 복제용 계정 repl과 shop 데이터베이스를 만들고, 테이블 두 개를 만들어요. 이 글에서는 orders(id, item, qty, status)를 씁니다.
이제 Source와 Replica에 접속하는 셸 함수(src, rep)를 만들고, Replica를 Source에 연결해 볼게요. MYSQL_PWD 환경 변수로 비밀번호를 넘기는 방식은 실습에서만 써 주세요.
Replica에서 먼저 실행하는 RESET BINARY LOGS AND GTIDS는 컨테이너가 처음 뜰 때 Replica가 스스로 남긴 GTID를 지워 줘요.
brew install mysql-client@8.4
export PATH="$(brew --prefix mysql-client@8.4)/bin:$PATH"
docker compose up -d
src() { docker compose exec -T -e MYSQL_PWD=root source mysql -uroot "$@"; }
rep() { docker compose exec -T -e MYSQL_PWD=root replica mysql -uroot "$@"; }
until src -e "SELECT 1" > /dev/null 2>&1 && rep -e "SELECT 1" > /dev/null 2>&1; do sleep 2; done
src < setup.sql
rep -e "RESET BINARY LOGS AND GTIDS; CHANGE REPLICATION SOURCE TO SOURCE_HOST='source', SOURCE_USER='repl', SOURCE_PASSWORD='repl', SOURCE_AUTO_POSITION=1, GET_SOURCE_PUBLIC_KEY=1; START REPLICA;"
실습 1: 다섯 번 실행하고 세 건이 남았습니다
Binlog는 파일 하나에 다 쌓이지 않고 여러 개로 나뉘어 쌓여요. 이번 실습에서 만든 이벤트만 따로 보고 싶으니, FLUSH BINARY LOGS로 새 파일을 열어 줄게요. 그다음 SHOW BINARY LOG STATUS로 지금 쓰고 있는 파일과 위치를 확인합니다.
src -e "FLUSH BINARY LOGS; SHOW BINARY LOG STATUS\G"
*************************** 1. row ***************************
File: binlog.000003
Position: 198
Binlog_Do_DB:
Binlog_Ignore_DB:
Executed_Gtid_Set: c5304688-bc81-11f1-a949-0242ac1a0002:1-11
File: 지금 기록하고 있는 Binlog 파일이에요.Position: 다음 이벤트가 기록될 위치(바이트)예요. 새 파일은 파일 머리글 이벤트 뒤인 198에서 시작합니다.Executed_Gtid_Set: 이 서버에서 실행을 마친 트랜잭션의 GTID 목록이에요.서버 UUID:번호형식이고, 지금까지 11개 트랜잭션이 실행됐다는 뜻입니다.
binlog.000003이 비어 있는 상태에서 문장 다섯 개를 실행해 볼게요. 두 행 INSERT, 전체 SELECT, UPDATE, DELETE, 그리고 INSERT한 뒤 ROLLBACK한 트랜잭션입니다.
src -e "INSERT INTO shop.orders VALUES (1, 'keyboard', 1, 'paid'), (2, 'mouse', 2, 'paid');"
src -t -e "SELECT * FROM shop.orders;"
src -e "UPDATE shop.orders SET status = 'shipped' WHERE id = 1;"
src -e "DELETE FROM shop.orders WHERE id = 2;"
src -e "BEGIN; INSERT INTO shop.orders VALUES (3, 'monitor', 1, 'paid'); ROLLBACK;"
+----+----------+------+--------+
| id | item | qty | status |
+----+----------+------+--------+
| 1 | keyboard | 1 | paid |
| 2 | mouse | 2 | paid |
+----+----------+------+--------+
이제 SHOW BINLOG EVENTS로 파일 안에 어떤 이벤트가 들어갔는지 보겠습니다.
src -t -e "SHOW BINLOG EVENTS IN 'binlog.000003';"
+---------------+------+----------------+-----------+-------------+--------------------------------------------------------------------+
| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
+---------------+------+----------------+-----------+-------------+--------------------------------------------------------------------+
| binlog.000003 | 4 | Format_desc | 1 | 127 | Server ver: 8.4.11, Binlog ver: 4 |
| binlog.000003 | 127 | Previous_gtids | 1 | 198 | c5304688-bc81-11f1-a949-0242ac1a0002:1-11 |
| binlog.000003 | 198 | Gtid | 1 | 277 | SET @@SESSION.GTID_NEXT= 'c5304688-bc81-11f1-a949-0242ac1a0002:12' |
| binlog.000003 | 277 | Query | 1 | 348 | BEGIN |
| binlog.000003 | 348 | Table_map | 1 | 412 | table_id: 95 (shop.orders) |
| binlog.000003 | 412 | Write_rows | 1 | 490 | table_id: 95 flags: STMT_END_F |
| binlog.000003 | 490 | Xid | 1 | 521 | COMMIT /* xid=46 */ |
| binlog.000003 | 521 | Gtid | 1 | 600 | SET @@SESSION.GTID_NEXT= 'c5304688-bc81-11f1-a949-0242ac1a0002:13' |
| binlog.000003 | 600 | Query | 1 | 680 | BEGIN |
| binlog.000003 | 680 | Table_map | 1 | 744 | table_id: 95 (shop.orders) |
| binlog.000003 | 744 | Update_rows | 1 | 829 | table_id: 95 flags: STMT_END_F |
| binlog.000003 | 829 | Xid | 1 | 860 | COMMIT /* xid=54 */ |
| binlog.000003 | 860 | Gtid | 1 | 939 | SET @@SESSION.GTID_NEXT= 'c5304688-bc81-11f1-a949-0242ac1a0002:14' |
| binlog.000003 | 939 | Query | 1 | 1010 | BEGIN |
| binlog.000003 | 1010 | Table_map | 1 | 1074 | table_id: 95 (shop.orders) |
| binlog.000003 | 1074 | Delete_rows | 1 | 1129 | table_id: 95 flags: STMT_END_F |
| binlog.000003 | 1129 | Xid | 1 | 1160 | COMMIT /* xid=58 */ |
+---------------+------+----------------+-----------+-------------+--------------------------------------------------------------------+
Format_desc,Previous_gtids: 모든 Binlog 파일 앞에 붙는 머리글이에요. 서버 버전과, 이 파일 이전에 실행된 GTID 목록이 들어 있어요.Gtid: 트랜잭션마다 붙는 번호예요. 12, 13, 14번이 차례로 붙었죠.Query(BEGIN): 트랜잭션이 시작됐다는 표시예요.Table_map: 뒤따르는 행 이벤트가 어느 테이블의 것인지 알려 줘요.shop.orders를 95번으로 부르겠다는 뜻입니다.Write_rows,Update_rows,Delete_rows: 각각 INSERT, UPDATE, DELETE로 바뀐 행이에요.Xid: 트랜잭션이 커밋됐다는 표시예요.Pos,End_log_pos: 이벤트가 파일 안에서 시작하고 끝나는 위치예요. 복구나 복제에서 "어디부터 어디까지"를 말할 때 이 값을 씁니다.
출력을 보면 문장은 다섯 개를 실행했는데 트랜잭션은 세 개만 남았어요. SELECT는 데이터를 바꾸지 않으니 기록되지 않았고, ROLLBACK한 트랜잭션도 보이지 않죠.
InnoDB 트랜잭션의 변경은 커밋할 때까지 따로 모아 두었다가, 커밋하는 순간 Binlog에 씁니다. 그래서 커밋하지 않은 변경은 Binlog에 들어가지 않아요.
실습 2: mysqlbinlog로 바뀐 값 보기
SHOW BINLOG EVENTS는 이벤트 종류와 위치만 알려 줄 뿐, 어떤 값으로 바뀌었는지는 보여 주지 않아요. 행의 값은 mysqlbinlog로 읽어야 합니다.
공식 Docker 이미지에는 mysqlbinlog가 들어 있지 않아요. 그래서 macOS에서 Homebrew로 설치한 mysql-client@8.4로 서버에 접속해서 읽을게요.
앞의 출력에서 UPDATE 트랜잭션은 위치 521에서 시작해 860에서 끝났죠. 이 구간만 읽고, 이벤트 머리글과 행 내용만 추려 보겠습니다.
MYSQL_PWD=root mysqlbinlog --read-from-remote-server -h127.0.0.1 -P3371 -uroot --base64-output=DECODE-ROWS -vv --start-position=521 --stop-position=860 binlog.000003 | grep -E "^#[0-9]{6}|^###" | cut -c1-80
#260930 12:49:44 server id 1 end_log_pos 0 CRC32 0xa6051fd0 Start: binlog v 4,
#260930 12:49:55 server id 1 end_log_pos 600 CRC32 0x49f6ba4b GTID last_commit
#260930 12:49:55 server id 1 end_log_pos 680 CRC32 0x64a50daf Query thread_id=
#260930 12:49:55 server id 1 end_log_pos 744 CRC32 0x56b4e7ae Table_map: `shop
#260930 12:49:55 server id 1 end_log_pos 829 CRC32 0xe691f399 Update_rows: tab
### UPDATE `shop`.`orders`
### WHERE
### @1=1 /* INT meta=0 nullable=0 is_null=0 */
### @2='keyboard' /* VARSTRING(80) meta=80 nullable=1 is_null=0 */
### @3=1 /* INT meta=0 nullable=1 is_null=0 */
### @4='paid' /* VARSTRING(40) meta=40 nullable=1 is_null=0 */
### SET
### @1=1 /* INT meta=0 nullable=0 is_null=0 */
### @2='keyboard' /* VARSTRING(80) meta=80 nullable=1 is_null=0 */
### @3=1 /* INT meta=0 nullable=1 is_null=0 */
### @4='shipped' /* VARSTRING(40) meta=40 nullable=1 is_null=0 */
#260930 12:49:55 server id 1 end_log_pos 860 CRC32 0x3800c459 Xid = 54
--read-from-remote-server: 파일을 직접 열지 않고 서버에 접속해서 Binlog를 받아 읽어요.--base64-output=DECODE-ROWS: 행 이벤트를 base64 덩어리로 출력하지 않게 해요.-vv: 행 이벤트를 SQL 비슷한 형태로 풀어 쓰고, 컬럼 타입을 주석으로 붙여 줘요.--start-position,--stop-position: 읽을 구간을Pos,End_log_pos값으로 정해요.
#260930 12:49:55로 시작하는 줄이 이벤트 머리글이에요. 첫 줄의 Start는 mysqlbinlog가 구간과 상관없이 항상 읽는 파일 머리글이고, 시간은 mysqlbinlog를 실행한 컴퓨터의 시간대로 표시돼요.
###로 시작하는 줄이 바뀐 행이에요.
WHERE: 바뀌기 전의 행이에요.status가paid였습니다.SET: 바뀐 뒤의 행이에요.status가shipped가 됐습니다.@1,@2,@3,@4: 컬럼 이름 대신 테이블에서의 순서로 표시돼요. 여기서는id,item,qty,status순서입니다.
바꾼 컬럼은 status 하나뿐인데 행 전체의 이전 값과 이후 값이 모두 남았어요. ROW 형식에서 행을 얼마나 남길지 정하는 binlog_row_image의 기본값이 FULL이기 때문입니다.
실습 3: STATEMENT 형식은 결과가 달라질 수 있습니다
binlog_format은 변경을 어떤 모양으로 기록할지 정하는 설정이에요.
ROW(기본값): 바뀐 행 자체를 기록해요. 지금까지 본Write_rows,Update_rows,Delete_rows가 이 형식입니다.STATEMENT: 실행한 SQL 문장을 그대로 기록해요. Replica는 같은 문장을 다시 실행합니다.
MySQL 8.4에서 binlog_format 변수는 deprecated라서, 바꾸면 경고(1287)가 나오고 이후 버전에서 없어질 수 있어요. 아래 실습은 형식 차이를 보려고 세션에서만 잠시 바꾸는 거예요.
STATEMENT 형식에서 UUID()로 값을 만드는 INSERT를 실행해 볼게요.
src -t -e "SET SESSION binlog_format = 'STATEMENT'; INSERT INTO shop.orders VALUES (10, LEFT(UUID(), 8), 1, 'paid'); SHOW WARNINGS;"
+-------+------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Level | Code | Message |
+-------+------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Note | 1592 | Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement is unsafe because it uses a system function that may return a different value on the replica. |
+-------+------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
MySQL이 문장을 실행하면서 Note 1592를 남겼어요. Replica에서 이 문장을 다시 실행하면 UUID()가 다른 값을 돌려줄 수 있어서 안전하지 않다는 뜻이에요.
정말 그런지 두 서버의 값을 비교해 볼게요.
src -t -e "SELECT * FROM shop.orders WHERE id = 10;"
rep -t -e "SELECT * FROM shop.orders WHERE id = 10;"
+----+----------+------+--------+
| id | item | qty | status |
+----+----------+------+--------+
| 10 | 0d302d80 | 1 | paid |
+----+----------+------+--------+
+----+----------+------+--------+
| id | item | qty | status |
+----+----------+------+--------+
| 10 | 0d325327 | 1 | paid |
+----+----------+------+--------+
복제는 오류 없이 진행됐는데, Source와 Replica의 item이 서로 달라요. Replica가 문장을 다시 실행하면서 UUID()를 새로 불렀기 때문이에요.
이런 차이는 오류로 드러나지 않아요. 그래서 새로 만드는 서버는 기본값 ROW를 그대로 두는 편이 좋습니다.
정리
범위: MySQL 8.4(mysql:8.4, 서버 8.4.11) Source 1대와 Replica 1대, GTID 사용, mysqlbinlog는 Homebrew mysql-client@8.4.
- INSERT, SELECT, UPDATE, DELETE, ROLLBACK한 INSERT 다섯 문장 가운데 Binlog에는 트랜잭션 세 개만 남았습니다. 읽기 이력이나 롤백된 변경은 Binlog에서 찾지 마세요.
- 커밋된 트랜잭션 하나는
Gtid,BEGIN,Table_map, 행 이벤트,Xid순서로 남았고, 이벤트마다Pos와End_log_pos가 붙었습니다. 복구나 복제에서 멈출 위치는SHOW BINLOG EVENTS의Pos와End_log_pos, GTID로 정해 주세요. status하나만 바꿔도FULL에서는 행 전체의 이전 값과 이후 값이 남았습니다. CDC처럼 행 전체가 필요한 곳에서는binlog_row_image를FULL로 두세요.- STATEMENT 형식으로
UUID()를 넣자 복제는 오류 없이 진행됐지만 Source와 Replica의item이0d302d80과0d325327로 달랐습니다. 새 서버는 기본값ROW를 그대로 두세요.