DataAccessResourceFailureException

2024. 7. 13. 23:36ㆍ실무/ISSUE

어느 날, 갑자기.. 개발망 spring batch 서버에서 

DataAccessResourceFailureException: Unable to commit new sequence value changes for BATCH_JOB_SEQ

 

위와 같은 에러가 발생하면서, batch에서 동작하는 Job 실패 알림이 지속적으로 왔다.

원인을 짐작할 수 없었다. 왜냐! 해당 서버에 대해 건든 것이 없었기 때문이다,,

 

처음에 이슈 원인이 뭘까,, 해당 batch 서버(A)의 db connection pool 이슈인가? 싶었는데, 다른 batch 서버(B)에서도 위 같은 에러가 동일하게 발생하고 있었다. 

그 순간, A,B 서버가 공통으로 사용하고 있는 db 서버에 이슈가 있을 것 같다라는 느낌이 들었고, db 서버를 확인했다

 

→ TMI

  • 리얼망 db 서버는 DBA분이 관리해주고 계시지만, 개발망 db 서버는 서비스 개발자가 관리하고 있다
  • db로는 MySql 5.7.17 버전 을 사용하고 있다

이전에도 db 서버 관련 이슈가 있었는데 disk 용량 이슈였던적이 있어, 우선적으로 db 서버 disk 용량을 확인해봤다.

[irteam@${server name} ~]$ df -h
Filesystem      Size  Used Avail Use% Mounted on
/dev/xvda1      9.8G  3.5G  6.3G  36% /
tmpfs           3.9G  208K  3.9G   1% /dev/shm
/dev/xvda2       89G   88G   0G  99% /home1

 

혹시나 했더니 역시나였다!  `/home1` 경로의 disk 용량이 부족했었다

정확히 어느 경로의 디렉토리 disk가 비정상적으로 많이 쌓였나 찾아보았다.

