Stuck in "ERROR 1047 (08S01): WSREP has not yet prepared node for application use" state
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC |
New
|
Undecided
|
Unassigned |
Bug Description
Using XtraDB Cluster version:
ii libmysqlclient18 5.6.x all Dummy package to satisfy dependencies when libperconaserve
ii libperconaserve
ii percona-xtrabackup 2.3.7-2.wheezy amd64 Open source backup tool for InnoDB and XtraDB
ii percona-
ii percona-
ii percona-
ii percona-
ii percona-
ii xtrabackup
on Ubuntu 16.04 and sometime when you restart a cluster member it gets stuck in Preparing state trying to apply the transactions it has missed when it was stopped. You can see in the process list that is is stuck applying the same transactions forever. My transactions are small.
Once stuck I ran:
mysql -e "SHOW FULL PROCESSLIST;SHOW GLOBAL VARIABLES;SHOW STATUS LIKE 'wsrep%';SHOW ENGINE InnoDB STATUS;"
and the output was:
1 system user NULL Sleep 289 wsrep aborter idle NULL 0 0
2 system user NULL Sleep 580 applied write set 7038 NULL 0 0
3 system user NULL Sleep 287 NULL NULL 0 0
4 system user NULL Sleep 580 applied write set 7037 NULL 0 0
5 system user NULL Sleep 287 NULL NULL 0 0
6 system user NULL Sleep 287 NULL NULL 0 0
7 system user NULL Sleep 579 applied write set 7040 NULL 0 0
8 system user NULL Sleep 287 NULL NULL 0 0
9 system user NULL Sleep 580 rolled back 7036 NULL 0 0
10 system user NULL Sleep 580 committed 7035 NULL 0 0
11 system user NULL Sleep 580 committed 7034 NULL 0 0
12 system user NULL Sleep 580 committed 7033 NULL 0 0
13 system user NULL Sleep 287 NULL NULL 0 0
14 system user NULL Sleep 287 NULL NULL 0 0
15 system user NULL Sleep 287 NULL NULL 0 0
16 system user NULL Sleep 287 NULL NULL 0 0
17 system user NULL Sleep 287 NULL NULL 0 0
2100 root localhost NULL Query 0 init SHOW FULL PROCESSLIST 0 0
auto_increment_
auto_increment_
autocommit ON
automatic_
avoid_temporal_
back_log 150
basedir /usr/
big_tables OFF
bind_address 0.0.0.0
binlog_cache_size 32768
binlog_checksum CRC32
binlog_
binlog_error_action IGNORE_ERROR
binlog_format ROW
binlog_
binlog_
binlog_
binlog_row_image FULL
binlog_
binlog_
binlogging_
block_encryptio
bulk_insert_
character_
character_
character_
character_
character_
character_
character_
character_sets_dir /usr/share/
collation_
collation_database latin1_swedish_ci
collation_server latin1_swedish_ci
completion_type NO_CHAIN
concurrent_insert ALWAYS
connect_timeout 5
core_file OFF
csv_mode
datadir /var/lib/mysql/
date_format %Y-%m-%d
datetime_format %Y-%m-%d %H:%i:%s
default_
default_
default_week_format 0
delay_key_write ON
delayed_
delayed_
delayed_queue_size 1000
disconnect_
div_precision_
end_markers_in_json OFF
enforce_
enforce_
eq_range_
event_scheduler OFF
expand_
expire_logs_days 2
explicit_
extra_max_
extra_port 0
flush OFF
flush_time 0
foreign_key_checks ON
ft_boolean_syntax + -><()~*:""&|
ft_max_word_len 84
ft_min_word_len 4
ft_query_
ft_stopword_file (built-in)
general_log OFF
general_log_file /var/lib/
group_concat_
gtid_deployment
gtid_executed
gtid_mode OFF
gtid_owned
gtid_purged
have_backup_locks YES
have_backup_
have_compress YES
have_crypt YES
have_dynamic_
have_elliptic_
have_geometry YES
have_openssl YES
have_profiling YES
have_query_cache YES
have_rtree_keys YES
have_snapshot_
have_ssl YES
have_statement_
have_symlink YES
have_tlsv1_2 YES
host_cache_size 628
hostname dp1
ignore_
ignore_db_dirs
init_connect
init_file
init_slave
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_checksums ON
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_doublewrite ON
innodb_
innodb_
innodb_file_format Antelope
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_flush_method O_DIRECT
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_ft_aux_table
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_io_capacity 400
innodb_
innodb_
innodb_large_prefix OFF
innodb_
innodb_
innodb_log_arch_dir ./
innodb_
innodb_log_archive OFF
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_open_files 400
innodb_
innodb_page_size 16384
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_read_only OFF
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_stats_method nulls_equal
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_strict_mode OFF
innodb_support_xa ON
innodb_
innodb_
innodb_table_locks ON
innodb_
innodb_
innodb_tmpdir
innodb_
innodb_
innodb_undo_logs 128
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_version 5.6.35-80.0
innodb_
interactive_timeout 28800
join_buffer_size 262144
keep_files_
key_buffer_size 134217728
key_cache_
key_cache_
key_cache_
kill_idle_
large_files_support ON
large_page_size 0
large_pages OFF
lc_messages en_US
lc_messages_dir /usr/share/mysql/
lc_time_names en_US
license GPL
local_infile ON
lock_wait_timeout 31536000
locked_in_memory OFF
log_bin ON
log_bin_basename /var/log/
log_bin_index /var/log/
log_bin_
log_bin_
log_error
log_output FILE
log_queries_
log_slave_updates OFF
log_slow_
log_slow_filter
log_slow_rate_limit 1
log_slow_rate_type session
log_slow_
log_slow_
log_slow_verbosity query_plan
log_throttle_
log_warnings 2
log_warnings_
long_query_time 10.000000
low_priority_
lower_case_
lower_case_
master_
master_
max_allowed_packet 134217728
max_binlog_
max_binlog_files 0
max_binlog_size 104857600
max_binlog_
max_connect_errors 100
max_connections 500
max_delayed_threads 20
max_digest_length 1024
max_error_count 64
max_heap_table_size 33554432
max_insert_
max_join_size 184467440737095
max_length_
max_prepared_
max_relay_log_size 0
max_seeks_for_key 184467440737095
max_slowlog_files 0
max_slowlog_size 0
max_sort_length 1024
max_sp_
max_statement_time 0
max_tmp_tables 32
max_user_
max_write_
metadata_
metadata_
min_examined_
multi_range_count 256
myisam_
myisam_
myisam_mmap_size 184467440737095
myisam_
myisam_
myisam_
myisam_stats_method nulls_unequal
myisam_use_mmap OFF
net_buffer_length 16384
net_read_timeout 30
net_retry_count 10
net_write_timeout 60
new OFF
old OFF
old_alter_table OFF
old_passwords 0
open_files_limit 1000000
optimizer_
optimizer_
optimizer_switch index_merge=
optimizer_trace enabled=
optimizer_
optimizer_
optimizer_
optimizer_
performance_schema ON
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
performance_
pid_file /var/run/
plugin_dir /usr/lib/
port 3306
preload_buffer_size 32768
profiling OFF
profiling_
protocol_version 10
proxy_protocol_
query_alloc_
query_cache_limit 131072
query_cache_
query_cache_size 67108864
query_cache_
query_cache_type OFF
query_cache_
query_prealloc_size 8192
range_alloc_
read_buffer_size 2097152
read_only OFF
read_rnd_
relay_log
relay_log_basename
relay_log_index
relay_log_info_file relay-log.info
relay_log_
relay_log_purge ON
relay_log_recovery OFF
relay_log_
report_host
report_password
report_port 3306
report_user
rpl_stop_
secure_auth ON
secure_file_priv /var/lib/
server_id 1
server_id_bits 32
server_uuid 9befe204-
sha256_
sha256_
show_old_temporals OFF
simplified_
skip_external_
skip_name_resolve OFF
skip_networking OFF
skip_show_database OFF
slave_allow_
slave_checkpoin
slave_checkpoin
slave_compresse
slave_exec_mode STRICT
slave_load_tmpdir /tmp
slave_max_
slave_net_timeout 3600
slave_parallel_
slave_pending_
slave_rows_
slave_skip_errors OFF
slave_sql_
slave_transacti
slave_type_
slow_launch_time 2
slow_query_log OFF
slow_query_
slow_query_log_file /var/log/
slow_query_
slow_query_
slow_query_
socket /var/run/
sort_buffer_size 4194304
sql_auto_is_null OFF
sql_big_selects ON
sql_buffer_result OFF
sql_log_bin ON
sql_log_off OFF
sql_mode NO_ENGINE_
sql_notes ON
sql_quote_
sql_safe_updates OFF
sql_select_limit 184467440737095
sql_slave_
sql_warnings OFF
ssl_ca /etc/mysql/
ssl_capath
ssl_cert /etc/mysql/
ssl_cipher
ssl_crl
ssl_crlpath
ssl_key /etc/mysql/
storage_engine InnoDB
stored_
super_read_only OFF
sync_binlog 0
sync_frm ON
sync_master_info 10000
sync_relay_log 10000
sync_relay_log_info 10000
system_time_zone UTC
table_definitio
table_open_cache 400
table_open_
thread_cache_size 16
thread_concurrency 10
thread_handling one-thread-
thread_
thread_
thread_
thread_
thread_
thread_pool_size 2
thread_
thread_stack 262144
thread_statistics OFF
time_format %H:%i:%s
time_zone SYSTEM
timed_mutexes OFF
tls_version TLSv1.1,TLSv1.2
tmp_table_size 33554432
tmpdir /tmp
transaction_
transaction_
tx_isolation READ-COMMITTED
tx_read_only OFF
unique_checks ON
updatable_
userstat OFF
version 5.6.35-80.0-56-log
version_comment Percona XtraDB Cluster (GPL), Release rel80.0, Revision 62752df, WSREP version 26.20, wsrep_26.20
version_
version_compile_os debian-linux-gnu
wait_timeout 600
wsrep_OSU_method TOI
wsrep_auto_
wsrep_causal_reads OFF
wsrep_certify_nonPK ON
wsrep_cluster_
wsrep_cluster_name Devportal Cluster
wsrep_convert_
wsrep_data_home_dir /var/lib/mysql/
wsrep_dbug_option
wsrep_debug OFF
wsrep_desync OFF
wsrep_dirty_reads OFF
wsrep_drupal_
wsrep_forced_
wsrep_load_
wsrep_log_conflicts OFF
wsrep_max_ws_rows 0
wsrep_max_ws_size 2147483647
wsrep_mysql_
wsrep_node_address 192.168.56.101
wsrep_node_
wsrep_node_name dp1
wsrep_notify_cmd /home/admin/
wsrep_preordered OFF
wsrep_provider /usr/lib/
wsrep_provider_
wsrep_recover OFF
wsrep_reject_
wsrep_replicate
wsrep_restart_slave OFF
wsrep_retry_
wsrep_slave_
wsrep_slave_
wsrep_slave_threads 16
wsrep_sst_auth ********
wsrep_sst_donor
wsrep_sst_
wsrep_sst_method xtrabackup-v2
wsrep_sst_
wsrep_start_
wsrep_sync_wait 0
wsrep_local_
wsrep_protocol_
wsrep_last_
wsrep_replicated 0
wsrep_replicate
wsrep_repl_keys 0
wsrep_repl_
wsrep_repl_
wsrep_repl_
wsrep_received 1
wsrep_received_
wsrep_local_commits 0
wsrep_local_
wsrep_local_replays 0
wsrep_local_
wsrep_local_
wsrep_local_
wsrep_local_
wsrep_local_
wsrep_local_
wsrep_local_
wsrep_local_
wsrep_local_
wsrep_flow_
wsrep_flow_
wsrep_flow_
wsrep_flow_
wsrep_cert_
wsrep_apply_oooe 0.700000
wsrep_apply_oool 0.000000
wsrep_apply_window 6.900000
wsrep_commit_oooe 0.000000
wsrep_commit_oool 0.000000
wsrep_commit_window 3.000000
wsrep_local_state 1
wsrep_local_
wsrep_cert_
wsrep_cert_
wsrep_gcache_
wsrep_causal_reads 0
wsrep_cert_interval 0.000000
wsrep_incoming_
wsrep_desync_count 0
wsrep_evs_delayed
wsrep_evs_
wsrep_evs_
wsrep_evs_state OPERATIONAL
wsrep_gcomm_uuid 2e08bbed-
wsrep_cluster_
wsrep_cluster_size 2
wsrep_cluster_
wsrep_cluster_
wsrep_connected ON
wsrep_local_
wsrep_local_index 1
wsrep_provider_name Galera
wsrep_provider_
wsrep_provider_
wsrep_ready OFF
InnoDB
=======
2017-08-07 09:14:45 7f87b3f7d700 INNODB MONITOR OUTPUT
=======
Per second averages calculated from the last 24 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 2 srv_active, 0 srv_shutdown, 284 srv_idle
srv_master_thread log flush and writes: 286
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 17
OS WAIT ARRAY INFO: signal count 14
Mutex spin waits 16, rounds 345, OS waits 9
RW-shared spins 6, rounds 151, OS waits 5
RW-excl spins 1, rounds 60, OS waits 2
Spin rounds per wait: 21.56 mutex, 25.17 RW-shared, 60.00 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 33315
Purge done for trx's n:o < 33315 undo n:o < 0 state: running but idle
History list length 2358
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 2100, OS thread handle 0x7f87b3f7d700, query id 6201 localhost root init
SHOW ENGINE InnoDB STATUS
---TRANSACTION 33302, not started
MySQL thread id 11, OS thread handle 0x7f87bc9a1700, query id 13 committed 7034
---TRANSACTION 33301, not started
MySQL thread id 10, OS thread handle 0x7f87bc91f700, query id 12 committed 7035
---TRANSACTION 33298, not started
MySQL thread id 9, OS thread handle 0x7f87bc85c700, query id 10 rolled back 7036
---TRANSACTION 33291, not started
MySQL thread id 12, OS thread handle 0x7f87bc9e2700, query id 5 committed 7033
---TRANSACTION 33306, ACTIVE 287 sec
2 lock struct(s), heap size 360, 1 row lock(s), undo log entries 1
MySQL thread id 4, OS thread handle 0x7f87bca23700, query id 14 applied write set 7037
---TRANSACTION 33300, ACTIVE 287 sec
2 lock struct(s), heap size 360, 1 row lock(s), undo log entries 1
MySQL thread id 7, OS thread handle 0x7f87bc89d700, query id 11 applied write set 7040
---TRANSACTION 33296, ACTIVE 287 sec
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 1
MySQL thread id 2, OS thread handle 0x7f880dc44700, query id 8 applied write set 7038
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
544 OS file reads, 64 OS file writes, 17 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
insert 0, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 73099936
Log flushed up to 73099936
Pages flushed up to 73099936
Last checkpoint at 73099936
Max checkpoint age 434154333
Checkpoint age target 420587011
Modified age 0
Checkpoint age 0
0 pending log writes, 0 pending chkp writes
26 log i/o's done, 0.00 log i/o's/second
-------
BUFFER POOL AND MEMORY
-------
Total memory allocated 1081769984; in additional pool allocated 0
Total memory allocated by read views 112
Internal hash tables (constant factor + variable factor)
Adaptive hash index 18334688 (18314104 + 20584)
Page hash 1145912 (buffer pool 0 only)
Dictionary cache 4862613 (4580624 + 281989)
File system 348112 (82672 + 265440)
Lock system 2574424 (2571544 + 2880)
Recovery system 0 (0 + 0)
Dictionary memory allocated 281989
Buffer pool size 63423
Buffer pool size, bytes 1039122432
Free buffers 62908
Database pages 514
Old database pages 209
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 510, created 4, written 41
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 514, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
3 RW transactions active inside InnoDB
0 RO transactions active inside InnoDB
3 out of 1000 descriptors used
Main thread process no. 24110, id 140220943857408, state: sleeping
Number of rows inserted 4, updated 2, deleted 3, read 5
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
-------
END OF INNODB MONITOR OUTPUT
=======
It is possible that this only happens if ntp jumps the clock forward by a significant amount (several minutes perhaps) whilst mysqld is running.