'분류 전체보기'에 해당되는 글 380건

쿼리 튜닝하고 장애 대처하다보니 mysql dba로 몇 년이 지났다.

궁금할 때나 장애로 날을 샐 때마다 내 스승은 구글링이며 몇가지 책등 일뿐..

어느 순간부터 기본부터 다시 공부하고자 하는생각이 들었다. 일단 쿼리 수행 구조부터 다시 시작한다.

real mysql 에 나온 것을 바탕으로 구글링해서 괜찮은 이미지를 차용해서 정리해 보았다.

장애때 중요한 부분은 옵티마이져 - 실행계획, 쿼리실행엔진 - 핸들러 (Disk I/O와 관련) 으로 보인다.

그래도 정리를 한번 해놓고 나니 깔끔하긴 하다. 

이제 메모리 사용과 접목해본다.

참조 : https://rrhh234cm.tistory.com/140

하루 단위 풀백업이 1.4T가 넘어가면서 xtrabackup에 압축이슈가 발생하였다.
xtrabackup은 2시간내외로 끝나는데 tar 압축은 10시간이 넘어가다보니 좀더 나은 방법을 검토 중에
좋은 참조 문서를 발견하였다.

일단 증분백업을 검토해봤지만.. 아무래도 관리하기 귀찮다. 어쩔 수 없이 증분백업데이터를 한번은 merge 해야하고, 관리이슈가 크기 때문에 풀백업을 유지하고
압축시간을 줄일 수 있는 방법을 찾던 중에 pigz라는 것을 찾게 되었다.

오라클의 parallel 힌트같이 압축중에 데이터 용량이 큰 파일을 만났을 시 process를 늘려서 한번에 처리하는 똑똑한 압축툴이다. tar과 같이 쓸 수 있어 기존로직을 많이 변경하지 않아도 되서 테스트를 진행하였다.

###parallel 압축 gz 방식 검토 ###
#서버에 pigz가 설치되어있는지 확인

rpm -qa | grep pigz

#pigz-2.3.4-1.el6.x86_64.rpm 설치

[root@ temp]# rpm -Uvh pigz-2.3.4-1.el6.x86_64.rpm
경고: pigz-2.3.4-1.el6.x86_64.rpm: Header V3 RSA/SHA256 Signature, key ID 0608b895: NOKEY
준비 중...               ########################################### [100%]
   1:pigz                   ########################################### [100%]

#1) 기존 압축방식과 비교
1-1) tar.gz
tar -cvzf test.tar.gz backup
#시작 17:10분

#종료 17:52분

--> 42분

1-2) tar pigz
tar 명령어에 외부 압축프로그램 바로 지정하는 방식을 사용한다면,
tar -I pigz -cvf blah.tar.gz blah blah 압축하기
tar -I pigz -xvf blah blah blah 압축풀기

#바로테스트진행
tar -I pigz -cvf test2.tar.gz backup

#top 확인

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 

5454 root 20 0 1813m 17m 584 S 1247.8 0.1 12:29.46 pigz
5453 root 20 0 113m 1272 1044 D 18.8 0.0 0:12.01 tar
358 root 20 0 0 0 0 S 2.3 0.0 6:35.84 kswapd1
357 root 20 0 0 0 0 S 1.7 0.0 11:00.23 kswapd0
5490 webadmin 20 0 15424 1660 912 R 0.7 0.0 0:00.44 top
--> cpu 1247%...ㄷㄷㄷ 상용서비스에서 쓸 수 있을까;

#시작 17:54분 

#종료 18:04분

--> 10분

#1-3) Process 설정

-p, --processes n Allow up to n compression threads (default is the
number of online processors, or 8 if unknown)

-->cpu의 Core 수를 조절할 수 있게 설정된다. 정확하게는 하이퍼스레딩 개수이다.

예를들어 물리 core가 8 core라면 top으로보면 1600% 까지 쓸 수 있다고 보면된다.

하지만 실제로 확인해보면 오버클럭되서 max는 1880% 정도까지 나온다.

Compress a directory using tar:
tar cf - path/to/directory | pigz > filename.tar.gz

#1-4) pigz 압축률 테스트
tar -cvf - backup | pigz -9 -p 4 > test2.tar.gz

#top 확인

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
591 root 20 0 322m 4152 592 S 404.9 0.0 29:37.29 pigz
590 root 20 0 113m 1284 1052 S 3.3 0.0 0:10.82 tar
357 root 20 0 0 0 0 S 0.7 0.0 11:18.11 kswapd0
229 root 20 0 0 0 0 S 0.3 0.0 20:33.63 kblockd/3
-->압축률 (9: 성능이 좋은것, 설정은 12까지 있는데 이건 잘 사용 안하는 거 같다)
압축해서 데이터 사이즈는 줄어들었지만 너무느리다.

# 압축률 default 로 테스트
tar -cvf - backup | pigz -6 -p 6 > test2.tar.gz