[irteam@${server name} data]$ pwd
/home1/irteam/db/mysql_13306/data
[irteam@${server name} data]$ du -sh
88G
[irteam@${server name} data]$ ls -alh
total 88G
-rw-r-----  1 irteam irteam 1.1G Jun 27  2022 mysql-bin.000050
-rw-r-----  1 irteam irteam 1.1G Jul 24  2022 mysql-bin.000051
-rw-r-----  1 irteam irteam 1.1G Aug 20  2022 mysql-bin.000052
-rw-r-----  1 irteam irteam 1.1G Sep 15  2022 mysql-bin.000053
-rw-r-----  1 irteam irteam 1.1G Oct 12  2022 mysql-bin.000054
-rw-r-----  1 irteam irteam 1.1G Nov  7  2022 mysql-bin.000055
-rw-r-----  1 irteam irteam 1.1G Nov 29  2022 mysql-bin.000056
-rw-r-----  1 irteam irteam 1.1G Dec 15  2022 mysql-bin.000057
-rw-r-----  1 irteam irteam 1.1G Dec 31  2022 mysql-bin.000058
-rw-r-----  1 irteam irteam 1.1G Jan 15  2023 mysql-bin.000059
-rw-r-----  1 irteam irteam 1.1G Jan 31  2023 mysql-bin.000060
-rw-r-----  1 irteam irteam 1.1G Feb 19  2023 mysql-bin.000061
-rw-r-----  1 irteam irteam 1.1G Feb 28  2023 mysql-bin.000062
-rw-r-----  1 irteam irteam 1.1G Mar  7  2023 mysql-bin.000063
-rw-r-----  1 irteam irteam 1.1G Mar 23  2023 mysql-bin.000064
-rw-r-----  1 irteam irteam 1.1G Apr  8  2023 mysql-bin.000065
-rw-r-----  1 irteam irteam 1.1G Apr 24  2023 mysql-bin.000066
-rw-r-----  1 irteam irteam 1.1G May 10  2023 mysql-bin.000067
-rw-r-----  1 irteam irteam 1.1G May 25  2023 mysql-bin.000068
-rw-r-----  1 irteam irteam 1.1G Jun 10  2023 mysql-bin.000069
-rw-r-----  1 irteam irteam 1.1G Jun 26  2023 mysql-bin.000070
-rw-r-----  1 irteam irteam 1.1G Jul 12  2023 mysql-bin.000071
-rw-r-----  1 irteam irteam 1.1G Jul 29  2023 mysql-bin.000072
-rw-r-----  1 irteam irteam 1.1G Aug 16  2023 mysql-bin.000073
-rw-r-----  1 irteam irteam 1.1G Sep 10  2023 mysql-bin.000074
-rw-r-----  1 irteam irteam 1.1G Oct 18  2023 mysql-bin.000075
-rw-r-----  1 irteam irteam 1.1G Nov  5  2023 mysql-bin.000076
-rw-r-----  1 irteam irteam 1.1G Nov 21  2023 mysql-bin.000077
-rw-r-----  1 irteam irteam 1.1G Dec  7  2023 mysql-bin.000078
-rw-r-----  1 irteam irteam 1.1G Dec 23  2023 mysql-bin.000079
-rw-r-----  1 irteam irteam 1.1G Jan  8  2024 mysql-bin.000080
-rw-r-----  1 irteam irteam 1.1G Jan 24 04:45 mysql-bin.000081
-rw-r-----  1 irteam irteam 1.1G Feb  9 02:04 mysql-bin.000082
-rw-r-----  1 irteam irteam 1.1G Feb 25 02:00 mysql-bin.000083
-rw-r-----  1 irteam irteam 1.1G Mar 11 10:30 mysql-bin.000084
-rw-r-----  1 irteam irteam 1.1G Mar 27 09:35 mysql-bin.000085
-rw-r-----  1 irteam irteam 1.1G Apr 12 08:28 mysql-bin.000086
-rw-r-----  1 irteam irteam 1.1G Apr 28 06:51 mysql-bin.000087
-rw-r-----  1 irteam irteam 1.1G May 14 04:59 mysql-bin.000088
-rw-r-----  1 irteam irteam 1.1G May 30 03:13 mysql-bin.000089
-rw-r-----  1 irteam irteam 1.1G Jun 15 02:11 mysql-bin.000090
-rw-r-----  1 irteam irteam 1.1G Jul  1 02:00 mysql-bin.000091
-rw-r-----  1 irteam irteam 818M Jul 13 23:00 mysql-bin.000092
...

 

특정 디렉토리에 mysql binary log가 굉장히 많이 쌓여있었음을 확인할 수 있었고 일정 기간이 지난 파일들은 지워야겠다는 생각이 들었다.  우선, mysql에 직접 접근하여 binary log를 확인해보자!

mysql> show binary logs;
+------------------+------------+
| Log_name         | File_size  |
+------------------+------------+
| mysql-bin.000050 | 1073742071 |
| mysql-bin.000051 | 1073742307 |
| mysql-bin.000052 | 1073741929 |
| mysql-bin.000053 | 1073741873 |
| mysql-bin.000054 | 1077103014 |
| mysql-bin.000055 | 1073741913 |
| mysql-bin.000056 | 1073742589 |
| mysql-bin.000057 | 1073742758 |
| mysql-bin.000058 | 1073742294 |
| mysql-bin.000059 | 1073742365 |
| mysql-bin.000060 | 1073742920 |
| mysql-bin.000061 | 1075621343 |
| mysql-bin.000062 | 1073742153 |
| mysql-bin.000063 | 1073742206 |
| mysql-bin.000064 | 1073741974 |
| mysql-bin.000065 | 1073741974 |
| mysql-bin.000066 | 1073742033 |
| mysql-bin.000067 | 1073742184 |
| mysql-bin.000068 | 1073742579 |
| mysql-bin.000069 | 1073742020 |
| mysql-bin.000070 | 1073741890 |
| mysql-bin.000071 | 1073742350 |
| mysql-bin.000072 | 1073742040 |
| mysql-bin.000073 | 1076148295 |
| mysql-bin.000074 | 1078161830 |
| mysql-bin.000075 | 1073742126 |
| mysql-bin.000076 | 1073742244 |
| mysql-bin.000077 | 1073742356 |
| mysql-bin.000078 | 1073742044 |
| mysql-bin.000079 | 1073741944 |
| mysql-bin.000080 | 1073741882 |
| mysql-bin.000081 | 1073742078 |
| mysql-bin.000082 | 1073742475 |
| mysql-bin.000083 | 1079261030 |
| mysql-bin.000084 | 1073742342 |
| mysql-bin.000085 | 1073742044 |
| mysql-bin.000086 | 1073742815 |
| mysql-bin.000087 | 1073742014 |
| mysql-bin.000088 | 1073742360 |
| mysql-bin.000089 | 1073742529 |
| mysql-bin.000090 | 1073741920 |
| mysql-bin.000091 | 1076661477 |
| mysql-bin.000092 |  855870954 |
+------------------+------------+
43 rows in set (0.00 sec)

 

 

