MariaDB SQL 로그가 서버를 마비시킨 날
16GB만으로 서비스가 마비된 이유
여는 글
안녕하세요. 오늘은 실무에서 겪은 DB 장애 경험을 공유하려 합니다. DB가 다운되지도 않았고, 네트워크 문제도 없었으며, 어플리케이션의 SQL 쿼리도 정상이었지만 데이터베이스가 정상 동작하지 않았던 날의 이야기입니다.
사건의 발단 - 갑작스러운 장애 발생
평소와 다름없던 어느 월요일 오전 9시 30분경, 운영팀으로부터 이상동작을 전달받았습니다.
장애 개요
- 발생 시각: 추정불가
- 인지 시각: 월요일 09:30 (운영팀 리포트)
- 복구 시각: 월요일 10:45
- 총 대응 시간: 약 1시간 15분
- 영향 범위: 해당 DB를 사용하는 모든 쓰기 작업 실패
장애 증상
- INSERT, UPDATE 쿼리가 전혀 실행되지 않음
- SELECT 쿼리는 간헐적으로 동작하며, Lock에 걸리는 현상 발생
- DB 서버는 정상 구동 중
- 애플리케이션 로그에는 특별한 에러 없음
- 네트워크 연결 상태 양호
가장 당황스러운 점은 명확한 에러 메시지가 없었다는 것입니다. 회사에서 베어메탈 장비 모니터링이나 DB 모니터링을 하고 있지 않았기 때문에, 당장에 추적할 방법은 SQL 쿼리를 통해 DB의 현 상태를 파악하는 것뿐이었습니다. 단순히 INSERT/UPDATE가 조용히 실패하고 Lock이 간헐적으로 걸리는 상황이었습니다.
초기 트러블슈팅 과정
※ 참고사항: 아래 트러블슈팅 과정은 Claude의 도움을 받아 재구성한 것입니다. 따라서, 같은 문제를 겪으시는 분들의 해결 경로가 100% 일치하지 않을 수 있습니다.
1단계: 기본적인 확인
# DB 서버 상태 확인
sudo systemctl status mariadb
● mariadb.service - MariaDB 10.6.7 database server
Loaded: loaded
Active: active (running) since Mon 2024-03-25 08:00:00 KST
# 프로세스 확인
ps aux | grep mysql
mysql 1234 0.5 2.1 1234567 123456 ? Sl 08:00 0:05 /usr/sbin/mysqld
# 네트워크 연결 확인
telnet db-server 3306
Trying 192.168.1.100...
Connected to db-server.
모든 기본 상태는 정상이었습니다.
2단계: MariaDB 접속 및 상태 확인
-- DB 접속은 정상
mysql -u root -p
-- 기본 상태 확인
SHOW STATUS LIKE 'Connections';
SHOW PROCESSLIST;
SHOW ENGINE INNODB STATUS;
여기서도 특별한 이상은 발견되지 않았습니다. 쿼리들이 Lock 상태에 걸려있는 것이 보였는데, 이것이 근본 원인이라기보다는 증상 중 하나라고 생각했습니다.
3단계: 시스템 리소스 확인
# 메모리 사용량 확인
free -h # 정상
# CPU 사용량 확인
top # 정상
# 디스크 사용량 확인 - 여기서 문제 발견!
df -h
Filesystem Size Used Avail Use% Mounted on
## 실제 경로 아님
...
/dev/sda1 16G 16G 0 100% /boot
...
사실 100%가 사용된 것을 확인하고도 이것이 원인이라고 확신할 수 없었지만, 제일 의심스러운 지표이긴 했습니다. 몇 TB 단위의 베어메탈 장비에서 다른 Filesystem은 여유가 있는데 유독 해당 Filesystem만 가득 찬 상황이었습니다. 따라서 무엇이 용량을 차지하고 있는지 확인했습니다.
범인 찾기
큰 파일들 찾기
# 큰 파일들 찾기
find / -type f -size +1G 2>/dev/null | head -20
# /var/lib/mysql 디렉토리 확인
du -sh /var/lib/mysql/*
128M /var/lib/mysql/payment_db
256M /var/lib/mysql/mysql
1.7G /var/lib/mysql/mysql-general.log # 범인 발견!
mysql-general.log 파일이 범인이었습니다
MariaDB General Log 확인
-- General Log 설정 확인
SHOW VARIABLES LIKE 'general_log';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| general_log | ON |
+---------------+-------+
SHOW VARIABLES LIKE 'general_log_file';
+------------------+----------------------------------+
| Variable_name | Value |
+------------------+----------------------------------+
| general_log_file | /var/lib/mysql/mysql-general.log |
+------------------+----------------------------------+
-- 로그 로테이션 설정 확인
SHOW VARIABLES LIKE 'log_output';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_output | FILE |
+---------------+-------+
문제의 핵심을 파악했습니다.
- General Log가 활성화되어 있음
- 모든 SQL 쿼리가 하나의 파일에 계속 기록됨
- 로그 로테이션이 설정되어 있지 않음
- 일별 백업/삭제 프로세스 없음
응급 처치: 서비스 복구
1단계: 즉시 디스크 공간 확보
# 우선 General Log 백업 (중요한 정보가 있을 수 있음)
sudo cp /var/lib/mysql/mysql-general.log /backup/mysql-general-$(date +%Y%m%d).log
# General Log 파일 비우기 (삭제하면 MariaDB에서 문제가 될 수 있음)
sudo truncate -s 0 /var/lib/mysql/mysql-general.log
# 디스크 공간 확인
df -h
2단계: General Log 임시 비활성화
-- 즉시 General Log 비활성화
SET GLOBAL general_log = 'OFF';
-- 설정 확인
SHOW VARIABLES LIKE 'general_log';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| general_log | OFF |
+---------------+-------+
3단계: 서비스 정상성 확인
-- INSERT 테스트
INSERT INTO test_table (message, created_at) VALUES ('test', NOW());
Query OK, 1 row affected (0.01 sec)
-- UPDATE 테스트
UPDATE test_table SET message = 'updated' WHERE id = 1;
Query OK, 1 row affected (0.01 sec)
서비스가 정상 복구되었습니다
근본 원인 분석
MariaDB General Log란?
General Log는 MariaDB/MySQL에서 제공하는 로깅 기능으로, 서버에서 실행되는 모든 SQL 문과 연결 정보를 기록합니다.
-- General Log에 기록되는 내용들
/*
2024-03-25T09:15:23.123456Z 123 Connect user@localhost on payment_db
2024-03-25T09:15:23.234567Z 123 Query SELECT * FROM transactions WHERE id = 12345
2024-03-25T09:15:23.345678Z 123 Query UPDATE transactions SET status = 'COMPLETED' WHERE id = 12345
2024-03-25T09:15:23.456789Z 123 Quit
*/
문제점
- 모든 쿼리가 기록되어 용량이 빠르게 증가
- 로그 로테이션이 기본적으로 설정되어 있지 않음
- 성능에도 약간의 영향을 미침
왜 디스크가 가득 차면 INSERT/UPDATE가 안 될까?
이 부분을 이해하려면 InnoDB의 내부 동작을 알아야 합니다.
InnoDB의 쓰기 과정
[INSERT/UPDATE 요청]
↓
[InnoDB Buffer Pool] ← 메모리에 변경 사항 저장
↓
[Redo Log (ib_logfile)] ← 트랜잭션 내구성 보장 (WAL)
↓
[Checkpoint] → 디스크의 실제 데이터 파일에 반영
InnoDB는 Write-Ahead Logging(WAL) 방식을 사용합니다. 데이터 변경 시 먼저 Redo Log에 기록하고, 나중에 실제 데이터 파일에 반영합니다. 이 방식 덕분에 장애 발생 시에도 데이터를 복구할 수 있습니다.
디스크 풀 시 발생하는 일
# 디스크 공간이 없을 때 발생하는 일들
1. Redo Log 기록 실패 → 트랜잭션 커밋 불가
2. Undo Log 기록 실패 → 롤백을 위한 정보 저장 불가
3. 임시 테이블 생성 실패 → 복잡한 쿼리 실행 불가
4. Binary Log 기록 실패 → 복제 중단
5. InnoDB가 쓰기 작업을 무한 대기 상태로 전환
중요한 점은 InnoDB가 디스크 풀 상황에서 에러를 던지지 않고 무한 대기한다는 것입니다. 이것이 “조용히 실패”하는 것처럼 보였던 이유입니다.
SELECT는 왜 되었나?
- SELECT는 Buffer Pool의 데이터를 읽는 작업
- 디스크 쓰기가 필요 없으므로 대부분 정상 동작
- 단, 쓰기 작업이 테이블 Lock을 잡고 대기 중이면 해당 테이블 SELECT도 대기
실제로 이 과정에서 SELECT는 되지만 간헐적으로 Lock에 걸리던 현상의 원인도 명확해졌습니다. 디스크 공간 부족으로 인해 트랜잭션 처리가 제대로 되지 않으면서 테이블 Lock이 발생했던 것이었습니다.
참고: innodb_force_recovery
만약 디스크 풀로 인해 MariaDB가 아예 시작되지 않는 상황이라면, innodb_force_recovery 옵션을 사용해 복구 모드로 시작할 수 있습니다. 하지만 이번 케이스에서는 서비스가 구동 중이었으므로 해당되지 않았습니다.
다른 로그 타입들과의 비교
General Log 외에도 MariaDB에는 여러 로그 타입이 있습니다. 각 로그의 특징을 이해하면 적절한 설정을 하는 데 도움이 됩니다.
로그 타입별 특징
| 로그 타입 | 용도 | 크기 증가 속도 | 성능 영향 | 운영 필요성 |
|---|---|---|---|---|
| General Log | 모든 쿼리 기록 | 매우 빠름 | 높음 | 디버깅 시에만 |
| Slow Query Log | 느린 쿼리 기록 | 보통 | 낮음 | 권장 |
| Error Log | 에러/경고 기록 | 느림 | 없음 | 필수 |
| Binary Log | 복제/백업용 | 빠름 | 보통 | 복제 시 필수 |
권장 설정
-- 개발 환경
SET GLOBAL general_log = 'ON'; -- 디버깅 시에만 일시적으로
-- 운영 환경
SET GLOBAL general_log = 'OFF'; -- 기본 OFF
SET GLOBAL slow_query_log = 'ON'; -- 성능 모니터링용
SET GLOBAL long_query_time = 2; -- 2초 이상 쿼리만 기록
영구적 해결책 구현
1. General Log 로테이션 설정
처음에는 General Log를 아예 비활성화하려 했습니다. 하지만 기록되는 내용이 유의미한 지표이고, 당장 필요하지 않더라도 로그는 보존해야 하므로 다른 방법을 찾아야 했습니다.
# logrotate 설정 파일 생성
sudo vi /etc/logrotate.d/mysql-general
# 설정 내용
/var/lib/mysql/mysql-general.log {
daily
rotate 7
compress
delaycompress
missingok
notifempty
create 644 mysql mysql
postrotate
if test -x /usr/bin/mysqladmin && \
/usr/bin/mysqladmin ping &>/dev/null
then
/usr/bin/mysqladmin flush-logs
fi
endscript
}
2. 모니터링 체계 구축
이번 장애의 근본적인 문제는 사전 감지 체계의 부재였습니다. 디스크가 100%가 될 때까지 아무도 몰랐다는 것이 가장 큰 문제였습니다.
오픈소스 모니터링 툴인 Zabbix를 구축하고, 다음과 같은 알림 체계를 설정했습니다.
디스크 사용률 알림 설정
| 임계값 | 심각도 | 알림 채널 | 액션 |
|---|---|---|---|
| 70% | Warning | Telegram | 인지 |
| 80% | High | Telegram + Email | 점검 필요 |
| 90% | Critical | Telegram + Email | 즉시 대응 |
추가 모니터링 항목
- MariaDB 프로세스 상태
- Slow Query 발생 빈도
- 테이블 Lock 대기 시간
- Binary Log / General Log 파일 크기
이제 디스크 사용률이 70%만 넘어도 Telegram 알림이 오기 때문에, 100%가 되기 전에 충분히 대응할 수 있게 되었습니다.
3. MariaDB 설정 최적화
# /etc/mysql/mariadb.conf.d/50-server.cnf
[mysqld]
# General Log 설정
general_log = 0 # 기본값을 OFF로 설정
general_log_file = /var/lib/mysql/mysql-general.log
# Slow Query Log (필요한 경우만)
slow_query_log = 1
slow_query_log_file = /var/lib/mysql/mysql-slow.log
long_query_time = 2
# Binary Log (복제나 백업용)
log-bin = mysql-bin
expire_logs_days = 7
max_binlog_size = 100M
개선 효과 측정
이번 장애 대응과 시스템 개선이 실제로 효과가 있었는지 측정했습니다.
Before vs After 비교
| 항목 | 개선 전 | 개선 후 |
|---|---|---|
| 장애 감지 방식 | 운영팀 수동 리포트 | Zabbix 자동 알림 |
| 예상 감지 시점 | 디스크 100% (장애 발생 후) | 디스크 70% (장애 발생 전) |
| 예상 MTTR | 1시간 15분 | 15분 이내 |
| 동일 장애 재발 가능성 | 있음 | 없음 (자동 로테이션) |
맺는글
이번 장애를 통해 배운 교훈들이 있습니다.
- 로그 관리의 중요성: 애플리케이션 로그뿐만 아니라 DB 로그도 적절한 로테이션과 관리가 필요합니다
- 디스크 모니터링 필수: 디스크 사용률 모니터링은 선택이 아닌 필수입니다
- General Log는 신중하게: 개발 환경에서만 일시적으로 사용하는 것이 바람직합니다
- 증상보다 원인: DB가 정상이어도 시스템 레벨의 문제가 있을 수 있습니다
- 예방이 최선: 사전 모니터링과 알림 시스템이 장애를 예방하는 최선의 방법입니다
- 선입견의 위험: 평소 경험에 의존해서 문제의 원인을 미리 단정짓지 말자
로그 파일로 인해 전체 서비스가 마비되는 경험을 했습니다. General Log에 대해서는 이번에 처음 알게 된 내용이라 DB 로그는 전혀 의심하지 못했던 것이 아쉬웠습니다. 다행히 빠른 대응으로 서비스를 복구할 수 있었고, 이런 상황을 반복하지 않기 위해 예방 시스템을 구축했습니다.
실제 트러블슈팅 과정은 이 포스팅에서 보여드린 것보다 훨씬 더 우회가 많았고 시간도 오래 걸렸지만, 비슷한 상황에 처한 개발자들에게 이 경험이 조금이라도 도움이 되길 바랍니다.