--> 압축률 default , process 6
--> 수행시간 10분

데이터 사이즈는 tar.gz로 압축할 떄와 비슷하지만 수행시간을 1/4로 줄였다.
core도 서버와 DB가 사용할 부분을 남겨놓고 설정했고
가장 원하는 방식으로 테스트를 마쳤다.

#반영

개발DB의 실제 반영은 xtrabackup에서 지원하는 --stream =  tar을 사용하여 굳이 백업 디렉토리를 만들지 않고

압축파일로만 관리하도록 반영하였다.

-> 이후 10.4로 DB upgrade를 하면서 한번 더 확인했는데

mariabackup에서는 --stream = tar은  지원하지않는다. 대신 xbstream 이라는 압축포멧을 default로 지원한다.

참조 : mariadb.com/kb/en/mariabackup-options/#-stream

/usr/bin/innobackupex \
--host=127.0.0.1 \
--user=root \
--password='비번' \
--ibbackup=xtrabackup \
--no-lock \
--stream=tar ./ | pigz -p 6 > backup.tar.gz

상용DB는 위와 같은 방식이 아니라 장애시 바로 점검이 가능하도록 백업디렉토리와 압축파일을 분리하여 관리하고 있다.

실제 상용에 적용할 때는 --no-lock 옵션을 사용하기 때문에 바로 압축하는 방식을 사용하지 못하였다. apply log를 합친 다음에 압축을 하여야 하기 때문이다.

1) xtrabackup -> 2) applay_log merge -> 3) pigz 압축 -> 4) transfer

# pigz 적용스크립트

tar -cf - 압축디렉토리 | pigz -p 6 > 압축파일이름.tar.gz
// -cvf로 하면 압축파일을 볼수있는데 압축파일이 TB 단위다 보니 이거 넣으면 확실히 더 느리다 걍 뺀다.

#pigz Man page
pigz --version (return code: 0)
pigz 2.4

tar --use-compress-program="pigz -p 4" -cvf mvno-test.tar.gz backup

pigz --help (return code: 0)
Usage: pigz [options] [files ...]
will compress files in place, adding the suffix '.gz'. If no files are
specified, stdin will be compressed to stdout. pigz does what gzip does,
but spreads the work over multiple processors and cores when compressing.

Options:
-0 to -9, -11 Compression level (level 11, zopfli, is much slower)
--fast, --best Compression levels 1 and 9 respectively
-b, --blocksize mmm Set compression block size to mmmK (default 128K)
-c, --stdout Write all processed output to stdout (won't delete)
-d, --decompress Decompress the compressed input
-f, --force Force overwrite, compress .gz, links, and to terminal
-F --first Do iterations first, before block split for -11
-h, --help Display a help screen and quit
-i, --independent Compress blocks independently for damage recovery
-I, --iterations n Number of iterations for -11 optimization
-J, --maxsplits n Maximum number of split blocks for -11
-k, --keep Do not delete original file after processing
-K, --zip Compress to PKWare zip (.zip) single entry format
-l, --list List the contents of the compressed input
-L, --license Display the pigz license and quit
-m, --no-time Do not store or restore mod time
-M, --time Store or restore mod time
-n, --no-name Do not store or restore file name or mod time
-N, --name Store or restore file name and mod time
-O --oneblock Do not split into smaller blocks for -11
-p, --processes n Allow up to n compression threads (default is the
number of online processors, or 8 if unknown)
-q, --quiet Print no messages, even on error
-r, --recursive Process the contents of all subdirectories
-R, --rsyncable Input-determined block locations for rsync
-S, --suffix .sss Use suffix .sss instead of .gz (for compression)
-t, --test Test the integrity of the compressed input
-v, --verbose Provide more verbose output
-V --version Show the version of pigz
-Y --synchronous Force output file write to permanent storage
-z, --zlib Compress to zlib (.zz) instead of gzip format

보고 싶었는데 번역본이 없어서 구글링으로만 리플리케이션 부분 참고만 했었던..

번역본이 나왔네?^^

replication과 performance schema 공부좀 해볼까~

사업부서의 요청으로 OLAP 관련 쿼리를 짜던 중에 뜻하지 않던 슬로우쿼리를 만났다.

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을 떠봤다.

흠..일단 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 확인

전체 데이터 추출시간 2초이내로 끝났고, 인덱스 스캔이 (eq_ref ) 제대로 되는 것을 확인할 수 있다.

mysql의 옵티마이져는 생각보다 똑똑했다..;

--> 최근에 개발된 테이블 스키마가 문제였고, 데이터 형변환을 적용하려 개발쪽과 협의해서 추가반영을 하였다.

고객이 늘면서 1000만 row가 넘어가는 테이블이 속속들이 생기고 있다.

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가 변경지점까지 잘따라갔는지 확인하기 위해서다.

2) 백업

Master DB<------------Slave DB

Slave 에서 Master로 가서 xtrabackup으로 데이터를 끌어온다.

