Mysql will not start

MySQL & MariaDB Percona XtraDB Cluster 5.x
1

Hi,

1 node is not starting with the following error:

Starting MySQL (Percona XtraDB Cluster)… ERROR! The server quit without updating PID file (/var/lib/mysql/tree.flyheight.com.pid).
ERROR! MySQL (Percona XtraDB Cluster) server startup failed!

Here is the error log:

cat /var/log/mysql.log
150408 16:11:10 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
150408 16:11:10 mysqld_safe WSREP: Running position recovery with --log_error=‘/var/lib/mysql/wsrep_recovery.5CgAuw’ --pid-file=‘/var/lib/mysql/tree.flyheight.com-recover.pid’
2015-04-08 16:11:11 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
150408 16:11:31 mysqld_safe WSREP: Failed to recover position: 2015-04-08 16:11:11 14080 [Warning] Using unique option prefix innodb_log_group_home instead of innodb-log-group-home-dir is deprecated and will be removed in a future release. Please use the full name instead. 2015-04-08 16:11:11 14080 [Note] Plugin ‘FEDERATED’ is disabled. 2015-04-08 16:11:11 14080 [Note] InnoDB: Using atomics to ref count buffer pool pages 2015-04-08 16:11:11 14080 [Note] InnoDB: The InnoDB memory heap is disabled 2015-04-08 16:11:11 14080 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2015-04-08 16:11:11 14080 [Note] InnoDB: Memory barrier is not used 2015-04-08 16:11:11 14080 [Note] InnoDB: Compressed tables use zlib 1.2.3 2015-04-08 16:11:11 14080 [Note] InnoDB: Using Linux native AIO 2015-04-08 16:11:11 14080 [Note] InnoDB: Using CPU crc32 instructions 2015-04-08 16:11:11 14080 [Note] InnoDB: Initializing buffer pool, size = 108.0G 2015-04-08 16:11:15 14080 [Note] InnoDB: Completed initialization of buffer pool 2015-04-08 16:11:16 14080 [Note] InnoDB: Setting log file /var/lib/mysql/ib_logfile101 size to 512 MB InnoDB: Progress in MB: 100 200 300 400 500 2015-04-08 16:11:20 14080 [Note] InnoDB: Setting log file /var/lib/mysql/ib_logfile1 size to 512 MB InnoDB: Progress in MB: 100 200 300 400 500 2015-04-08 16:11:24 14080 [Note] InnoDB: Renaming log file /var/lib/mysql/ib_logfile101 to /var/lib/mysql/ib_logfile0 2015-04-08 16:11:24 14080 [Warning] InnoDB: New log files created, LSN=342478053398 2015-04-08 16:11:24 14080 [Note] InnoDB: Highest supported file format is Barracuda. InnoDB: Transaction 13230725930 was in the XA prepared state. InnoDB: 1 transaction(s) which must be rolled back or cleaned up InnoDB: in total 0 row operations to undo InnoDB: Trx id counter is 13230743808 2015-04-08 16:11:26 14080 [Note] InnoDB: 128 rollback segment(s) are active. InnoDB: Starting in background the rollback of uncommitted transactions 2015-04-08 16:11:26 7fcf68280700 InnoDB: Rollback of non-prepared transactions completed 2015-04-08 16:11:26 14080 [Note] InnoDB: Waiting for purge to start 2015-04-08 16:11:26 14080 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.20-68.0 started; log sequence number 342478053900 2015-04-08 16:11:26 14080 [Warning] InnoDB: Skipping buffer pool dump/restore during wsrep recovery. 2015-04-08 16:11:26 7febc83567e0 InnoDB: Starting recovery for XA transactions… 2015-04-08 16:11:26 7febc83567e0 InnoDB: Transaction 13230725930 in prepared state after recovery 2015-04-08 16:11:26 7febc83567e0 InnoDB: Transaction contains changes to 1 rows 2015-04-08 16:11:26 7febc83567e0 InnoDB: 1 transactions in prepared state after recovery 2015-04-08 16:11:26 14080 [Note] Found 1 prepared transaction(s) in InnoDB 2015-04-08 16:11:26 14080 [ERROR] Found 1 prepared transactions! It means that mysqld was not shut down properly last time and critical recovery information (last binlog or tc.log file) was manually deleted after a crash. You have to start mysqld with --tc-heuristic-recover switch to commit or rollback pending transactions. 2015-04-08 16:11:26 14080 [ERROR] Aborting 2015-04-08 16:11:26 14080 [Note] Binlog end 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘partition’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘ARCHIVE’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘BLACKHOLE’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘PERFORMANCE_SCHEMA’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_CHANGED_PAGES’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_SYS_DATAFILES’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_SYS_TABLESPACES’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_SYS_FOREIGN_COLS’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_SYS_FOREIGN’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_SYS_FIELDS’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_SYS_COLUMNS’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_SYS_INDEXES’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_SYS_TABLESTATS’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_SYS_TABLES’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_FT_INDEX_TABLE’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_FT_INDEX_CACHE’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_FT_CONFIG’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_FT_BEING_DELETED’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_FT_DELETED’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_FT_DEFAULT_STOPWORD’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_METRICS’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_BUFFER_POOL_STATS’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_BUFFER_PAGE_LRU’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_BUFFER_PAGE’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_CMP_PER_INDEX_RESET’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_CMP_PER_INDEX’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_CMPMEM_RESET’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_CMPMEM’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_CMP_RESET’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_CMP’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_LOCK_WAITS’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_LOCKS’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘INNODB_TRX’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘XTRADB_RSEG’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘XTRADB_INTERNAL_HASH_TABLES’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘XTRADB_READ_VIEW’ 2015-04-08 16:11:26 14080 [Note] Shutting down plugin ‘InnoDB’ 2015-04-08 16:11:26 14080 [Note] InnoDB: FTS optimize thread exiting. 2015-04-08 16:11:26 14080 [Note] InnoDB: Starting shutdown… 2015-04-08 16:11:31 14080 [Note] InnoDB: Shutdown completed; log sequence number 342478053910 2015-04-08 16:11:31 14080 [Note] Shutting down plugin ‘CSV’ 2015-04-08 16:11:31 14080 [Note] Shutting down plugin ‘MyISAM’ 2015-04-08 16:11:31 14080 [Note] Shutting down plugin ‘MRG_MYISAM’ 2015-04-08 16:11:31 14080 [Note] Shutting down plugin ‘MEMORY’ 2015-04-08 16:11:31 14080 [Note] Shutting down plugin ‘sha256_password’ 2015-04-08 16:11:31 14080 [Note] Shutting down plugin ‘mysql_old_password’ 2015-04-08 16:11:31 14080 [Note] Shutting down plugin ‘mysql_native_password’ 2015-04-08 16:11:31 14080 [Note] Shutting down plugin ‘wsrep’ 2015-04-08 16:11:31 14080 [Note] Shutting down plugin ‘binlog’ 2015-04-08 16:11:31 14080 [Note] /usr/sbin/mysqld: Shutdown complete

