떠나간 데이터... 끄나풀이라도 잡아보자... 😱 (MySQL binlog)
어느 한 날… 프로덕션 서버 (실운영은 안하고 있는 상태)에 생성해놓은 더미 데이터들이 몽땅 사라지는 일을 겪었습니다.
다시 일일이 만들기는 귀찮아서 집 나간 데이터를 되찾아보는 시간을 가졌습니다.
사건 조사
프론트엔드 개발하는 친구로부터 API가 동작하지 않는다며 연락을 받았습니다.
그래서 뭐지? 하며 JAVA 로그를 보는데… 칼럼이 발견되지 않는다는 오류를 보게 되었습니다.
당장 DataGrip을 열고 DB를 확인해 봤는데…. 텅텅 비어 있더라고요?????
아… 누군가 데이터를 날렸구나… 하고 추적에 나섰습니다… (설마 난가?)
일단 binlog를 확인 해 보았습니다. 확인 방법은 다음과 같습니다.
binlog 폴더로 이동하여 binlog.000001 형태의 파일 확인
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
root@localhost:~# cd /var/lib/mysql/
root@localhost:/var/lib/mysql# ls -al
total 104504
drwx------ 10 mysql mysql 4096 Jul 23 00:00 .
drwxr-xr-x 47 root root 4096 Jun 17 08:25 ..
drwxr-x--- 2 mysql mysql 4096 Jul 23 08:17 anabada
-rw-r----- 1 mysql mysql 56 May 28 13:32 auto.cnf
-rw-r----- 1 mysql mysql 2132 Jun 23 00:00 binlog.000036
-rw-r----- 1 mysql mysql 1830 Jun 23 11:38 binlog.000037
-rw-r----- 1 mysql mysql 201 Jun 24 00:00 binlog.000038
-rw-r----- 1 mysql mysql 2756 Jun 25 00:00 binlog.000039
-rw-r----- 1 mysql mysql 201 Jun 26 00:00 binlog.000040
-rw-r----- 1 mysql mysql 3092 Jun 27 00:00 binlog.000041
-rw-r----- 1 mysql mysql 5397 Jun 28 00:00 binlog.000042
-rw-r----- 1 mysql mysql 1057 Jun 29 00:00 binlog.000043
-rw-r----- 1 mysql mysql 2557 Jun 30 00:00 binlog.000044
-rw-r----- 1 mysql mysql 201 Jul 1 00:00 binlog.000045
-rw-r----- 1 mysql mysql 10636 Jul 2 00:00 binlog.000046
-rw-r----- 1 mysql mysql 9793 Jul 3 00:00 binlog.000047
-rw-r----- 1 mysql mysql 201 Jul 4 00:00 binlog.000048
-rw-r----- 1 mysql mysql 201 Jul 5 00:00 binlog.000049
-rw-r----- 1 mysql mysql 3407 Jul 6 00:00 binlog.000050
-rw-r----- 1 mysql mysql 201 Jul 7 00:00 binlog.000051
-rw-r----- 1 mysql mysql 7715 Jul 8 00:00 binlog.000052
-rw-r----- 1 mysql mysql 2847 Jul 9 00:00 binlog.000053
-rw-r----- 1 mysql mysql 13846 Jul 10 00:00 binlog.000054
-rw-r----- 1 mysql mysql 3796 Jul 11 00:00 binlog.000055
-rw-r----- 1 mysql mysql 2384 Jul 11 13:01 binlog.000056
-rw-r----- 1 mysql mysql 201 Jul 12 00:00 binlog.000057
-rw-r----- 1 mysql mysql 201 Jul 13 00:00 binlog.000058
-rw-r----- 1 mysql mysql 17622 Jul 14 00:00 binlog.000059
-rw-r----- 1 mysql mysql 2946 Jul 15 00:00 binlog.000060
-rw-r----- 1 mysql mysql 34372 Jul 16 00:00 binlog.000061
-rw-r----- 1 mysql mysql 8012 Jul 17 00:00 binlog.000062
-rw-r----- 1 mysql mysql 1361 Jul 18 00:00 binlog.000063
-rw-r----- 1 mysql mysql 201 Jul 19 00:00 binlog.000064
-rw-r----- 1 mysql mysql 6082 Jul 20 00:00 binlog.000065
-rw-r----- 1 mysql mysql 2238884 Jul 21 00:00 binlog.000066
-rw-r----- 1 mysql mysql 2256937 Jul 22 00:00 binlog.000067
-rw-r----- 1 mysql mysql 46329 Jul 23 00:00 binlog.000068
-rw-r----- 1 mysql mysql 8412430 Jul 23 08:23 binlog.000069
-rw-r----- 1 mysql mysql 544 Jul 23 00:00 binlog.index
그러고 가장 최근 생성된 binlog부터 살펴보았습니다.
우리가 찾아야 하는 DROP 쿼리를 드디어 찾게 되었습니다.
그런데 보니깐 테이블 칼럼의 주석까지 같이 CREATE되더라고요?
해당 쿼리의 근원을 찾아본 결과 주석이 포함되어 있었기 때문에 ddl-auto의 영향은 아니고, schema.sql이 실행된 것으로 확인했습니다.
저희 프로젝트는 테스트가 실행될 때 테스트 환경에 대해서 schema.sql로 스키마를 초기화하게 해두었습니다.
참고 - 스프링부트에서 sql.init.mode=always를 통해 데이터베이스 초기화할때 주의해야 할 점
다음 명령어를 통해, 쿼리가 실행된 시간을 확인해 보겠습니다.
1
mysqlbinlog /var/lib/mysql/binlog.000068
확인 결과 타임스탬프가 1690022381로 확인되었습니다. 이를 KST로 변경해 보니…
23년 7월 22일 오후 7시 39분으로 확인되었습니다.
검거 완료…(일단 난 아니였다. 다행.)
근데 도대체 어떻게 TEST DB가 아닌 다른 환경의 DB가 날아간 걸까요?
프로젝트의 TEST 리소스의 application.yml을 확인해 보면 TEST DB 용 ID, PW를 환경 변수를 통해 받고 있습니다. 
그래서 이 환경 변수 값을 잘못 설정한 게 아닐까? 싶어서 확인해 보았습니다.
(사건조사 완료…)
집 나간 데이터 복구해 보자…!
일단 최신 버전의 스키마는 Git을 통해 관리하고 있었습니다. (아까 확인했던 Schema.sql 파일)
그래서 테이블을 다 밀어버리고 해당 Schema.sql로 1차적으로 DDL을 복구하였습니다.
이제 데이터를 복구해야 할 차례입니다.
간단한 파이썬 스크립트를 작성하여 다음과 같은 작업을 진행했습니다.
- 특정 binlog 파일들을 하나의. sql 파일로 생성함
- 생성된. sql 파일에서
CREATE TABLE,ALTER TABLE의 쿼리를 주석 처리함- 기타 불필요한 주석 제거 (생성된 최종 SQL를 확인할 때 깔끔하게 확인할 수 있게끔)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
import subprocess
import re
import os
def remove_comments(query):
# binlog 자체로 생긴 주석 제거
return re.sub(r'(?:/\*.*?\*/|#.*?$|--.*?$)', '', query, flags=re.MULTILINE)
def comment_out_drop_create_queries(query):
# DROP, ALTER 문법 주석 처리
return re.sub(r'(?i)^\s*(DROP|ALTER\sTABLE)\s', r'#\g<0>', query, flags=re.MULTILINE)
def extract_binlogs(start_file_number, end_file_number, output_sql_file):
if os.path.exists(output_sql_file):
os.remove(output_sql_file)
mysql_binlog_path = '/usr/bin/mysqlbinlog' # mysqlbinlog 실행 파일 경로를 해당 시스템에 맞게 수정하세요.
mysql_binlog_directory = '/var/lib/mysql/' # 추출하려는 binlog 파일들이 있는 디렉토리 경로를 해당 시스템에 맞게 수정하세요.
merged_query = ''
for file_number in range(int(start_file_number), int(end_file_number) + 1):
binlog_filename = f'binlog.{str(file_number).zfill(6)}'
binlog_filepath = f'{mysql_binlog_directory}{binlog_filename}'
try:
command = f'{mysql_binlog_path} {binlog_filepath}'
output = subprocess.check_output(command, shell=True, text=True)
cleaned_output = remove_comments(output)
cleaned_output = comment_out_drop_create_queries(cleaned_output)
# 정제된 쿼리를 합쳐줍니다.
merged_query += cleaned_output
print(f'Successfully extracted and cleaned {binlog_filename}')
except subprocess.CalledProcessError as e:
print(f'Error extracting {binlog_filename}: {e}')
# 최종적으로 합쳐진 쿼리를 파일로 저장합니다.
with open(output_sql_file, 'w') as f:
f.write(merged_query)
if __name__ == '__main__':
start_file_number = "000000" # 파싱 시작 파일 번호
end_file_number = "000067" # 파싱 끝 파일 번호
output_sql_file = 'output.sql' # 생성할 결과물 파일명
extract_binlogs(start_file_number, end_file_number, output_sql_file)
그러고 생성된 output.sql 파일을 직접 확인하여 일부 쿼리들을 수정해주었습니다.
마지막으로 쿼리를 다음과 같이 실행 시켜 주었습니다.
1
mysql -u root -p -f < ./output.sql
드디어…. 집나간 데이터가 돌아왔습니다!!!
결론
- 백업을 생활화 하자.
디비 백업 전략(추가 관리비가 필요없는 방법)은 어떤 것이 있을까?
스케쥴러를 따로 구성해야할까? 한번 찾아보고 도입 해 보아야겠다.- 민감정보가 담길 수 있는 yml을 관리하는 법을 추가로 생각해봐야겠다.
Comments powered by Disqus.