ssh -o StrictHostKeyChecking=no mysql@192.168.10.101 \
 "innobackupex \
 --host="127.0.0.1" \
 --port=3306 \
 --user=root \
 --password="DB비번" \
 --no-lock \
 --stream=xbstream \
 /backup/temp | pv --rate-limit 50000000" 2> innobackupex.log \
 | xbstream -x 2> xbstream.log

흠.. 뭐 바로 될거라고 생각안했지만 일단 xtrabackup shell이 제대로 동작을 안한다.

구글링해보니 xtrabackup 2.4.12 ver이상부터 된다는 얘기가 있다.

음... 지금보니 xtarbackup 2.4.9다. version 패치한다.

[root@mysqldb_tmp]# rpm -Uvh percona-xtrabackup-24-2.4.19-1.el6.x86_64.rpm
경고: percona-xtrabackup-24-2.4.19-1.el6.x86_64.rpm: Header V4 RSA/SHA256 Signature, key ID 8507efa5: NOKEY
준비 중...               ########################################### [100%]
   1:percona-xtrabackup-24  ########################################### [100%]
[root@mysqldb_tmp]# rpm -Uvh percona-xtrabackup-24-debuginfo-2.4.19-1.el6.x86_64.rpm
경고: percona-xtrabackup-24-debuginfo-2.4.19-1.el6.x86_64.rpm: Header V4 RSA/SHA256 Signature, key ID 8507efa5: NOKEY
준비 중...               ########################################### [100%]
   1:percona-xtrabackup-24-d########################################### [100%]

xtarbackup 2.4.19로 올리니 잘된다. version 문제였다.

백업이 잘되었는지 여부는

마지막에 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는 비우고 새로 생성해야한다.

/usr/bin/innobackupex --defaults-file=/etc/my.cnf --datadir=/data/mysqldb_data --copy-back /backup2/temp/temp

4) slave replication 연결

--> 현재는 Master는 10만건의 데이터가 전부 임시테이블에 들어가 있고 slave는 DB올리고 보니 54689이 쌓여있음을 확인했다. 데이터유실 없는 replication이 되려면 임시테이블의 데이터가 replication 후 10만건이 되면 된다.

vi xtrabackup_binlog_info
mysql-bin.000012        61288234

vi xtrabackup_binlog_pos_innodb
mysql-bin.000012        61287127

둘 중에 아래꺼를 slave 복구 때 적용하면 된다.

change master to
master_host='192.168.10.101',
master_user='repl',
master_password='repl',
master_port=3306,
master_log_file='mysql-bin.000012',
master_log_pos=61287127;

slave start;

--> show slave status\G; 로 동기화완료후 확인해보니 slave 임시테이블의 데이터가 10만건임을 확인했다.

replication 동기화 끝!! 데이터 유실없이 online slave 구축이 가능함을 확인했다.

참조사이트

https://gywn.net/tag/xtrabackup/

where 절에 function 쓰면 성능이슈가 있다고 한다.

실제로 본적은 많지 않은데... 오늘 장애를 만나면서 그 끝판왕을 보았다.

이슈를 기록하고 튜닝한 내용을 정리한다.

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

2) 수행시간 : 0.83초

where 조건절에는 웬만하면 function 쓰면 안되고 어쩔 수 없이 쓰더라도

mysql에서 기본으로 제공하는 function을 사용하는 것이 좋다.

개발에서 반영요청한 테이블 스키마를 보던 중에 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. 표로 정리

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로 변경해서 반영했다.

DB 서버의 UTC 값을 가져와서 해외로 이전할 때는 문제 될 거 같긴 하지만

성능으로 보자면 파일사이즈(4byte)가 datetime 의 절반이라 

2038년까지는 timestamp를 쓰는 게 좋을 거 같긴하다..^^

mysqldump 뜨던중에 갑자기 이런 에러가 났다

뭐지? 급당황... 찾아보니 생각보다 간단한 에러였다.

용량이 다 찼다는 에러다 ㅋㅋ

비우고 다시 dump 뜨면 된다.

[admin@backup]$ mysqldump -uroot -p DB스키마 테이블이름  > 62_TALBES.sql

Filesystem Type Size Used Avail Use% Mounted on
/dev/sda2 ext4 20G 19G 16M 100% /
tmpfs tmpfs 16G 0 16G 0% /dev/shm
/dev/sda1 ext4 477M 111M 341M 25% /boot
/dev/sda5 ext4 20G 9.5G 9.1G 52% /usr
/dev/sda7 ext4 3.9G 645M 3.0G 18% /var
/dev/sda6 ext4 3.9G 8.2M 3.7G 1% /tmp
/dev/sdb1 ext4 1.1T 264G 780G 26% /data
/dev/sda8 ext4 212G 98G 103G 49% /backup
xxx.xxx.xxx.xxx:/data nfs 13T 3.6T 8.1T 31% /data2