Appreciate anyone’s help :slight_smile:

2

What happened to this node? Why the transaction logs were deleted prior to this start? Let me just quote this error log fragment:


2015-04-08 16:11:16 14080 [Note] InnoDB: Setting log file /var/lib/mysql/ib_logfile101 size to 512 MB InnoDB: Progress in MB: 100 200 300 400 500
2015-04-08 16:11:20 14080 [Note] InnoDB: Setting log file /var/lib/mysql/ib_logfile1 size to 512 MB InnoDB: Progress in MB: 100 200 300 400 500
2015-04-08 16:11:24 14080 [Note] InnoDB: Renaming log file /var/lib/mysql/ib_logfile101 to /var/lib/mysql/ib_logfile0
2015-04-08 16:11:24 14080 [Warning] InnoDB: New log files created, LSN=342478053398
2015-04-08 16:11:24 14080 [Note] InnoDB: Highest supported file format is Barracuda. InnoDB: Transaction 13230725930 was in the XA prepared state. InnoDB: 1 transaction(s) which must be rolled back or cleaned up InnoDB: in total 0 row operations to undo InnoDB: Trx id counter is 13230743808
2015-04-08 16:11:26 14080 [Note] InnoDB: 128 rollback segment(s) are active. InnoDB: Starting in background the rollback of uncommitted transactions
2015-04-08 16:11:26 7fcf68280700 InnoDB: Rollback of non-prepared transactions completed
2015-04-08 16:11:26 14080 [Note] InnoDB: Waiting for purge to start
2015-04-08 16:11:26 14080 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.20-68.0 started; log sequence number 342478053900
2015-04-08 16:11:26 14080 [Warning] InnoDB: Skipping buffer pool dump/restore during wsrep recovery.
2015-04-08 16:11:26 7febc83567e0 InnoDB: Starting recovery for XA transactions...
2015-04-08 16:11:26 7febc83567e0 InnoDB: Transaction 13230725930 in prepared state after recovery
2015-04-08 16:11:26 7febc83567e0 InnoDB: Transaction contains changes to 1 rows
2015-04-08 16:11:26 7febc83567e0 InnoDB: 1 transactions in prepared state after recovery
2015-04-08 16:11:26 14080 [Note] Found 1 prepared transaction(s) in InnoDB
2015-04-08 16:11:26 14080 [ERROR] Found 1 prepared transactions! It means that mysqld was not shut down properly last time and critical recovery information (last binlog or tc.log file) was manually deleted after a crash. You have to start mysqld with --tc-heuristic-recover switch to commit or rollback pending transactions.
2015-04-08 16:11:26 14080 [ERROR] Aborting
3

