밤 12시가 되면 mysql이 뻗어버립니다.
본문
mysql 이 먹통이 되면서 뻗는데, 메모리 떄문인가 싶은데 어떻게 해결해야 될지 모르겠습니다.
일단 service restart mysql로 되살아나긴 합니다만... 에러 로그는 아래와 같습니다.
문제 발생은 밤 12시가 되면 발생하구요. 접속이 매우 느리다가 mysql이 뻗어버리고 connectino refused가 걸립니다.
InnoDB: 1 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 1 row operations to undo
InnoDB: Trx id counter is 21750167296
230815 10:39:04 [Note] InnoDB: Starting final batch to recover 3764 pages from redo log
230815 10:39:06 [Note] InnoDB: 128 rollback segment(s) are active.
230815 10:39:06 [Note] InnoDB: Starting in background the rollback of recovered transactions
230815 10:39:06 [Note] InnoDB: Waiting for purge to start
230815 10:39:06 [Note] InnoDB: Rollback of trx with id 21750164828 completed
230815 10:39:06 [Note] InnoDB: Rollback of non-prepared transactions completed
230815 10:39:06 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.42-84.2 started; log sequence number 3985757650846
230815 10:39:06 [Note] Plugin 'FEEDBACK' is disabled.
230815 10:39:06 [Note] Server socket created on IP: '::'.
230815 10:39:06 [Warning] 'proxies_priv' entry '@% *** 개인정보보호를 위한 이메일주소 노출방지 ***' ignored in --skip-name-resolve mode.
230815 10:39:06 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.0.38-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
230816 0:11:58 [Note] /usr/sbin/mysqld: Normal shutdown
230816 0:11:58 [Note] Event Scheduler: Purging the queue. 0 events
230816 0:11:59 [Note] InnoDB: FTS optimize thread exiting.
230816 0:11:59 [Note] InnoDB: Starting shutdown...
230816 0:12:00 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
230816 0:12:03 [Note] InnoDB: Shutdown completed; log sequence number 3986875014512
230816 0:12:03 [Note] /usr/sbin/mysqld: Shutdown complete
230816 00:12:03 mysqld_safe mysqld from pid file /var/lib/mysql/***.***.***.***.jp.linodeusercontent.com.pid ended
230816 00:12:04 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
230816 0:12:04 [Warning] 'THREAD_CONCURRENCY' is deprecated and will be removed in a future release.
230816 0:12:04 [Note] /usr/sbin/mysqld (mysqld 10.0.38-MariaDB) starting as process 21512 ...
230816 0:12:04 [Note] InnoDB: Using mutexes to ref count buffer pool pages
230816 0:12:04 [Note] InnoDB: The InnoDB memory heap is disabled
230816 0:12:04 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
230816 0:12:04 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
230816 0:12:04 [Note] InnoDB: Compressed tables use zlib 1.2.7
230816 0:12:04 [Note] InnoDB: Using Linux native AIO
230816 0:12:04 [Note] InnoDB: Using CPU crc32 instructions
230816 0:12:04 [Note] InnoDB: Initializing buffer pool, size = 12.0G
230816 0:12:05 [Note] InnoDB: Completed initialization of buffer pool
230816 0:12:05 [Note] InnoDB: Highest supported file format is Barracuda.
230816 0:12:05 [Note] InnoDB: 128 rollback segment(s) are active.
230816 0:12:05 [Note] InnoDB: Waiting for purge to start
230816 0:12:05 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.42-84.2 started; log sequence number 3986875014512
230816 0:12:05 [Note] Plugin 'FEEDBACK' is disabled.
230816 0:12:05 [Note] Server socket created on IP: '::'.
230816 0:12:05 [Warning] 'proxies_priv' entry '@% *** 개인정보보호를 위한 이메일주소 노출방지 ***' ignored in --skip-name-resolve mode.
230816 0:12:05 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.0.38-Maria
어떤 문제일까요? 그동안 잘 돌아가다가 어제부터 계속 밤 12시가 되면 사이트가 죽네요ㅠ
조언 부탁드립니다.
답변 8
그누보드 db.optimize.inc.php 인가 하는 파일이 있는데, 이게 하루에 한번 실행되는 형태로 로직이 만들어져 있습니다.
이 파일을 주석처리 하시면 12시마다(하루에 한번인죠) 문제가 발생하진 않습니다.
해당 파일에는 오래된 로그(g5_visit등) 테이블 내용을 지우는 코드가 있는데, 이건 필요한 작업이니,
배치잡으로 변경하거나, 주기적으로 한번식 실행해주셔야 합니다. 아니면, 테이블이 너무 커져서 감당하기 힘들어집니다.
참고로 mysql서버가 죽는 이유를 유추해본다면,
db.optimize.inc.php 가 수행될때, 완료될때까지 락상태라서 mysql메모리 사용량이 계속 증가(max connection)까지 증가하게 됩니다. max connection 을 크게 잡으면, connection 에 비례해서 메모리 사용량이 증가하는데, 결국 메모리가 부족해집니다.
어느 순간 out of memeory 오류가 발생하거나,,, oome killer 가 메모리를 확보하기 위해서 가장 메모리를 많이 사용하는 프로세스 하나를 kill 하게 됩니다.(아마 mysqld )
최적화 하기 위해선 어려가지 처리가 필요하긴 하지만,
12시에 정지하는건 db.optimize.inc.php 를 잘 처리하시면 해결됩니다.
(급한대로 그냥 코드를 주석처리하시면 됩니다.)
디비에 문제가 있어 복구할려고 하는것 같습니다.
12시에 cron 으로 어떤것을 실행 하도혹 되어 있는것은 아닌지 봐보세요...
로그 분석을 해 보세요...
어떤 접속이 있었는지를요..
문제가 해결되지 않으면 계속해서 발생할 것입니다.
디비를 백업하고 새로 설치해 보세요.
그동안 잘 동작하다가 발생하는 문제라면 최근에 어떤 변경된 사항이 있는지
어플리케이션 소스코드 부터 OS 설정단,
플랫폼을 사용중이라면 플랫폼 설정단 까지 작업내역을 추적해보는 방법이 좋을것 같습니다.
예상해볼수 있는 문제점으로는
소스코드나 쿼리가 잘못 변경되어 비효율적인 동작으로 인해 문제가 발생하는 경우라던지
어떤 이유로 사용자가 그 시간에 몰린다던지
또는 그 시간에 프로그램 내부적으로 어떤 이벤트가 등록되서 라던지
의 경우가 있겠습니다만
230816 0:11:58 [Note] /usr/sbin/mysqld: Normal shutdown
으로 유추해볼때 그런 문제는 아닌것 같고
OS 업데이트 정책으로 인한 방해
모니터링 프로그램의 방해
등의 이유로 의도하지 않은 동작이 실행되는 현상은 아닌지 생각해봅니다.
Slow query log 한번 살펴 보세요
Slow query log 한번 살펴 보세요.
디비로그가 12시 뻗었을때의 로그는없고
그이후 재시작 복구한
로그만 있어서 알기어렵습니다
뻗었을때 전후로 서버내부에서
디비 접속이 혹시 가능하다면
show full processlist
결과랑 서버자체에서 uptime 결과좀 알려주세요
윗분말씀대로 12시 전후로 크론작업이든 대량접속이든
그누보드 테이블정리든 뭔가 하는게 있을듯합니다
12시전후로 디비 쿼리들이 뭔가 sleep 상태로 오래걸리는게 있을것같으니 장애시간전후 위에 프로세스 리스트 상태를
통해 원인을 찾아봐야 할것 같습니다
제가 볼 적에는 서버의 특정 부분이 손상이 되어 그것을 스스로 복구 하려고 하다가 결국 실패 하고 멈춘것으로 보여집니다.
우선 sql 의 버젼이라던가 등등에 대해 좀더 자세히 알아야 합니다.
innodb_force_recovery 의, 값도 알아야 할것같습니다.
지난 질문 글에서의 내용까지 종합해 보면,
100% 취약점 노출로 악성 백그라운드 작업이 돌아가고 있다고 생각됩니다.
지난 글에서 다른 분이 백신이니 뭐니 하면서 도와준다는 답변을 달았던데 백신도 무용지물이고요.
DB 튜닝이나, 파티셔닝으로도 해결은 안 됩니다.
다운의 원인은 악성 스케줄링이 자정에 돌기 때문일거고,
이로 인한 부하 증가로 서버가 뻗는 상황으로 생각되고요.
질문자 분이 운영하시는 사이트가 일반적인 사이트는 아니라는 생각이 드네요.
