MySQL이 안 뜨거나 재시작될 때 Error Log는 어떻게 읽을까?

Q: MySQL이 안 뜨거나 재시작될 때 Error Log는 어떻게 읽을까?

시작 실패와 크래시의 원인은 Error log에 남으므로 Error log부터 연다. 설정 이름 오타의 unknown variable은 InnoDB 초기화가 끝난 뒤에야 나왔고, SIGKILL 크래시는 Shutdown complete 없이 다음 시작이 이어진 자리로 드러났다.

이번 시간에는 MySQL의 시작 실패와 크래시를 직접 만들어 보고, 그때마다 Error log에 무엇이 남는지와 어떤 순서로 읽어야 하는지를 확인하며 배워가는 시간입니다.

예를 들어서 배포하면서 MySQL 설정을 하나 바꾸고 재시작했는데 서버가 올라오지 않는다고 해볼게요. 애플리케이션 로그에는 DB에 연결할 수 없다는 메시지만 반복되고요.

이럴 때 원인이 남아 있는 곳이 MySQL의 Error log예요.

실습 준비

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

compose.yaml: MySQL 8.4 source(conf.d 디렉터리와 /var/log/mysql 볼륨 연결)와 replica
error-log.cnf: 본문의 conf.d/error-log.cnf와 같은 내용(Error log를 파일로)
tuning.cnf: 본문에서 오타를 고친 conf.d/tuning.cnf와 같은 내용

Docker Compose(compose.yaml)로 MySQL 8.4 두 대를 띄울게요. source는 설정 파일을 넣을 conf.d 디렉터리와 로그를 둘 /var/log/mysql 볼륨을 연결해 두었어요. replica는 복제를 받는 서버인데, 이 글에서는 쓰지 않아요.

컨테이너를 띄우고, 매번 긴 명령을 입력하지 않도록 source 컨테이너의 mysql 클라이언트를 실행하는 셸 함수 src를 만들어 둘게요. MYSQL_PWD 환경 변수로 비밀번호를 넘기는 방식은 실습에서만 써 주세요.

mkdir -p conf.d
docker compose up -d

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

공식 Docker 이미지는 Error log를 파일이 아니라 표준 오류(stderr)로 내보내요. 그래서 Error log가 컨테이너 로그로 나가요. 방금 시작한 서버의 마지막 기록을 볼게요.

docker compose logs source | tail -n 9

source-1  | 2026-09-29T07:44:07.916982Z 0 [System] [MY-015015] [Server] MySQL Server - start.
source-1  | 2026-09-29T07:44:08.160368Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.4.11) starting as process 1
source-1  | 2026-09-29T07:44:08.170277Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
source-1  | 2026-09-29T07:44:08.647348Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
source-1  | 2026-09-29T07:44:08.923238Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
source-1  | 2026-09-29T07:44:08.923293Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
source-1  | 2026-09-29T07:44:08.927445Z 0 [Warning] [MY-011810] [Server] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
source-1  | 2026-09-29T07:44:08.959608Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /var/run/mysqld/mysqlx.sock
source-1  | 2026-09-29T07:44:08.960432Z 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.

한 줄은 이런 순서로 읽으시면 됩니다.

2026-09-29T07:44:07.916982Z: 기록한 시간이에요. 끝의 Z는 UTC라는 뜻이에요.
0: 메시지를 남긴 스레드 ID예요.
[System]: 우선순위예요.
[MY-015015]: 오류 코드예요. 같은 문제는 같은 코드로 남기 때문에 검색하거나 집계할 때 써요.
[Server]: 메시지를 남긴 서브시스템이에요. InnoDB, Repl 등이 있어요.

MySQL Server - start로 시작해 InnoDB 초기화를 거치고 ready for connections로 끝나면 정상적으로 켜진 거예요. 이 흐름을 알고 있으면 시작이 실패했을 때 어느 단계에서 멈췄는지 바로 보여요.

실습 1: 로그 파일을 열지 못한 경우

Error log를 컨테이너 로그 대신 파일로 남기도록 conf.d/error-log.cnf를 만들어 볼게요.

[mysqld]
log_error = /var/log/mysql/error.log

재시작한 뒤 컨테이너 상태를 확인합니다.

docker compose restart source
docker compose ps -a source --format '{{.Name}} {{.Status}}'

elog-source-1 Exited (1) 9 seconds ago

서버가 꺼졌어요. 로그 파일을 열지 못했기 때문에, 이 오류는 파일이 아니라 컨테이너 로그에 남아 있어요.

