GRA_*.log 파일 이해

GRA_*.log 오류는 노드가 트랜잭션을 적용하지 못해 클러스터에 복제 오류가 발생할 때 주로 생성됩니다. 이러한 트랜잭션의 대부분은 테이블, 인덱스 등의 변경과 같은 DDL과 관련되어 있습니다. 따라서 아래에서는 GRA_*.log 파일을 보고 기록되었을 수 있는 실패한 트랜잭션을 확인하는 간단한 방법을 보여 드리겠습니다.

참고: GRA_*.log 파일은 자동으로 삭제되지 않습니다. 이것이 MySQL datadir에 너무 많은 파일이 표시되는 이유이므로 해당 파일을 확인한 후에 직접 수동으로 삭제해야 합니다. 그리고 대부분의 경우 이러한 각 로그는 단일 트랜잭션 실패 후에 생성됩니다.

좋습니다. GRA_*.log를 보는 과정을 살펴보겠습니다.

내 MySQL dtaadir에는 GRA_*.log 파일 GRA_10_98558.log가 여러 개 있었습니다. 따라서 아래 예에서는 이 로그를 사용합니다. 그럼 다음 단계를 따르세요:

cat /tmp/GRA-header > /tmp/GRA-bin.log
cat /var/lib/mysql/GRA_10_98558.log >> /tmp/GRA-bin.log
mysqlbinlog -vvv /tmp/GRA-bin.log

이로 인해 다음과 같은 결과가 나왔습니다.

db-skyline-1# mysqlbinlog -vvv /tmp/GRA-bin.log
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#120715 7:45:56 server id 1 end_log_pos 107 Start: binlog v 4, server v 5.5.25-debug-log created 120715 7:45:56 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
NHUCUA8BAAAAZwAAAGsAAAABAAQANS41LjI1LWRlYnVnLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAA0dQJQEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
# at 107
#181121 2:06:51 server id 172163 end_log_pos 181 Query thread_id=18871 exec_time=0 error_code=0
use `skyline_db`/*!*/;
SET TIMESTAMP=1542766011/*!*/;
SET @@session.pseudo_thread_id=18871/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1073741824/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8mb4 *//*!*/;
SET @@session.character_set_client=45,@@session.collation_connection=45,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
ALTER TABLE `skyline_db`.`membership` 
MODIFY COLUMN `member_id` int(11) UNSIGNED NOT NULL AUTO_INCREMENT FIRST
/*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

따라서 위 로그에서 auto_increment 기본 키를 추가하려고 시도했을 때 문제가 발생했음을 알 수 있습니다. 이제 문제가 발생한 날짜와 시간이 표시되므로 MySQL 오류 로그에서 이를 확인할 수 있습니다. 보고된 오류 로그는 2018-11-21 02:06:51에 발생했습니다.

...skipping...
2018-11-21T02:06:51.733684-00:00 10 [ERROR] Slave SQL: Error 'Incorrect table definition; there can be only one auto column and it must be defined as a key' on query. Default database: 'skyline_db'. Query: 'ALTER TABLE `skyline_db`.`membership` 
MODIFY COLUMN `member_id` int(11) UNSIGNED NOT NULL AUTO_INCREMENT FIRST', Error_code: 1075
2018-11-21T02:06:51.733881-00:00 10 [Warning] WSREP: RBR event 1 Query apply warning: 1, 98558
2018-11-21T02:06:51.735663-00:00 10 [Warning] WSREP: Ignoring error for TO isolated action: source: 15bf5a43-ec93-11e8-8edc-ffbd5d545b2d version: 4 local: 0 state: APPLYING flags: 65 conn_id: 18871 trx_id: -1 seqnos (l: 95217, g: 98558, s: 98557, d: 98557, ts: 68341749422008)

실제로 auto_increment 기본 키를 추가하는 "ALTER TABLE" 문에 문제가 있음을 알 수 있습니다.

출처) https://georgechilumbu.wordpress.com/2018/11/23/understanding-the-percona-pxc-gra_-log-files/