Hey przemek, I have the exact same issue, how can we solve it? what can we do if we see our selves in this situation?

In my case, I rebooted the VM twice too fast apparenty.

4

Hi there,
This post is really old and things might have moved on. Are you able to create a Forum post anew and put some of your own information in e.g. version, environment etc. It could help with tracking down your issue. If you have any error logs etc. that would help. Thanks!

5

Hello every body I have a problem too and is this:

my server was rebbot, after it my percona cluester dont wake up

i have the follow error:

Loaded: loaded (/usr/lib/systemd/system/mysql@.service; disabled; vendor preset: disabled)
Active: failed (Result: exit-code) since Mon 2018-10-15 15:28:39 CEST; 1min 4s ago
Process: 14583 ExecStopPost=/usr/bin/mysql-systemd stop-post (code=exited, status=0/SUCCESS)
Process: 14554 ExecStop=/usr/bin/mysql-systemd stop (code=exited, status=2)
Process: 14136 ExecStartPost=/usr/bin/mysql-systemd start-post $MAINPID (code=exited, status=1/FAILURE)
Process: 14135 ExecStart=/usr/bin/mysqld_safe --basedir=/usr ${EXTRA_ARGS} (code=exited, status=0/SUCCESS)
Process: 14087 ExecStartPre=/usr/bin/mysql-systemd start-pre (code=exited, status=0/SUCCESS)
Main PID: 14135 (code=exited, status=0/SUCCESS)

Oct 15 15:28:39 servidor-1.localdomain mysql-systemd[14136]: ERROR! mysqld_safe with PID 14135 has already exited: FAILURE
Oct 15 15:28:39 servidor-1.localdomain systemd[1]: mysql @bootstrap.service: control process exited, code=exited status=1
Oct 15 15:28:39 servidor-1.localdomain mysql-systemd[14554]: WARNING: mysql pid file /run/mysqld/mysql.pid empty or not readable
Oct 15 15:28:39 servidor-1.localdomain mysql-systemd[14554]: ERROR! mysql already dead
Oct 15 15:28:39 servidor-1.localdomain systemd[1]: mysql @bootstrap.service: control process exited, code=exited status=2
Oct 15 15:28:39 servidor-1.localdomain systemd[1]: Failed to start Percona XtraDB Cluster with config /etc/sysconfig/mysql.bootstrap.
Oct 15 15:28:39 servidor-1.localdomain systemd[1]: Unit mysql @bootstrap.serviceentered failed state.
Oct 15 15:28:39 servidor-1.localdomain systemd[1]: mysql @bootstrap.service failed.
Oct 15 15:28:39 servidor-1.localdomain mysql-systemd[14583]: WARNING: mysql pid file /run/mysqld/mysql.pid empty or not readable
Oct 15 15:28:39 servidor-1.localdomain mysql-systemd[14583]: WARNING: mysql may be already dead

my my.cnf is :

[mysqld]

user = mysql

log_bin
binlog_format = ROW

innodb_buffer_pool_size = 1000M
innodb_flush_log_at_trx_commit = 0
innodb_flush_method = O_DIRECT
innodb_log_files_in_group = 2
innodb_log_file_size = 60M
innodb_file_per_table = 1

datadir = /var/lib/mysql

wsrep_cluster_address = gcomm://119.20.166.9,149.202.167.71
wsrep_provider = /usr/lib64/galera3/libgalera_smm.so
wsrep_slave_threads = 8
wsrep_cluster_name = db.com
wsrep_node_name = Node1
wsrep_node_address = 119.20.166.9

default_storage_engine=InnoDB
innodb_locks_unsafe_for_binlog = 1
innodb_autoinc_lock_mode = 2

wsrep_sst_method=xtrabackup-v2
wsrep_sst_auth=“sstuser:s3cret”

[mysqld_safe]
pid-file = /run/mysqld/mysql.pid
syslog

!includedir /etc/my.cnf.d

–

My SO is: CENTOS 7

i hace disabled firewall and

sellinux disabled too

the command used for wake up the master

systemctl start mysql @bootstrap.service