docker compose logs source | tail -n 4

source-1  | 2026-09-29T07:44:36.546931Z 0 [ERROR] [MY-010187] [Server] Could not open file '/var/log/mysql/error.log' for error logging: Permission denied
source-1  | 2026-09-29T07:44:36.547018Z 0 [ERROR] [MY-010119] [Server] Aborting
source-1  | 2026-09-29T07:44:36.549023Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.4.11)  MySQL Community Server - GPL.
source-1  | 2026-09-29T07:44:36.549029Z 0 [System] [MY-015016] [Server] MySQL Server - end.

ERROR가 두 줄이에요. 그런데 Aborting은 시작을 포기했다는 결과일 뿐이고, 원인은 바로 앞 줄의 Permission denied예요.

왜 권한이 없었을까요? 새로 만든 볼륨의 /var/log/mysql은 root 소유인데, MySQL은 mysql 사용자로 실행되기 때문에 파일을 만들 수 없었던 거예요.

디렉터리 소유자를 바꾸고 다시 시작해 볼게요.

docker compose run --rm --no-deps --user root --entrypoint chown source mysql:mysql /var/log/mysql
docker compose start source
docker compose exec source ls /var/log/mysql
docker compose exec source tail -n 3 /var/log/mysql/error.log

error.log
2026-09-29T07:45:00.394487Z 0 [Warning] [MY-011810] [Server] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2026-09-29T07:45:00.445582Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /var/run/mysqld/mysqlx.sock
2026-09-29T07:45:00.445931Z 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.

서버가 다시 켜졌고, Error log도 파일에 쌓이기 시작했어요.

실습 2: 설정 이름을 잘못 쓴 경우

이번에는 버퍼 풀 크기를 바꾸면서 변수 이름을 innodb_bufer_pool_size로 잘못 적은 conf.d/tuning.cnf를 넣고 재시작해 볼게요.

[mysqld]
innodb_bufer_pool_size = 256M

docker compose restart source
docker compose ps -a source --format '{{.Name}} {{.Status}}'
docker compose logs source | tail -n 3

elog-source-1 Exited (1) 8 seconds ago
source-1  | 2026-09-29 07:45:23+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
source-1  | 2026-09-29 07:45:23+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.4.11-1.el9 started.
source-1  | '/var/lib/mysql/mysql.sock' -> '/var/run/mysqld/mysqld.sock'

서버는 꺼졌는데, 컨테이너 로그에는 이미지의 시작 스크립트가 남긴 메시지뿐이에요. Error log를 파일로 바꿨으니 원인은 파일에 있어요.

컨테이너가 꺼져 있어서 exec를 쓸 수 없으니, 같은 볼륨을 연결한 임시 컨테이너로 파일을 읽어 볼게요.

docker compose run --rm --no-deps --entrypoint tail source -n 11 /var/log/mysql/error.log

2026-09-29T07:45:23.443559Z 0 [System] [MY-015015] [Server] MySQL Server - start.
2026-09-29T07:45:23.762766Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.4.11) starting as process 1
2026-09-29T07:45:23.782007Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2026-09-29T07:45:24.582973Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2026-09-29T07:45:25.167656Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2026-09-29T07:45:25.167752Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2026-09-29T07:45:25.174015Z 0 [Warning] [MY-011810] [Server] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2026-09-29T07:45:25.181779Z 0 [ERROR] [MY-000067] [Server] unknown variable 'innodb_bufer_pool_size=256M'.
2026-09-29T07:45:25.182818Z 0 [ERROR] [MY-010119] [Server] Aborting
2026-09-29T07:45:26.666708Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.4.11)  MySQL Community Server - GPL.
2026-09-29T07:45:26.666741Z 0 [System] [MY-015016] [Server] MySQL Server - end.

원인은 unknown variable이에요.

여기서 눈여겨볼 건 이 오류가 InnoDB 초기화가 끝난 뒤에야 나왔다는 점이에요. InnoDB까지 올라왔으니 설정은 괜찮다고 앞부분만 보고 판단하면 원인을 놓쳐요. 그래서 시작 로그는 MySQL Server - end까지 읽어 주세요.

오타를 고친 conf.d/tuning.cnf로 다시 시작합니다.

[mysqld]
innodb_buffer_pool_size = 256M

docker compose start source
docker compose ps -a source --format '{{.Name}} {{.Status}}'

elog-source-1 Up 12 seconds

실습 3: 크래시 뒤에는 마지막 몇 줄을 봅니다