흠,, 많이도 쌓여있군! 그렇다면 로그 보관 기간이 따로 설정되어 있나? 확인해보자!

mysql> show variables like 'expire%';
+------------------+-------+
| Variable_name    | Value |
+------------------+-------+
| expire_logs_days | 0     |
+------------------+-------+
1 row in set (0.01 sec)

 

 

`expire_logs_days` 변수가 '0'으로 세팅되어 있었는데, 해당 값으로 미루어 보아 보관 기간이 따로 설정되어 있지 않는 것으로 추측되는데, 정확히 확인해보자!

→ mysql 5.7.17 'expire_logs_days' docs  (참고로, mysql 8 버전에서는 binlog_expire_logs_seconds 변수로 '초'단위로 설정한다.)

 

아하, 최대 99일까지 설정할 수 있으며, '0'으로 설정되어 있으면 자동적으로 제거 처리가 안 된다는 것을 확인했다. 

보관기간을 설정할까? 했으나!, 예전에 선배 개발자분께서 db 관련된 작업하다 실수로 데이터를 통째로 날렸을 때 복구하는 방법으로 binary log 파일을 활용했던 것이 기억이 났다..! 

사람일은 모르니, 보관기간을 따로 설정하지 말고 최소한의 binary log 파일만 제거하는게 좋겠다!

 

자, 그럼 binary log 파일을 지워볼까?

binary log 파일이 저장되어 있는 디렉토리로 이동하여 파일 삭제 명령어를 실행해도 될 것 같으나, 위 'expire_logs_days' 변수 설명 마지막 줄에 '수동적으로 binary log file'을 제거하는 방법에 대한 링크가 걸려 있는 것을 확인했으니 이참에 mysql에서 binary log 파일을 지우는 것을 한 번 확인해보자!

 

확인 결과 요약하자면 아래와 같다!

  1. binary log 파일 뿐만 아니라, log에 대한 index 파일도 같이 관리되고 있어서 디렉토리에 접근하여 파일 제거 명령어를 실행하는 것 보다는 mysql에서 PURGE BINARY LOGS 명령어를 실행하는 것이 더 안전하다.
  2. binary 파일을 제거하기 위해선 BINLOG_ADMIN 권한이 필요하다. (root 유저로 접근한 경우엔 신경쓰지 않아도 될 듯!) > 참조
  3. 아래와 같은 명령어를 통해 특정 로그 파일 또는 특정 날짜 이전 파일들을 제거할 수 있다
PURGE BINARY LOGS TO 'mysql-bin.010';
PURGE BINARY LOGS BEFORE '2019-04-02 22:46:26';

 

정리

위와 같이, mysql db 서버에 binary log 파일을 정리함으로써, batch 서버에서 발생했던 이슈는 해결할 수 있었다.

평소에 db 서버에는 자주 접근하지 않아서 약간 생소하긴 했으나 그래도 원인 파악 잘 하고 내용을 잘 정리한 것 같다!

다음에 비슷한 이슈가 발생했을 때, 당황하지 않고 대응할 수 있을 것 같다!  -끝- ^^

'실무 > ISSUE' 카테고리의 다른 글

Error parsing HTTP request header  (0) 2024.07.07

관련글

티스토리툴바