이번에 stored function 관련 full scan 튜닝이 끝나면 innodb status를 보고 좀더 개선포인트가 있는지 본격적으로 my.cnf 메모리 튜닝을 검토해볼 생각이다.
튜닝 가이드 중에서 잘 정리된 내용(SK Cloud Z Support Portal > Cloud Z DB >이승철님)이 있어 정리해놓는다.
Mariadb의 메모리는 크게 두 가지로 분류가 됩니다.
-> 글로벌 메모리영역은 공유하고 세션메모리영역(connection당)은 공유하지 않는다.
이것에 대한 하나 예를 들면 오라클과 postgres를 mysql로 마이그레이션을 진행한다면 다른 것보다 function과 procedure의 사용이 많은지 확인해봐야하고 어느부분에서는 Dynamic sql로 변경을 해야할 수도 있다.
오라클, postgres는 function과 procedure를 글로벌메모리영역에서 사용하지만 mysql은 일단 성능도 그들의 1/2배이며, global 메모리 영역에서 쓰지 않고 session 메모리 영역에서만 사용하기 때문에 성능이슈가 발생할 가능성이 더 크다. 인덱스스캔이 제대로 된다면 별문제 없지만.. 이후 function이나 procedure가 바뀌고 기존의 실행계획이 틀어진다면 바로 풀스캔 및 디스크I/O로 이어져 성능이슈가 발생할 가능성이 있다......mysql 잇점이 있다면 경험상 postgres는 procedure가 뭔짓을 하는지 모르다가 out of memory 떨구고 DB가 죽었지만, mysql은 session(connection) 메모리가 full이어서 disk로 넘어가게 되면 이미 성능이슈로 서버의 응답시간이 지연되는 것을 이미 다른 SM이 알기 때문에 DB 장애로 넘어가기 전에 미리 확인이 가능했다.
1. Global 메모리 영역 : DB가 최초 기동되었을 때에는 메모리를 최소한만 사용하다가 설정된 값 까지 증가하며 증가한 이후에는 "메모리를 반환하지 않고" 설정 된 값 이내에서 계속 사용됩니다. (오라클의 경우 DB기동시 설정된 값 만큼 메모리를 할당 받고 올라가는 반면 Mariadb 는 기동시 설정된 메모리 값만큼 할당 받는것이 아닌 설정된 값 만큼 서서히 증가하게 됩니다) •Innodb_buffer_pool_size •Key_buffer_size •innodb_log_buffer_size •tmp_table_size → Global 메모리 = Innodb_buffer_pool_size + Key_buffer_size + innodb_log_buffer_size + tmp_table_size
--> 대용량 테이블을 union all을 사용하는 sql호출이 많아지면서 성능이슈가 있었고 tmp_table_size을 사이즈를 512M -> 2G로 늘려서 DB 성능을 개선한 적이 있다. 해당 옵션을 튜닝하려면 max_heap_table_size도 같이 늘려줘야한다.
2. Session 메모리 영역 Mariadb session 별로 사용되어지는 메모리 공간으로 Max connection 설정 값과 관련이 있습니다. (커넥션을 맺고만 있을 경우에는 커넥션에 필요한 최소한의 메모리만 사용되어지며 조인, 정렬 등이 필요할 경우에는 아래 설정된 값만큼을 메모리에서 사용하게 됩니다. 때문에 정확한 예측값은 동시에 Active한 세션 수 이지만 기본적으로는 Max connection 수 만큼 동시 사용 세션이 수행될 수 있기에 아래 공식으로 계산되어 집니다.) •sort_buffer_size •read_buffer_size •read_rnd_buffer_size •join_buffer_size •thread_stack •binlog_cache_size •Max connection → Session 메모리 = (sort_buffer_size + read_buffer_size + read_rnd_buffer_size + join_buffer_size + thread_stack + binlog_cache_size) x Max connection
*예시 만약 Mariadb의 설정값이 다음과 같다면... Global 메모리 •Innodb buffer pool size: 2048 MB + Key buffer size: 16MB + innodb log buffer: 10MB + tmp table size: 64MB = 약 2.1 GB
Session 메모리 •( sort_buffer_size: 2MB + read_buffer_size: 1MB + read_rnd_buffer_size: 1MB + join_buffer_size: 0.128 MB + thread_stack: 0.128 MB + binlog_cache_size: 1MB) x Max connection 300 = 약 1.6 GB 이 됩니다.
따라서 global 메모리 영역 (2.1GB) + Session 메모리 영역(1.6GB) 에 추가로 Mariadb 기본 기동(350MB) + performance_schema data(150MB) + OS / 파일 버퍼링 공간(전체 메모리의 약 10%) 을 고려하여 위 설정된 값을 기준으로 전체 메모리의 적정 수치는 4,5GB ~ 5GB 정도가 적당해 보입니다. 위의 설명 및 예시를 참고하시어 MariaDB의 메모리를 설정해주시면 됩니다.
-> 팀이동후 DBA로 업무분석하다 처음으로 정리한 내용이었다. 당시 mysql 5.5에 MyISAM이라 시도때도 없이 Lock이 잡히고 새벽에 장애나고 ; 가장 큰 문제는 납작두꺼비처럼 옆으로 퍼져버린 테이블이 문제였는데.. 테이블 정규화를 해야하는데 소스수정범위가 너무 크다보니 개발쪽에 일정잡기가 어려워 결론적으로 현재는 옆으로 더 퍼져있고;;.. 인덱스만 추가하고 function/procedure에서 full scan 안타게 조심해서 쓰고 있다.
한번 선언한 테이블의 정규화는 많은 시간과 비용이 든다는 것을 다시 한번 느끼게 된다.
1) innoDB engine에서 테이블에 최대생성 가능한 컬럼과 인덱스
- 컬럼 1017개
- 인덱스 64개
-> 적정 컬럼 수는 40개 내외라고 한다.
2) 컬럼을 늘릴 때 발생할 수 있는 이슈
- 테이블에 인덱스 검색을 한다고 하더라도 DB 내부 Logic은 인덱스조건에 해당하는 row의 전체를 읽기 때문에 한번에 읽을 데이터의 값이 커지고 io에 부담을 준다.
DB컬럼은 여러 개의 Linked List로 구성되어있고 인덱스를 사용하더라도 해당열의 전체 값을 가져오기 때문에 컬럼이 늘어날수록 데이터 조회 비용은 늘어날 수밖에 없다.
#아래는 (프로게이밍연구실)에서 발췌한 내용임
DB에서 연결리스트를 가장 많이 사용하는 부분이 바로 테이블
컬럼명
캐릭터ID
캐릭터이름
레벨
경험치
게임머니
자료형
INT
NVARCHAR(50)
SMALLINT
INT
BIGINT
크기
4 BYTE
50 BYTE
2 BYTE
4 BYTE
8 BYTE
간단하게 예를 들어 만든 테이블 구조입니다. 위 구조라면 한 행의 크기는 68 BYTE의 작은 테이블이지요.
온라인 게임에서 사용되는 테이블의 크기는 보통 이렇게 작은 데이터들로 이루어지기 때문에 별 문제가 발생하지 않습니다
SELECT 캐릭터ID, 캐릭터이름, 게임머니FROM 캐릭터테이블 WHERE 캐릭터ID = 1
이렇게 쿼리를 날린다면 가져오는 데이터는 총 62 BYTE의 데이터를 가져옵니다.
하지만 데이터베이스 엔진의 내부 알고리즘의 움직임에 조금 관심을 가져본다면 ‘어떤 과정을 통해 데이터를 가져오는 것일까?’라는 생각을 해보신다면 재미있는 것을 알 수 있습니다.
바로 ‘연결된 리스트’라는 것이 그 재미의 핵심입니다.
아무리 인덱스를 사용하여 데이터를 빠르게 가져온다고 해도 연결된 리스트라는 녀석은 내부적으로 한 행의 모든 데이터내용을 싹 읽어버립니다. 게임과 같이 작은 데이터를 다룬다면 큰 문제가 없겠지만 아래처럼 게시판일 경우에는? 얘기가 완전 달라지는 것이죠.
컬럼명
글번호
게시자
제목
본문
게시일
자료형
INT
NVARCHAR(50)
VARCHAR(200)
TEXT or Image
SMALLDATETIME
크기
4 BYTE
50 BYTE
200 BYTE
2^31-1 BYTE(2GB)
8 BYTE
위에 보이는 것처럼 큰 데이터 열이 있다면 연결된 리스트로 데이터를 읽을 때에 어마어마한 비용이 발생하겠지요?
그런데 위에서 보이는 것과 같이 큰 크기의 열이 있으면 그만큼 많은 페이지를 읽어야 하고 어마어마한 데이터를 ‘사용하지 않더라도 읽어야 하는 것’이죠.
인덱스를 사용하면 빠르게 데이터를 조회할 수 있지만 만약 게시판에 정말 많은 량의 내용을 담은 게시물이 있을 경우 성능을 보장할 수 없습니다.
그렇다면 ‘어떻게 하면 이런 재앙을 막을 수 있을까?’에 대한 연구해봅시다.
개인적으로 저는 저렇게 큰 데이터 열을 별도의 테이블로 분리시켜야 한다고 생각합니다.
‘게시물을 가져올 때에 JOIN을 하게 되니 성능이 더 나빠지지 않느냐!?’ 라고 반박하시는 분께서 계실지 모르겠지만, 인덱스를 사용해서 정확하게 SEEK한 데이터는 무조건 0초 만에 수행됩니다.
게시물 본문과 글 번호를 별도의 테이블로 분리한 후 본문을 조회할 때에만 조인하여 가져오는 방식이 제가 생각할 수 있는 최고의 성능을 보장할 수 있는 최선의 방법입니다.
상용서비스에 슬로우 쿼리 이슈가 있어 확인해보니 select ~ from 안에 function을 사용했는데
이게 문제가 되어 응답시간이 느려지고 서비스 지연이 발생하였다.
근데 이게 원래는 슬로우 쿼리가 아니었는데 왜 갑자기 튀어나왔는지 보다보니
지난주에 대용량 테이블에 인덱스 추가 3개를 하고 나서 사이드 이펙트로 튀어나왔다. ㅠ
인덱스 추가하고 나서 아무래도 fucntion의 로컬 메모리(connection 당) 사용이 어느부분에서 MAX를 넘어 디스크를 사용하게 되었고 이게 Disk I/O를 치는 이유로 보인다.
--> mysql은 오라클과 달리 function이나 procedure가 global memory 영역을 사용하지 못하고 connection당 local 메모리가 my.cnf에 정의되어 있고 그 이상 사용할 경우 Disk로 넘어가 스토리지 엔진의 핸들러가 바뻐지게 되고 이게 Disk I/O를 발생시킨다.
슬로우쿼리 설정값은 2초이고 인덱스 3개 추가 후 현재는 14초 이상이 소요되고 있다.
대용량 참조하는 fucntion의 로직을 개선하려고 보니 쓰는 곳이 너무 많아서 수정하게 되면 테스트할 곳이 많다고
개발, 기획파트에서 얘기가 많다.ㅠ
고민중 fucntion에 캐시를 쓸 수 있는 DETERMINISTIC 옵션이 있는 것을 확인하고 테스트를 진행하였다.
mysql function에 DETERMINISTIC, NOT DETERMINISTIC 이라는 설정이 있다.
#장비사항
DB version : mysql 5.7.19
MEM : 16G ( innodb buffer pool :16G =테스트 용도로 Max로 잡음)
2.옵션 정의
characteristic { CONTAINS SQL | NO SQL | READS SQL DATA | MODIFIES SQL DATA } SQL SECURITY { DEFINER | INVOKER } COMMENT 'string'
1) DETERMINISTIC - 입력값이 같은면 결과는 늘 같다.
- 쿼리가 실행되면 그때 한번 호출하고 그 쿼리 안에서 상수값을 돌려줌 다시 쿼리가 호출되면 다시 실행됨
2) NOT DETERMINISTIC - 입력값이 같아도 시간에 따라 결과는 다르다.
- 디펄트가 늘 변함 임으로 속도가 느려질수 있다 꼭 구분해서 사용하자
--> 따로 설정하지 않으면 NOT DETERDETERMINISTIC 이다
3. 추가 설명
DETERMINISTIC and NOT DETERMINISTIC 특성은 함수가 주어진 입력 값에 대해 항상 동일한 결과를 만드는지 아닌지를 나타낸다. 어떤 특성도 주어지지 않으면, 디폴트는 NOT DETERMINISTIC이며, 따라서 함수를 확정적인 것으로 선언하기 위해서는 DETERMINISTIC를 확실하게 지정해 주어야한다.
NOW() 함수(또는 동일 기능함수) 또는 RAND()의 사용은 함수를 반드시 non-deterministic하게 만들어 주는 것은 아니다. NOW()의 경우, 바이너리 로그는 타임스탬프와 복사본은 올바르게 포함한다. 또한 RAND()도 함수내에서 일단 한번 호출되어 지면 정확하게 복사본을 만들게 된다. (함수 실행 타임스탬프 및 무작위 수는 마스터 서버 및 슬레이브 상에 있는 동일한 암시적 입력(implicit input)으로 간주할 수 있다.)
--> function 안에 now() 있는데 넣다 뺐다 둘다 테스트 해봐야할 거 같다.
contains sql, no sql, reads sql data, modifies sql data 특성은 함수가 데이터를 읽거나 또는 스는 정보를 제공한다. NO SQL 또는 Read sql data는 함수가 데이터를 변경하지 않는다는 것을 나타내는 것이다. 하지만 어떠한 특성도 주어지지 않으면 디폴트가 CONTAIN SQL이 되기 때문에 반드시 이러한 것 중에 하나를 명확히 지정해 주어야한다
--> 이렇게 얘기하긴 하는데 찾아보니 별로 중요하지 않다는 얘기가 더 많다.
1) CONTAINS SQL : 데이터를 읽거나 쓰는 명령문을 갖지 않음. 2) NO SQL : 아무런 SQL명령문이 없음. 3) READS SQL DATA : 데이터를 읽는 명령문. 4) MODIFIES SQL DATA : 데이터를 쓰는 있는 명령문 5) CONTAINS SQL : DEFAULT
6) SQL SECURITY : 사용자가 생성/수정 권한인지, 호출 권한인지 명시
4. 테스트
4-1) 쿼리 캐시 OFF 일떄
DEFAULT 설정
-> 수행시간 13초
DETERMINISTIC 설정 -> 수행시간 13초 (똑같네;;)
4-1) 쿼리 캐시 ON 일떄
mysql> set global query_cache_type=1;
ERROR 1651 (HY000): Query cache is disabled; restart the server with query_cache_type=1 to enable it
#my.cnf 설정하고 재시작한다.
mysql> show global variables like 'query_cache_type';
+------------------+-------+
| Variable_name | Value |
+------------------+-------+
| query_cache_type | ON |
+------------------+-------+
1 row in set (0.00 sec)
#쿼리캐시 설정 옵션설명
1) Query_Cache_Type = ON – 예외사항을 제외한 모든 SQL결과를 메모리에 캐싱하겠다. 2) Query_Cache_Type = OFF – Query Cache를 사용하지 않겠다. 3) Query_Cache_Type = DEMAND
DEFAULT 설정
-> 수행시간 14초
DETERMINISTIC 설정 -> 수행시간 14초 (더 느리다;;)
캐시를 쓰는지 확인해본다.
mysql> show global status like 'qcache%';
+-------------------------+----------+
| Variable_name | Value |
+-------------------------+----------+
| Qcache_free_blocks | 1 |
| Qcache_free_memory | 67091584 |
| Qcache_hits | 0 |
| Qcache_inserts | 0 |
| Qcache_lowmem_prunes | 0 |
| Qcache_not_cached | 18 |
| Qcache_queries_in_cache | 0 |
| Qcache_total_blocks | 1 |
+-------------------------+----------+
8 rows in set (0.00 sec)
1) 임시 테이블에 대한 쿼리 2) 사용자 변수의 사용(프리페어 스테이트먼트와 동일하게 작용) 3) 칼럼 기반의 권한 설정 4) LOCK IN SHARE MODE 힌트 5) FOR UPDATE 힌트 6) UDF(User Define Function)사용 7) 독립적인 SELECT문장이 아닌 일부분의 서브 쿼리 8) 스토어드 루틴(Procedure, Function, Trigger)에서 사용된 쿼리--> 아.... 9) SQL_NO_CACHE 힌트
5.결론
쿼리캐시 사용하고 function 에 DETERMINISTIC 을 설정하더라도 스토어드 루틴(Procedure, Function, Trigger)에서 사용된 쿼리는 캐시를 쓰지 않는다. --> function 튜닝은 결국 한 세션에 로컬 메모리를 적게 사용(table cache를 줄임) 옵티마이져 cost를 개선하는 방법 말곤 없는 거 같다.
select 절은 복잡했지만 from 이하절은 테이블 2개의 양쪽에 pk를 join해서 값을 가져오는 단순한 쿼리였다.
limit 200으로 끊어서 1차 데이터 이상없음을 검증하고
전체 쿼리를 수행하려는데 근데 이게 느려도 너무 느렸다...
into outfile로 수행해도 느렸다.. 뭔가 문제가 있어보였지만 query 상 문제는 아닌 것으로 보였다.
//나머지 제거하고 문제되는 부분만 본다.
select
T1.*
from TMP_LOAD_20200313_01 T1
LEFT OUTER JOIN TMP_LOAD_20200313_02 T2
ON T1.SEQ_NO = T2.SEQ_NO;
1) plan 확인
뭐가 문제일까 일단 쿼리를 단순화 시켜 plan을 떠봤다.
id
select type
table
type
possible_key
key
key len
ref
rows
extra
1
SIMPLE
T1
ALL
559741
1
SIMPLE
T2
ALL
PRIMARY
66728
Range checked for each record (index map: 0x1)
흠..일단 pk인데 T2 절에 인덱스스캔이 안된 것이 이상했고
Range checked for each record (index map: 0x1) 이게 뭔지 궁금해서 찾아보았다.
# range checked for each record (index map:N)
Mysql은 사용하기에 좋은 인덱스를 찾지 못했으나, 이전 테이블에서 컬럼 값을 찾고 난 후에는 사용할 수도 있을 법한 인덱스는 알아냈다. 이전 테이블에 있는 각 열 조합에 대해서는, Mysql은 그 조합이 열을 추출하기 위해서 range 또는 index_merge 접근방식을 사용할 수 있을지를 검사한다. 이방법은 그리 빠른 방법은 아니지만, 인덱스를 전혀 사용하지 않는 것보다는 빠르게 진행한다.
--> 인덱스를 찾지 못했다?.. pk이라고... 잴빠른 b-tree 인덱스인데..왜 못찾을까;;
인덱스를 못찾았는데 어떻게든 옵티마이져가 인덱스 비슷하게 만들어서 scan 했다는 얘기같은데.. 이게 정확히 뭘 의미하는지 몰랐다.
# 테이블 스키마를 확인했다.
TMP_LOAD_20200313_01
SEQ_NO bigint (15) unsigned not null
TMP_LOAD_20200313_02
SEQ_NO varchar (20) not null
--> 같은 컬럼 네이밍에 데이터 타입이 다르다니; 솔직히 생각지 못했다.
seq_no는테이블 200 여개에서 같은 컬럼 네이밍을 쓰고 있는데 데이터형이 다를 줄이야...
결국 range checked for each record 의미는 컬럼의 데이터형이 맞지 않는데 옵티마이져가 강제 형변환해서 scan을 한 것이었다.
2) 형변환후 plan 확인
id
select type
table
type
possible_key
key
key len
ref
rows
extra
1
SIMPLE
T1
ALL
559741
1
SIMPLE
T2
eq_ref
PRIMARY
PRIMARY
8
xxx.T1.SEQ_NO
1
전체 데이터 추출시간 2초이내로 끝났고, 인덱스 스캔이 (eq_ref ) 제대로 되는 것을 확인할 수 있다.
mysql의 옵티마이져는 생각보다 똑똑했다..;
--> 최근에 개발된 테이블 스키마가 문제였고, 데이터 형변환을 적용하려 개발쪽과 협의해서 추가반영을 하였다.
mysql 은 100만 row만 넘어도 대용량 테이블로 보고 관련테이블을 join으로 쓰는 쿼리는 최소한의 function 사용, procedure 사용지양하여
open table cache를 최소한으로 쓸 수있는 방법과 index 튜닝을 해왔는데..
이제는 그것만으로 버티긴 힘들다. 그래서 디스크를 SAS 에서 SSD로 교체작업을 진행중이고
Master 교체후 이제 Slave를 교체하는 작업을 진행하였다.
예전에는 서비스 중단후 slave 교체작업을 했었지만 이제는 xtrabackup의 도움을 받아 한번 도전해보고 싶다.
결론은 상용 서버에서 100% 무중단으로 slave 구축에 성공했고, 작업 전에 테스트기에서 했던 내용을 남긴다.
mysql replication은 참 편리한 기능이다. 하지만 replication 관련 에러가 났을 때 그것을 해결할 만한 레퍼런스는 많지 않다. 3년 전에 그렇게 한 5일을 고생하고 .. 결국 찾은 원인은 federated table 때문이었지만.. 그 이후에는 그냥 점검할 떄 웬만하면 서비스 중단 후 작업을 진행했다.
이번에 온라인으로 상용기 slave를 구축하는 목적은 추후 로드밸런싱이나 모니터링 툴 도입시 slave를 추가로
구축할 수도 있어서 미리 해보기로 했다.
참조사이트는 성동찬님의 xtrabackup 부분을 참조했다.
# 테스트기 환경
1) 백업전 준비
실시간 트렌젝션은 지속된다.(상용 서버에 작업한다는 전제하에 최대한 동일한 환경을 구성)
Master는 계속해서 insert update가 일어나고 binlog에 데이터는 쌓인다.
--> xtrabackup 전에 임시테이블을 생성하고 insert into로 10만건을 밀어넣도록 했다. 백업 끝날때까지 안끝나도록 하는 것이 목적이었다. binlog 와 pos가 변경되고 xtrabackup 후에 apply log가 변경지점까지 잘따라갔는지 확인하기 위해서다.
마지막에 xbstream.log에 아무것도 없고, innodbackupex.log에 completed 를 확인하면된다.
# shell 분석
# xtrabackup 옵션
--stream=name 이 옵션에 명시된 포맷으로 백업 데이터를 stream한다. 현재는 xbstream과 tar를 지원한다. 스트리밍 기능을 사용하려면 --stream 옵션을 사용하여 스트림 형식은 (tar 또는 xbstream)을 사용하고 임시 파일을 저장할 위치를 제공해야 합니다.
--> stream의 임시저장 경로(/backup/temp) 은 어디에 만들어야할까? Master다. Slave에서는 데이터 끌어올 위치에서 실행하면 그 위치에 데이터가 쌓이는 것이지 실제 쉘에서 쓰는 /backup/temp는 마스터에 있어야할 폴더이고 이게 없으면 innodbackup.log에서 에러를 뱉어내고 실행 안된다.
--no-lock 이 옵션을 사용하게 되면 FLUSH TABLES WITH READ LOCK을 실행하지 않는다. 이옵션을 사용하지 않아도 일관성에 문제가 없다고 판단하는 경우에만 사용하도록 한다. 만약 백업 도중에 DDL이 발생할 수 있다면 사용하지 않는 것이 좋다. 이 옵션을 백업을 위해 락을 잡는데 문제가 된다고 생각하는 경우에만 사용하도록 한다. --safe-slave-backup 을 사용하여 잠시라도 리플리케이션 슬레이브 스레드를 중지하게 되면 성공적으로 백업을 진행할 수 있게 도움을 줄 수 있다. 하지만, 이 옵션에 의존적일 필요는 없다. xtrabackup_binlog_info 파일은 이 옵션을 사용하면 생성되지 않는다. 대신에 xtrabackup_binlog_pos_innodb 파일을 사용할 수 있다.
--> xtrabackup을 하게되면 xtrabackup_binlog_info, xtrabackup_binlog_pos_innodb 둘다 binlog 파일이름과 pos가 생긴다. 둘중에 뭘 써야할 지 몰랐는데 이번에 shell분석하면서 확실히 알게되었다. no-lock 는 xtrabackup_binlog_pos_innodb 다.
# pv 옵션
- linux 에서 대용량 파일 복사시 진행 상황 표시 및 중단시 이어서 복사 (cp 명령어 대체) pv 는 콘솔 프로그램으로 다음과 같은 특징이 있습니다. •pipe 기반으로 동작하여 속도가 빠름 •파일의 복사/이동 진행 상태를 확인할 수 있음 •총 전송량과 예상 시간을 표시 •중단후 다시 시작할 경우 이후부터 시작
--rate-limit 옵션 이 옵션을 사용하여 처리 속도를 제한할 수 있다. 이 옵션의 인수로는 하나의 숫자와 하나의 접미어(예: MB/초를 나타내는 m)가 있다
--> 온라인 hot 백업시 가장 큰 고민이었다. 분명 ssh로 끌어온다면 Master의 네트웍 부하를 최소화해야하는데 방법을 고민했는데, pv 라는 좋은 것을 알게 되었다.
50M로 끊어서 전송한다.
3) 재생성
3-1) apply log 복구
xtrabackup은 백업 도중에 Master에서 발생한 트랜젝션을 xtrabackup_logfile에 쌓아놓고 xtrabackup이 끝날 때까지 쌓는다.
apply log를 실행하게되면 xtrabackup_logfile 파일을 읽어 xtrabackup 동안 추가된 트랜젝션 데이터를 /data/영역에 merge하고 마지막 binlog 파일과 pos를 xtrabackup_binlog_pos_innodb에 남긴다.
--> xtrabackup_logfile 을 한번 보고 싶어서 mysqlbinlog로 열어봤는데 안열린다. 다른 파일포맷인가보다...
일단 임시테이블 생성하고 발생한 트랜젝션이 apply log 실행으로 제대로 merge 되는지 확인했다.
백업시작시 0건에서 시작한 임시테이블 count(*)가 xtrabackup이 끝났을 떄 54689건이 되었다.
xtrabackup 도중에 발생한 트랜젝션이 제대로 쌓였음을 확인했다.
[root@backup]# /usr/bin/innobackupex --defaults-file=/etc/my.cnf --datadir=/data/mysqldb_data --apply-log /backup2/temp/temp
xtrabackup: recognized server arguments: --innodb_checksum_algorithm=crc32 --innodb_log_checksum_algorithm=strict_crc32 --innodb_data_file_path=ibdata1:500M;ibdata2:500M;ibdata3:500M;ibdata4:100M:autoextend --innodb_log_files_in_group=3 --innodb_log_file_size=268435456 --innodb_fast_checksum=0 --innodb_page_size=16384 --innodb_log_block_size=512 --innodb_undo_directory=./ --innodb_undo_tablespaces=0 --server-id=1 --redo-log-version=1 --datadir=/data/mysqldb_data
xtrabackup: recognized client arguments:
200403 15:37:35 innobackupex: Starting the apply-log operation
IMPORTANT: Please check that the apply-log run completes successfully.
At the end of a successful apply-log run innobackupex
prints "completed OK!".
/usr/bin/innobackupex version 2.4.19 based on MySQL server 5.7.26 Linux (x86_64) (revision id: c2d69da)
xtrabackup: cd to /backup2/temp/temp/
xtrabackup: This target seems to be not prepared yet.
InnoDB: Number of pools: 1
xtrabackup: xtrabackup_logfile detected: size=682229760, start_lsn=(232065897958)
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_data_home_dir = .
xtrabackup: innodb_data_file_path = ibdata1:500M;ibdata2:500M;ibdata3:500M;ibdata4:100M:autoextend
xtrabackup: innodb_log_group_home_dir = .
xtrabackup: innodb_log_files_in_group = 1
xtrabackup: innodb_log_file_size = 682229760
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_data_home_dir = .
xtrabackup: innodb_data_file_path = ibdata1:500M;ibdata2:500M;ibdata3:500M;ibdata4:100M:autoextend
xtrabackup: innodb_log_group_home_dir = .
xtrabackup: innodb_log_files_in_group = 1
xtrabackup: innodb_log_file_size = 682229760
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
InnoDB: PUNCH HOLE support available
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Uses event mutexes
InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
InnoDB: Compressed tables use zlib 1.2.3
InnoDB: Number of pools: 1
InnoDB: Not using CPU crc32 instructions
InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
InnoDB: Completed initialization of buffer pool
InnoDB: page_cleaner coordinator priority: -20
InnoDB: Highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 232065897958
InnoDB: Doing recovery: scanned up to log sequence number 232071140352 (0%)
InnoDB: Doing recovery: scanned up to log sequence number 232076383232 (1%)
InnoDB: Doing recovery: scanned up to log sequence number 232081626112 (2%)
InnoDB: Doing recovery: scanned up to log sequence number 232086868992 (3%)
InnoDB: Doing recovery: scanned up to log sequence number 232092111872 (4%)
InnoDB: Doing recovery: scanned up to log sequence number 232097354752 (5%)
InnoDB: Doing recovery: scanned up to log sequence number 232102597632 (6%)
InnoDB: Doing recovery: scanned up to log sequence number 232107840512 (6%)
InnoDB: Doing recovery: scanned up to log sequence number 232113083392 (7%)
InnoDB: Doing recovery: scanned up to log sequence number 232118326272 (8%)
InnoDB: Doing recovery: scanned up to log sequence number 232123569152 (9%)
InnoDB: Doing recovery: scanned up to log sequence number 232128812032 (10%)
InnoDB: Doing recovery: scanned up to log sequence number 232134054912 (11%)
InnoDB: Doing recovery: scanned up to log sequence number 232139297792 (12%)
InnoDB: Doing recovery: scanned up to log sequence number 232144540672 (12%)
InnoDB: Doing recovery: scanned up to log sequence number 232149783552 (13%)
InnoDB: Doing recovery: scanned up to log sequence number 232155026432 (14%)
InnoDB: Doing recovery: scanned up to log sequence number 232160269312 (15%)
InnoDB: Doing recovery: scanned up to log sequence number 232165512192 (16%)
InnoDB: Doing recovery: scanned up to log sequence number 232170755072 (17%)
InnoDB: Doing recovery: scanned up to log sequence number 232175997952 (18%)
InnoDB: Doing recovery: scanned up to log sequence number 232181240832 (19%)
InnoDB: Doing recovery: scanned up to log sequence number 232186483712 (19%)
InnoDB: Doing recovery: scanned up to log sequence number 232191726592 (20%)
InnoDB: Doing recovery: scanned up to log sequence number 232196969472 (21%)
InnoDB: Doing recovery: scanned up to log sequence number 232202212352 (22%)
InnoDB: Doing recovery: scanned up to log sequence number 232207455232 (23%)
InnoDB: Doing recovery: scanned up to log sequence number 232212698112 (24%)
InnoDB: Doing recovery: scanned up to log sequence number 232217940992 (25%)
InnoDB: Doing recovery: scanned up to log sequence number 232223183872 (25%)
InnoDB: Doing recovery: scanned up to log sequence number 232228426752 (26%)
InnoDB: Doing recovery: scanned up to log sequence number 232233669632 (27%)
InnoDB: Doing recovery: scanned up to log sequence number 232238912512 (28%)
InnoDB: Doing recovery: scanned up to log sequence number 232244155392 (29%)
InnoDB: Doing recovery: scanned up to log sequence number 232249398272 (30%)
InnoDB: Doing recovery: scanned up to log sequence number 232254641152 (31%)
InnoDB: Doing recovery: scanned up to log sequence number 232259884032 (31%)
InnoDB: Doing recovery: scanned up to log sequence number 232265126912 (32%)
InnoDB: Doing recovery: scanned up to log sequence number 232270369792 (33%)
InnoDB: Doing recovery: scanned up to log sequence number 232275612672 (34%)
InnoDB: Doing recovery: scanned up to log sequence number 232280855552 (35%)
InnoDB: Doing recovery: scanned up to log sequence number 232286098432 (36%)
InnoDB: Doing recovery: scanned up to log sequence number 232291341312 (37%)
InnoDB: Doing recovery: scanned up to log sequence number 232296584192 (38%)
InnoDB: Doing recovery: scanned up to log sequence number 232301827072 (38%)
InnoDB: Doing recovery: scanned up to log sequence number 232307069952 (39%)
InnoDB: Doing recovery: scanned up to log sequence number 232312312832 (40%)
InnoDB: Doing recovery: scanned up to log sequence number 232317555712 (41%)
InnoDB: Doing recovery: scanned up to log sequence number 232322798592 (42%)
InnoDB: Doing recovery: scanned up to log sequence number 232328041472 (43%)
InnoDB: Doing recovery: scanned up to log sequence number 232333284352 (44%)
InnoDB: Doing recovery: scanned up to log sequence number 232338527232 (44%)
InnoDB: Doing recovery: scanned up to log sequence number 232343770112 (45%)
InnoDB: Doing recovery: scanned up to log sequence number 232349012992 (46%)
InnoDB: Doing recovery: scanned up to log sequence number 232354255872 (47%)
InnoDB: Doing recovery: scanned up to log sequence number 232359498752 (48%)
InnoDB: Doing recovery: scanned up to log sequence number 232364741632 (49%)
InnoDB: Doing recovery: scanned up to log sequence number 232369984512 (50%)
InnoDB: Doing recovery: scanned up to log sequence number 232375227392 (51%)
InnoDB: Doing recovery: scanned up to log sequence number 232380470272 (51%)
InnoDB: Doing recovery: scanned up to log sequence number 232385713152 (52%)
InnoDB: Doing recovery: scanned up to log sequence number 232390956032 (53%)
InnoDB: Doing recovery: scanned up to log sequence number 232396198912 (54%)
InnoDB: Doing recovery: scanned up to log sequence number 232401441792 (55%)
InnoDB: Doing recovery: scanned up to log sequence number 232406684672 (56%)
InnoDB: Doing recovery: scanned up to log sequence number 232411927552 (57%)
InnoDB: Doing recovery: scanned up to log sequence number 232417170432 (57%)
InnoDB: Doing recovery: scanned up to log sequence number 232422413312 (58%)
InnoDB: Doing recovery: scanned up to log sequence number 232427656192 (59%)
InnoDB: Doing recovery: scanned up to log sequence number 232432899072 (60%)
InnoDB: Doing recovery: scanned up to log sequence number 232438141952 (61%)
InnoDB: Doing recovery: scanned up to log sequence number 232443384832 (62%)
InnoDB: Doing recovery: scanned up to log sequence number 232448627712 (63%)
InnoDB: Doing recovery: scanned up to log sequence number 232453870592 (63%)
InnoDB: Doing recovery: scanned up to log sequence number 232459113472 (64%)
InnoDB: Doing recovery: scanned up to log sequence number 232464356352 (65%)
InnoDB: Doing recovery: scanned up to log sequence number 232469599232 (66%)
InnoDB: Doing recovery: scanned up to log sequence number 232474842112 (67%)
InnoDB: Doing recovery: scanned up to log sequence number 232480084992 (68%)
InnoDB: Doing recovery: scanned up to log sequence number 232485327872 (69%)
InnoDB: Doing recovery: scanned up to log sequence number 232490570752 (70%)
InnoDB: Doing recovery: scanned up to log sequence number 232495813632 (70%)
InnoDB: Doing recovery: scanned up to log sequence number 232501056512 (71%)
InnoDB: Doing recovery: scanned up to log sequence number 232506299392 (72%)
InnoDB: Doing recovery: scanned up to log sequence number 232511542272 (73%)
InnoDB: Doing recovery: scanned up to log sequence number 232516785152 (74%)
InnoDB: Doing recovery: scanned up to log sequence number 232522028032 (75%)
InnoDB: Doing recovery: scanned up to log sequence number 232527270912 (76%)
InnoDB: Doing recovery: scanned up to log sequence number 232532513792 (76%)
InnoDB: Doing recovery: scanned up to log sequence number 232537756672 (77%)
InnoDB: Doing recovery: scanned up to log sequence number 232542999552 (78%)
InnoDB: Doing recovery: scanned up to log sequence number 232548242432 (79%)
InnoDB: Doing recovery: scanned up to log sequence number 232553485312 (80%)
InnoDB: Doing recovery: scanned up to log sequence number 232558728192 (81%)
InnoDB: Doing recovery: scanned up to log sequence number 232563971072 (82%)
InnoDB: Doing recovery: scanned up to log sequence number 232569213952 (82%)
InnoDB: Doing recovery: scanned up to log sequence number 232574456832 (83%)
InnoDB: Doing recovery: scanned up to log sequence number 232579699712 (84%)
InnoDB: Doing recovery: scanned up to log sequence number 232584942592 (85%)
InnoDB: Doing recovery: scanned up to log sequence number 232590185472 (86%)
InnoDB: Doing recovery: scanned up to log sequence number 232595428352 (87%)
InnoDB: Doing recovery: scanned up to log sequence number 232600671232 (88%)
InnoDB: Doing recovery: scanned up to log sequence number 232605914112 (89%)
InnoDB: Doing recovery: scanned up to log sequence number 232611156992 (89%)
InnoDB: Doing recovery: scanned up to log sequence number 232616399872 (90%)
InnoDB: Doing recovery: scanned up to log sequence number 232621642752 (91%)
InnoDB: Doing recovery: scanned up to log sequence number 232626885632 (92%)
InnoDB: Doing recovery: scanned up to log sequence number 232632128512 (93%)
InnoDB: Doing recovery: scanned up to log sequence number 232637371392 (94%)
InnoDB: Doing recovery: scanned up to log sequence number 232642614272 (95%)
InnoDB: Doing recovery: scanned up to log sequence number 232647857152 (95%)
InnoDB: Doing recovery: scanned up to log sequence number 232653100032 (96%)
InnoDB: Doing recovery: scanned up to log sequence number 232658342912 (97%)
InnoDB: Doing recovery: scanned up to log sequence number 232663585792 (98%)
InnoDB: Doing recovery: scanned up to log sequence number 232668828672 (99%)
InnoDB: Doing recovery: scanned up to log sequence number 232672354749 (100%)
InnoDB: Database was not shutdown normally!
InnoDB: Starting crash recovery.
InnoDB: Doing recovery: scanned up to log sequence number 232067601408 (0%)
InnoDB: Doing recovery: scanned up to log sequence number 232072844288 (1%)
InnoDB: Doing recovery: scanned up to log sequence number 232078087168 (2%)
InnoDB: Doing recovery: scanned up to log sequence number 232083330048 (2%)
InnoDB: Doing recovery: scanned up to log sequence number 232088572928 (3%)
InnoDB: Doing recovery: scanned up to log sequence number 232093815808 (4%)
InnoDB: Doing recovery: scanned up to log sequence number 232099058688 (5%)
InnoDB: Doing recovery: scanned up to log sequence number 232104301568 (6%)
InnoDB: Doing recovery: scanned up to log sequence number 232109544448 (7%)
InnoDB: Doing recovery: scanned up to log sequence number 232114787328 (8%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 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 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 232120030208 (8%)
InnoDB: Doing recovery: scanned up to log sequence number 232125273088 (9%)
InnoDB: Doing recovery: scanned up to log sequence number 232130515968 (10%)
InnoDB: Doing recovery: scanned up to log sequence number 232135758848 (11%)
InnoDB: Doing recovery: scanned up to log sequence number 232141001728 (12%)
InnoDB: Doing recovery: scanned up to log sequence number 232146244608 (13%)
InnoDB: Doing recovery: scanned up to log sequence number 232151487488 (14%)
InnoDB: Doing recovery: scanned up to log sequence number 232156730368 (14%)
InnoDB: Doing recovery: scanned up to log sequence number 232161973248 (15%)
InnoDB: Doing recovery: scanned up to log sequence number 232167216128 (16%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 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 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 232172459008 (17%)
InnoDB: Doing recovery: scanned up to log sequence number 232177701888 (18%)
InnoDB: Doing recovery: scanned up to log sequence number 232182944768 (19%)
InnoDB: Doing recovery: scanned up to log sequence number 232188187648 (20%)
InnoDB: Doing recovery: scanned up to log sequence number 232193430528 (21%)
InnoDB: Doing recovery: scanned up to log sequence number 232198673408 (21%)
InnoDB: Doing recovery: scanned up to log sequence number 232203916288 (22%)
InnoDB: Doing recovery: scanned up to log sequence number 232209159168 (23%)
InnoDB: Doing recovery: scanned up to log sequence number 232214402048 (24%)
InnoDB: Doing recovery: scanned up to log sequence number 232219644928 (25%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 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 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 232224887808 (26%)
InnoDB: Doing recovery: scanned up to log sequence number 232230130688 (27%)
InnoDB: Doing recovery: scanned up to log sequence number 232235373568 (27%)
InnoDB: Doing recovery: scanned up to log sequence number 232240616448 (28%)
InnoDB: Doing recovery: scanned up to log sequence number 232245859328 (29%)
InnoDB: Doing recovery: scanned up to log sequence number 232251102208 (30%)
InnoDB: Doing recovery: scanned up to log sequence number 232256345088 (31%)
InnoDB: Doing recovery: scanned up to log sequence number 232261587968 (32%)
InnoDB: Doing recovery: scanned up to log sequence number 232266830848 (33%)
InnoDB: Doing recovery: scanned up to log sequence number 232272073728 (33%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 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 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 232277316608 (34%)
InnoDB: Doing recovery: scanned up to log sequence number 232282559488 (35%)
InnoDB: Doing recovery: scanned up to log sequence number 232287802368 (36%)
InnoDB: Doing recovery: scanned up to log sequence number 232293045248 (37%)
InnoDB: Doing recovery: scanned up to log sequence number 232298288128 (38%)
InnoDB: Doing recovery: scanned up to log sequence number 232303531008 (39%)
InnoDB: Doing recovery: scanned up to log sequence number 232308773888 (40%)
InnoDB: Doing recovery: scanned up to log sequence number 232314016768 (40%)
InnoDB: Doing recovery: scanned up to log sequence number 232319259648 (41%)
InnoDB: Doing recovery: scanned up to log sequence number 232324502528 (42%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 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 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 232329745408 (43%)
InnoDB: Doing recovery: scanned up to log sequence number 232334988288 (44%)
InnoDB: Doing recovery: scanned up to log sequence number 232340231168 (45%)
InnoDB: Doing recovery: scanned up to log sequence number 232345474048 (46%)
InnoDB: Doing recovery: scanned up to log sequence number 232350716928 (46%)
InnoDB: Doing recovery: scanned up to log sequence number 232355959808 (47%)
InnoDB: Doing recovery: scanned up to log sequence number 232361202688 (48%)
InnoDB: Doing recovery: scanned up to log sequence number 232366445568 (49%)
InnoDB: Doing recovery: scanned up to log sequence number 232371688448 (50%)
InnoDB: Doing recovery: scanned up to log sequence number 232376931328 (51%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 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 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 232382174208 (52%)
InnoDB: Doing recovery: scanned up to log sequence number 232387417088 (53%)
InnoDB: Doing recovery: scanned up to log sequence number 232392659968 (53%)
InnoDB: Doing recovery: scanned up to log sequence number 232397902848 (54%)
InnoDB: Doing recovery: scanned up to log sequence number 232403145728 (55%)
InnoDB: Doing recovery: scanned up to log sequence number 232408388608 (56%)
InnoDB: Doing recovery: scanned up to log sequence number 232413631488 (57%)
InnoDB: Doing recovery: scanned up to log sequence number 232418874368 (58%)
InnoDB: Doing recovery: scanned up to log sequence number 232424117248 (59%)
InnoDB: Doing recovery: scanned up to log sequence number 232429360128 (59%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 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 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 232434603008 (60%)
InnoDB: Doing recovery: scanned up to log sequence number 232439845888 (61%)
InnoDB: Doing recovery: scanned up to log sequence number 232445088768 (62%)
InnoDB: Doing recovery: scanned up to log sequence number 232450331648 (63%)
InnoDB: Doing recovery: scanned up to log sequence number 232455574528 (64%)
InnoDB: Doing recovery: scanned up to log sequence number 232460817408 (65%)
InnoDB: Doing recovery: scanned up to log sequence number 232466060288 (65%)
InnoDB: Doing recovery: scanned up to log sequence number 232471303168 (66%)
InnoDB: Doing recovery: scanned up to log sequence number 232476546048 (67%)
InnoDB: Doing recovery: scanned up to log sequence number 232481788928 (68%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 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 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 232487031808 (69%)
InnoDB: Doing recovery: scanned up to log sequence number 232492274688 (70%)
InnoDB: Doing recovery: scanned up to log sequence number 232497517568 (71%)
InnoDB: Doing recovery: scanned up to log sequence number 232502760448 (72%)
InnoDB: Doing recovery: scanned up to log sequence number 232508003328 (72%)
InnoDB: Doing recovery: scanned up to log sequence number 232513246208 (73%)
InnoDB: Doing recovery: scanned up to log sequence number 232518489088 (74%)
InnoDB: Doing recovery: scanned up to log sequence number 232523731968 (75%)
InnoDB: Doing recovery: scanned up to log sequence number 232528974848 (76%)
InnoDB: Doing recovery: scanned up to log sequence number 232534217728 (77%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 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 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 232539460608 (78%)
InnoDB: Doing recovery: scanned up to log sequence number 232544703488 (78%)
InnoDB: Doing recovery: scanned up to log sequence number 232549946368 (79%)
InnoDB: Doing recovery: scanned up to log sequence number 232555189248 (80%)
InnoDB: Doing recovery: scanned up to log sequence number 232560432128 (81%)
InnoDB: Doing recovery: scanned up to log sequence number 232565675008 (82%)
InnoDB: Doing recovery: scanned up to log sequence number 232570917888 (83%)
InnoDB: Doing recovery: scanned up to log sequence number 232576160768 (84%)
InnoDB: Doing recovery: scanned up to log sequence number 232581403648 (85%)
InnoDB: Doing recovery: scanned up to log sequence number 232586646528 (85%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 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 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 232591889408 (86%)
InnoDB: Doing recovery: scanned up to log sequence number 232597132288 (87%)
InnoDB: Doing recovery: scanned up to log sequence number 232602375168 (88%)
InnoDB: Doing recovery: scanned up to log sequence number 232607618048 (89%)
InnoDB: Doing recovery: scanned up to log sequence number 232612860928 (90%)
InnoDB: Doing recovery: scanned up to log sequence number 232618103808 (91%)
InnoDB: Doing recovery: scanned up to log sequence number 232623346688 (91%)
InnoDB: Doing recovery: scanned up to log sequence number 232628589568 (92%)
InnoDB: Doing recovery: scanned up to log sequence number 232633832448 (93%)
InnoDB: Doing recovery: scanned up to log sequence number 232639075328 (94%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 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 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 232644318208 (95%)
InnoDB: Doing recovery: scanned up to log sequence number 232649561088 (96%)
InnoDB: Doing recovery: scanned up to log sequence number 232654803968 (97%)
InnoDB: Doing recovery: scanned up to log sequence number 232660046848 (97%)
InnoDB: Doing recovery: scanned up to log sequence number 232665289728 (98%)
InnoDB: Doing recovery: scanned up to log sequence number 232670532608 (99%)
InnoDB: Doing recovery: scanned up to log sequence number 232672354749 (100%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 0 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 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: xtrabackup: Last MySQL binlog file position 33415270, file name mysql-bin.000012
InnoDB: Creating shared tablespace for temporary tables
InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
InnoDB: File './ibtmp1' size is now 12 MB.
InnoDB: 96 redo rollback segment(s) found. 1 redo rollback segment(s) are active.
InnoDB: 32 non-redo rollback segment(s) are active.
InnoDB: page_cleaner: 1000ms intended loop took 76339ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
InnoDB: 5.7.26 started; log sequence number 232672354749
InnoDB: xtrabackup: Last MySQL binlog file position 33415270, file name mysql-bin.000012
xtrabackup: starting shutdown with innodb_fast_shutdown = 1
InnoDB: FTS optimize thread exiting.
InnoDB: Starting shutdown...
InnoDB: Shutdown completed; log sequence number 232672356123
InnoDB: Number of pools: 1
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_data_home_dir = .
xtrabackup: innodb_data_file_path = ibdata1:500M;ibdata2:500M;ibdata3:500M;ibdata4:100M:autoextend
xtrabackup: innodb_log_group_home_dir = .
xtrabackup: innodb_log_files_in_group = 3
xtrabackup: innodb_log_file_size = 268435456
InnoDB: PUNCH HOLE support available
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Uses event mutexes
InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
InnoDB: Compressed tables use zlib 1.2.3
InnoDB: Number of pools: 1
InnoDB: Not using CPU crc32 instructions
InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
InnoDB: Completed initialization of buffer pool
InnoDB: page_cleaner coordinator priority: -20
InnoDB: Setting log file ./ib_logfile101 size to 256 MB
InnoDB: Progress in MB:
100 200
InnoDB: Setting log file ./ib_logfile1 size to 256 MB
InnoDB: Progress in MB:
100 200
InnoDB: Setting log file ./ib_logfile2 size to 256 MB
InnoDB: Progress in MB:
100 200
InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
InnoDB: New log files created, LSN=232672356123
InnoDB: Highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 232672356364
InnoDB: Doing recovery: scanned up to log sequence number 232672356373 (0%)
InnoDB: Database was not shutdown normally!
InnoDB: Starting crash recovery.
InnoDB: xtrabackup: Last MySQL binlog file position 33415270, file name mysql-bin.000012
InnoDB: Removed temporary tablespace data file: "ibtmp1"
InnoDB: Creating shared tablespace for temporary tables
InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
InnoDB: File './ibtmp1' size is now 12 MB.
InnoDB: 96 redo rollback segment(s) found. 1 redo rollback segment(s) are active.
InnoDB: 32 non-redo rollback segment(s) are active.
InnoDB: page_cleaner: 1000ms intended loop took 12821ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
InnoDB: 5.7.26 started; log sequence number 232672356373
xtrabackup: starting shutdown with innodb_fast_shutdown = 1
InnoDB: FTS optimize thread exiting.
InnoDB: Starting shutdown...
InnoDB: Shutdown completed; log sequence number 232672356392
200403 15:39:10 completed OK!
3-2) 데이터 복구
copy-back 이나 move-back를 하면된다. 하기전에 /data/mysqldb_data는 비우고 새로 생성해야한다.
CREATE FUNCTION `xxx`.`FN_DATE_xxx`(varDate datetime) RETURNS datetime
BEGIN
declare varxxx datetime;
declare varDt varchar(8);
set varDt:= FN_YMD_xxx(varDate,'');
SELECT STR_TO_DATE(concat(varDt,'000000'), '%Y%m%d%H%i%s') INTO varxxx
FROM DUAL
;
RETURN varxxx;
END
fucntion에서 다시 function을 호출한다.
fucntion을 분석해보니 현재시간에서 일정기간을 뺀 range를 검색하는 목적으로 만든 듯했다.
개발당시 어떤 이슈가 있었는지는 모르지만 mysql function 레퍼런스를 확인할 시간적 여유가 없었나보다...
이게 쌓이고 쌓여 3년만에 대용량 테이블과 만나서 장애를 일으켰다...
튜닝)
// 수많은 join으로 되어있지만 대용량테이블 하나만 가지고 분석한다. 나머지 테이블 다붙여도 1초 내외이다.
//튜닝전
select * FROM xxxx.xxxxxxx AP
where 1=1
AND AP.REG_DATE BETWEEN xxx.FN_DATE_xxx (xxx.FN_xxx(NOW(),-14)) AND NOW()
//튜닝후
select * FROM xxxx.xxxxxxx AP
where 1=1
AND AP.REG_DATE BETWEEN DATE_FORMAT(DATE_SUB(NOW(), interval 14 day),'%Y-%m-%d 00:00:00') and NOW()
튜닝전)
1) 플랜 : 1 SIMPLE AP ALL REG_DATE 422277 11.11 Using where
2) 수행시간 : 51초
튜닝후)
1) 플랜 : 1 SIMPLE AP range REG_DATE REG_DATE 5 23128 100 Using index condition
개발에서 반영요청한 테이블 스키마를 보던 중에 datetime과 timestamp를 각각 선언해서 쓴 경우가 있어서 둘의 차이를 분석해보고 반영여부를 검토했다.
일단 구글링..
1. 날짜 및 시간 타입
1) DATETIME 이 타입은 매우 큰 범위의 값, 즉 1001년부터 9999년까지의 값을 1초 단위로 저장할 수 있다. DATETIME 은 날짜와 시각을 YYYYMMDDHHMMSS` 포맷의 정수 값으로 묶는데, 시간대에는 영향을 받지 않는다. DATETIME 은 8 바이트의 저장 공간을 사용한다.
2) TIMESTAMP 이름이 암시하듯, TIMESTAMP 타입은 1970년 1월 1일 자정(그리니치 평균시)을 기준으로 몇초가 지났는지를 저장하며, Unix 타임스탬프와 동일하다. TIMESTAMP 는 저장 공간을 4 바이트만 사용하므로 값의 범위가 DATETIME 보다 훨씬 작고, 1970년부터 2038년 사이의 값만을 저장할 수 있다.
MySQL 에서는 FROM_UNIXTIME(), UNIX_TIMESTAMP()` 같은 함수를 제공하는데 이 함수를 이용하면 Unix 타임스탬프를 날짜로 바꾸거나 그 날짜를 Unix 타임스탬프로 바꿀 수 있다.
TIMESTAMP 에 출력되는 값은 시간대에 따라 다르다. MySQL 서버, 운영체제, 클라이언트 연결은 모두 시간대 설정이 있다. 또한 TIMESTAMP 에는 DATETIME 에는 없는 특별한 특성들이 있다. 기본적으로 TIMESTAMP 컬럼에 값을 지정하지 않은 채로 행을 추가하면 첫 번째 TIMESTAMP 컬럼에 현재 시각을 넣는다. 또, UPDATE 실행 시 TIMESTAMP 값을 명시적으로 할당하지 않고 실행하면 TIMESTAMP 컬럼의 값이 자동으로 업데이트 된다. (즉, TIMESTAMP 는 기본적으로 NOT NULL)
2. 표로 정리
timestamp
datetime
날짜 범위
1970-01-01 09:00:00 ~ 2037-12-31 23:59:59
1000-01-01 00:00:00 ~ 9999-12-31 23:59:59
저장형태
숫자형
문자형
파일사이즈
4byte
8byte
자동입력?
O (defalut 값을 주면 굳이now() 컬럼 값 주지 않아도 자동입력됨)
x
3. 테스트
컬럼 스키마 선언
`REG_DATE` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP COMMENT '등록일시'
위처럼 선언하면 insert into 할 때 now() 안써도 된다는데 확인해본다.
음.. 잘된다.
보통은 datetime 이라면 insert into 테이블 ( SEQ, REG_DATE) values ( SEQ, now() );
이렇게 썼겠지만
타임스템프 default 옵션을 쓰면 insert into 테이블 ( SEQ, REG_DATE) values ( SEQ );
만 쓰면 자동으로 현재시간을 테이블에 넣는다.
4. timestamp 쓸것인가 말것인가
개발쪽에서 알고 기존 테이블 복붙해서 쓴 것이고 제대로 알고 쓴 것이 아닌 것으로 확인했고,
소스도 이미 now()를 넣는 것으로 컴파일해서 올렸다고 한다..
그래서 소스재배포 없이 그냥 DB 스키마를 datetime not null로 변경해서 반영했다.