서버가 갑자기 죽으면 Error log에서 두 군데를 봐요. 죽기 직전의 마지막 줄들과, 다시 시작하면서 남긴 복구 메시지예요.

테이블을 하나 만든 뒤, 컨테이너에 SIGKILL을 보내 강제로 종료해 볼게요. 전원이 나가거나 OS가 메모리 부족으로 프로세스를 죽인 것과 비슷한 상황이에요.

src -e "CREATE DATABASE shop; CREATE TABLE shop.orders (id INT AUTO_INCREMENT PRIMARY KEY, amount INT); INSERT INTO shop.orders (amount) VALUES (1000), (2000);"
docker compose kill -s SIGKILL source
docker compose start source
docker compose exec source tail -n 13 /var/log/mysql/error.log

2026-09-29T07:47:02.477317Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /var/run/mysqld/mysqlx.sock
2026-09-29T07:47:02.478772Z 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.
2026-09-29T07:47:28.441196Z 0 [System] [MY-015015] [Server] MySQL Server - start.
2026-09-29T07:47:28.689284Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.4.11) starting as process 1
2026-09-29T07:47:28.695886Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2026-09-29T07:47:29.010302Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2026-09-29T07:47:29.080510Z 0 [System] [MY-010229] [Server] Starting XA crash recovery...
2026-09-29T07:47:29.094430Z 0 [System] [MY-010232] [Server] XA crash recovery finished.
2026-09-29T07:47:29.162619Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2026-09-29T07:47:29.162639Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2026-09-29T07:47:29.164393Z 0 [Warning] [MY-011810] [Server] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2026-09-29T07:47:29.176700Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /var/run/mysqld/mysqlx.sock
2026-09-29T07:47:29.176719Z 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.

정상 종료였다면 ready for connections와 MySQL Server - start 사이에 Received SHUTDOWN과 Shutdown complete가 있어야 해요. 그런데 여기서는 종료 기록 없이 바로 다음 시작이 이어지죠.

SIGKILL은 프로세스를 즉시 끝내기 때문에 MySQL이 아무것도 남기지 못했어요. 이렇게 종료 기록이 빠진 자리가 비정상 종료의 흔적이 됩니다.

다시 시작할 때는 Starting XA crash recovery가 남았어요. 정상 종료 뒤의 시작 기록에는 없던 줄이에요. 다만 남길 메시지 등급을 정하는 log_error_verbosity가 기본값 2(Error와 Warning까지)일 때는 InnoDB가 무엇을 복구했는지까지는 보이지 않아요.

정리

범위: MySQL 8.4.11(mysql:8.4 이미지), Docker Compose, log_error_verbosity 기본값 2.

볼륨의 /var/log/mysql이 root 소유라 log_error를 파일로 바꾸자 서버가 Permission denied로 시작하지 못했고, 이 오류는 파일이 아니라 컨테이너 로그에 남았습니다. 컨테이너에서 Error log를 파일로 바꿀 때는 디렉터리 소유자를 mysql로 맞춰 주세요.
변수 이름 오타의 unknown variable은 InnoDB 초기화가 끝난 뒤에야 나왔고, 파일로 바꾼 뒤라 docker logs에는 원인이 없었습니다. 시작 로그는 MySQL Server - end까지 읽고, 파일로 남기는 서버는 파일을 열어 보세요.
SIGKILL로 죽인 뒤 로그에는 Shutdown complete 없이 다음 MySQL Server - start가 이어졌습니다. 크래시를 의심하면 종료 기록이 빠진 자리부터 찾아보세요.
이 글에 싣지 않은 추가 측정에서는 log_error_verbosity를 1로 줄여도 System 7개는 남았고, 3에서는 시작 한 번에 Note가 72개 늘었으며 InnoDB 크래시 복구 메시지(Rolling back trx ..., 6 rows to undo)도 3에서만 보였습니다. 평소에는 2로 두고 원인을 좁히는 동안에만 3으로 올리세요.
이 글에 싣지 않은 추가 측정에서는 Replica 중복 키 오류에서 Last_SQL_Error가 실패한 트랜잭션만 알렸고 Error log에는 Duplicate entry '100' 원인이 시간 순서로 남았으며, 07:49:47의 두 번째 ERROR는 같은 시간 Source 재시작 때문이었습니다. 장애 때는 시간 범위를 정하고, 그 안의 ERROR와 WARNING을 찾고, 앞뒤 메시지를 읽은 뒤, 다른 서버 기록과 시간을 맞춰 보세요.