[9.0][BVT] Deployment fails on execution of task `database` on one of the nodes

[Roman Podoliaka]

One of the recent BVT builds (https://product-ci.infra.mirantis.net/job/9.x.main.ubuntu.bvt_2/543/) failed with the following error in astute.log:

2016-11-22 15:15:11 INFO [15066] Cluster[]: All nodes are finished. Failed tasks: Task[database/5] Stopping the deployment process!

puppet.log on node-5 says that connection to a local mysqld server can't be established:

2016-11-22 14:59:55 +0000 /Stage[main]/Cluster::Mysql/Exec[wait-for-sync]/returns (notice): Warning: Using a password on the command line interface can be insecure.
2016-11-22 14:59:55 +0000 /Stage[main]/Cluster::Mysql/Exec[wait-for-sync]/returns (notice): ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/run/
mysqld/mysqld.sock' (2)
2016-11-22 14:59:55 +0000 /Stage[main]/Cluster::Mysql/Exec[wait-for-sync] (err): Failed to call refresh: mysql -uclustercheck -p1QF1WvJx64XlpUxGGpiAKDHm -Nbe "show status li
ke 'wsrep_local_state_comment'" | grep -q -e Synced && sleep 10 returned 1 instead of one of [0]
2016-11-22 14:59:55 +0000 /Stage[main]/Cluster::Mysql/Exec[wait-for-sync] (err): mysql -uclustercheck -p1QF1WvJx64XlpUxGGpiAKDHm -Nbe "show status like 'wsrep_local_state_co
mment'" | grep -q -e Synced && sleep 10 returned 1 instead of one of [0]

Based on mysqld.log, Galera failed to recover position on start:

<29>Nov 22 14:54:53 node-5 mysqld_safe: Starting mysqld daemon with databases from /var/lib/mysql
<29>Nov 22 14:54:53 node-5 mysqld_safe: WSREP: Running position recovery with --log_error='/var/lib/mysql/wsrep_recovery.6x7LKf' --pid-file='/var/lib/mysql/node-5.test.domai
n.local-recover.pid'
<27>Nov 22 14:54:53 node-5 mysqld: 2016-11-22 14:54:53 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server o
ption (see documentation for more details).
<27>Nov 22 14:54:53 node-5 mysqld: 2016-11-22 14:54:53 0 [Note] /usr/sbin/mysqld (mysqld 5.6.33-0~u14.04+mos3) starting as process 19196 ...
<27>Nov 22 14:54:53 node-5 mysqld_safe: WSREP: Failed to recover position: 2016-11-22 14:54:53 19196 [Warning] Using unique option prefix myisam_recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead. 2016-11-22 14:54:53 19196 [Note] Plugin 'FEDERATED' is disabled. 2016-11-22 14:54:53 7efe88400780 InnoDB: Warning: Using innodb_locks_unsafe_for_binlog is DEPRECATED. This option may be removed in future releases. Please use READ COMMITTED transaction isolation level instead, see http://dev.mysql.com/doc/refman/5.6/en/set-transaction.html. 2016-11-22 14:54:53 19196 [Note] InnoDB: Using atomics to ref count buffer pool pages 2016-11-22 14:54:53 19196 [Note] InnoDB: The InnoDB memory heap is disabled 2016-11-22 14:54:53 19196 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2016-11-22 14:54:53 19196 [Note] InnoDB: Memory barrier is not used 2016-11-22 14:54:53 19196 [Note] InnoDB: Compressed tables use zlib 1.2.8 2016-11-22 14:54:53 19196 [Note] InnoDB: Using Linux native AIO 2016-11-22 14:54:53 19196 [Note] InnoDB: Using CPU crc32 instructions 2016-11-22 14:54:53 19196 [Note] InnoDB: Initializing buffer pool, size = 601.0M 2016-11-22 14:54:53 19196 [Note] InnoDB: Completed initialization of buffer pool 2016-11-22 14:54:53 19196 [ERROR] InnoDB: Only one log file found. 2016-11-22 14:54:53 19196 [ERROR] Plugin 'InnoDB' init function returned error. 2016-11-22 14:54:53 19196 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed. 2016-11-22 14:54:53 19196 [ERROR] Unknown/unsupported storage engine: innodb 2016-11-22 14:54:53 19196 [ERROR] Aborting 2016-11-22 14:54:53 19196 [Note] Binlog end 2016-11-22 14:54:53 19196 [Note] Shutting down plugin 'partition' 2016-11-22 14:54:53 19196 [Note] Shutting down plugin 'BLACKHOLE' 2016-11-22 14:54:53 19196 [Note] Shutting down plugin 'ARCHIVE' 2016-11-22 14:54:53 19196 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA' 2016-11-22 14:54:53 19196 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'

[Sergii Golovatiuk (sgolovatiuk)]

The node was not able to synchronize during timeout amount of time. According to atop, there was a huge load on environment at that time.