Description of problem: OSP12->13 undercloud upgrade gets stuck because mariadb.service is stuck in deactivating during yum cleanup Version-Release number of selected component (if applicable): [root@undercloud-0 ~]# rpm -qa | grep mariadb mariadb-10.1.20-2.el7ost.x86_64 mariadb-5.5.56-2.el7.x86_64 mariadb-common-10.1.20-2.el7ost.x86_64 mariadb-libs-10.1.20-2.el7ost.x86_64 mariadb-libs-5.5.56-2.el7.x86_64 mariadb-config-10.1.20-2.el7ost.x86_64 mariadb-errmsg-10.1.20-2.el7ost.x86_64 mariadb-server-5.5.56-2.el7.x86_64 mariadb-server-10.1.20-2.el7ost.x86_64 instack-undercloud-8.2.1-0.20180214022816.8a7609e.el7ost.noarch instack-8.1.1-0.20180210031553.1fe782a.el7ost.noarch How reproducible: 100% Steps to Reproduce: 1. Deploy OSP12 undercloud 2.sudo yum -y update python-tripleoclient 3. openstack undercloud upgrade Actual results: During yum cleanup the upgrade process gets stuck because mariadb service is stuck in deactivating state. Expected results: Undercloud upgrade process doesn't get stuck. Additional info: [root@undercloud-0 ~]# systemctl status mariadb ● mariadb.service - MariaDB 10.1 database server Loaded: loaded (/usr/lib/systemd/system/mariadb.service; enabled; vendor preset: disabled) Drop-In: /etc/systemd/system/mariadb.service.d └─limits.conf Active: deactivating (stop-sigterm) since Sun 2018-02-25 22:31:33 EST; 2min 3s ago Main PID: 1730 (mysqld_safe) CGroup: /system.slice/mariadb.service ├─1730 /bin/sh /usr/bin/mysqld_safe --basedir=/usr └─3260 /usr/libexec/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --log-error=/var/log/mariadb/mariadb.log --open-files-limit=-1 --pid-file=/var/run/mariadb/mariadb.pid --socket=/var/lib... Feb 25 22:22:53 undercloud-0.redhat.local systemd[1]: Starting MariaDB database server... Feb 25 22:22:54 undercloud-0.redhat.local mariadb-prepare-db-dir[1484]: Database MariaDB is probably initialized in /var/lib/mysql already, nothing is done. Feb 25 22:22:54 undercloud-0.redhat.local mariadb-prepare-db-dir[1484]: If this is not the case, make sure the /var/lib/mysql is empty before running mariadb-prepare-db-dir. Feb 25 22:23:04 undercloud-0.redhat.local mysqld_safe[1730]: 180225 22:23:04 mysqld_safe Logging to '/var/log/mariadb/mariadb.log'. Feb 25 22:23:05 undercloud-0.redhat.local mysqld_safe[1730]: 180225 22:23:05 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql Feb 25 22:23:07 undercloud-0.redhat.local systemd[1]: Started MariaDB database server. Feb 25 22:29:04 undercloud-0.redhat.local systemd[1]: Current command vanished from the unit file, execution of the command list won't be resumed. Feb 25 22:31:33 undercloud-0.redhat.local systemd[1]: Stopping MariaDB 10.1 database server... [root@undercloud-0 ~]# tail /var/log/mariadb/mariadb.log 180225 22:23:07 [ERROR] mysqld: Table './mysql/proxies_priv' is marked as crashed and should be repaired 180225 22:23:07 [Warning] Checking table: './mysql/proxies_priv' 180225 22:23:07 [ERROR] mysql.proxies_priv: 1 client is using or hasn't closed the table properly 180225 22:23:07 [Note] Event Scheduler: Loaded 0 events 180225 22:23:07 [Note] /usr/libexec/mysqld: ready for connections. Version: '5.5.56-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server 180225 22:23:07 [Note] Hostname 'undercloud-0.redhat.local' does not resolve to '192.168.24.1'. 180225 22:23:07 [Note] Hostname 'undercloud-0.redhat.local' has the following IP addresses: 180225 22:23:07 [Note] - 127.0.0.1
Hitting that as well: [root@undercloud-0 mariadb]# systemctl status mariadb ● mariadb.service - MariaDB 10.1 database server Loaded: loaded (/usr/lib/systemd/system/mariadb.service; enabled; vendor preset: disabled) Drop-In: /etc/systemd/system/mariadb.service.d └─limits.conf Active: failed (Result: exit-code) since vie 2018-03-02 19:49:15 EST; 7h ago Process: 26712 ExecStartPre=/usr/libexec/mysql-check-socket (code=exited, status=1/FAILURE) Main PID: 365 CGroup: /system.slice/mariadb.service ├─365 /bin/sh /usr/bin/mysqld_safe --basedir=/usr └─883 /usr/libexec/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --log-error=/var/log/mariadb/mariadb.log --open-files-limit=-1 --pid-file=/var/run/mariadb/mariadb.pid --socket=/var/lib/... mar 02 19:49:14 undercloud-0.redhat.local systemd[1]: Starting MariaDB 10.1 database server... mar 02 19:49:14 undercloud-0.redhat.local mysql-check-socket[26712]: Socket file /var/lib/mysql/mysql.sock exists. mar 02 19:49:15 undercloud-0.redhat.local mysql-check-socket[26712]: Is another MySQL daemon already running with the same unix socket? mar 02 19:49:15 undercloud-0.redhat.local mysql-check-socket[26712]: Please, stop the process 883 or remove /var/lib/mysql/mysql.sock manually to start the service. mar 02 19:49:15 undercloud-0.redhat.local systemd[1]: mariadb.service: control process exited, code=exited status=1 mar 02 19:49:15 undercloud-0.redhat.local systemd[1]: Failed to start MariaDB 10.1 database server. mar 02 19:49:15 undercloud-0.redhat.local systemd[1]: Unit mariadb.service entered failed state. mar 02 19:49:15 undercloud-0.redhat.local systemd[1]: mariadb.service failed. [root@undercloud-0 mariadb]# journalctl -xe | grep mariad -- Subject: Unit mariadb.service has begun shutting down -- Unit mariadb.service has begun shutting down. mar 02 19:37:51 undercloud-0.redhat.local systemd[1]: mariadb.service stop-sigterm timed out. Skipping SIGKILL. mar 02 19:38:52 undercloud-0.redhat.local systemd[1]: mariadb.service: control process exited, code=exited status=3 mar 02 19:42:51 undercloud-0.redhat.local systemd[1]: mariadb.service stop-post timed out. Terminating. mar 02 19:47:51 undercloud-0.redhat.local systemd[1]: mariadb.service stop-final-sigterm timed out. Skipping SIGKILL. Entering failed mode. mar 02 19:47:51 undercloud-0.redhat.local systemd[1]: Unit mariadb.service entered failed state. mar 02 19:47:51 undercloud-0.redhat.local systemd[1]: mariadb.service failed. -- Subject: Unit mariadb.service has begun start-up -- Unit mariadb.service has begun starting up. mar 02 19:47:51 undercloud-0.redhat.local systemd[1]: mariadb.service: control process exited, code=exited status=1 -- Subject: Unit mariadb.service has failed -- Unit mariadb.service has failed. mar 02 19:47:51 undercloud-0.redhat.local systemd[1]: Unit mariadb.service entered failed state. mar 02 19:47:51 undercloud-0.redhat.local systemd[1]: mariadb.service failed. -- Subject: Unit mariadb.service has begun start-up -- Unit mariadb.service has begun starting up. mar 02 19:49:15 undercloud-0.redhat.local systemd[1]: mariadb.service: control process exited, code=exited status=1 -- Subject: Unit mariadb.service has failed -- Unit mariadb.service has failed. mar 02 19:49:15 undercloud-0.redhat.local systemd[1]: Unit mariadb.service entered failed state. mar 02 19:49:15 undercloud-0.redhat.local systemd[1]: mariadb.service failed. [root@undercloud-0 mariadb]# cat mariadb.log 180302 17:40:40 [Warning] Failed to setup SSL 180302 17:40:40 [Warning] SSL error: SSL_CTX_set_default_verify_paths failed 180302 17:40:40 [Warning] Failed to setup SSL 180302 17:40:40 [Warning] SSL error: SSL_CTX_set_default_verify_paths failed 180302 17:40:41 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql 180302 17:40:41 [Warning] option 'open_files_limit': unsigned value 18446744073709551615 adjusted to 4294967295 180302 17:40:41 [Warning] option 'open_files_limit': unsigned value 18446744073709551615 adjusted to 4294967295 180302 17:40:41 [Note] /usr/libexec/mysqld (mysqld 5.5.56-MariaDB) starting as process 9119 ... 180302 17:40:41 InnoDB: The InnoDB memory heap is disabled 180302 17:40:41 InnoDB: Mutexes and rw_locks use GCC atomic builtins 180302 17:40:41 InnoDB: Compressed tables use zlib 1.2.7 180302 17:40:41 InnoDB: Using Linux native AIO 180302 17:40:41 InnoDB: Initializing buffer pool, size = 128.0M 180302 17:40:41 InnoDB: Completed initialization of buffer pool InnoDB: The first specified data file ./ibdata1 did not exist: InnoDB: a new database to be created! 180302 17:40:41 InnoDB: Setting file ./ibdata1 size to 10 MB InnoDB: Database physically writes the file full: wait... 180302 17:40:41 InnoDB: Log file ./ib_logfile0 did not exist: new to be created InnoDB: Setting log file ./ib_logfile0 size to 5 MB InnoDB: Database physically writes the file full: wait... 180302 17:40:41 InnoDB: Log file ./ib_logfile1 did not exist: new to be created InnoDB: Setting log file ./ib_logfile1 size to 5 MB InnoDB: Database physically writes the file full: wait... InnoDB: Doublewrite buffer not found: creating new InnoDB: Doublewrite buffer created InnoDB: 127 rollback segment(s) active. InnoDB: Creating foreign key constraint system tables InnoDB: Foreign key constraint system tables created 180302 17:40:41 InnoDB: Waiting for the background threads to start 180302 17:40:42 Percona XtraDB (http://www.percona.com) 5.5.52-MariaDB-38.3 started; log sequence number 0 180302 17:40:42 [Note] Plugin 'FEEDBACK' is disabled. 180302 17:40:42 [Warning] Failed to setup SSL 180302 17:40:42 [Warning] SSL error: SSL_CTX_set_default_verify_paths failed 180302 17:40:42 [Note] Server socket created on IP: '192.0.2.1'. 180302 17:40:42 [Note] Event Scheduler: Loaded 0 events 180302 17:40:42 [Note] /usr/libexec/mysqld: ready for connections. Version: '5.5.56-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server 180302 17:41:18 [Note] Hostname 'undercloud-0.redhat.local' does not resolve to '192.0.2.1'. 180302 17:41:18 [Note] Hostname 'undercloud-0.redhat.local' has the following IP addresses: 180302 17:41:18 [Note] - 127.0.0.1 180302 19:03:03 [Note] /usr/libexec/mysqld: Normal shutdown 180302 19:03:03 [Note] Event Scheduler: Purging the queue. 0 events 180302 19:03:03 InnoDB: Starting shutdown... 180302 19:03:06 InnoDB: Shutdown completed; log sequence number 111885898 180302 19:03:06 [Note] /usr/libexec/mysqld: Shutdown complete 180302 19:03:06 mysqld_safe mysqld from pid file /var/run/mariadb/mariadb.pid ended 180302 19:03:06 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql 180302 19:03:06 [Warning] option 'open_files_limit': unsigned value 18446744073709551615 adjusted to 4294967295 180302 19:03:06 [Warning] option 'open_files_limit': unsigned value 18446744073709551615 adjusted to 4294967295 180302 19:03:06 [Note] /usr/libexec/mysqld (mysqld 5.5.56-MariaDB) starting as process 883 ... 180302 19:03:06 InnoDB: The InnoDB memory heap is disabled 180302 19:03:06 InnoDB: Mutexes and rw_locks use GCC atomic builtins 180302 19:03:06 InnoDB: Compressed tables use zlib 1.2.7 180302 19:03:06 InnoDB: Using Linux native AIO 180302 19:03:06 InnoDB: Initializing buffer pool, size = 128.0M 180302 19:03:06 InnoDB: Completed initialization of buffer pool 180302 19:03:06 InnoDB: highest supported file format is Barracuda. 180302 19:03:07 InnoDB: Waiting for the background threads to start 180302 19:03:08 Percona XtraDB (http://www.percona.com) 5.5.52-MariaDB-38.3 started; log sequence number 111885898 180302 19:03:08 [Note] Plugin 'FEEDBACK' is disabled. 180302 19:03:08 [Note] Server socket created on IP: '192.0.2.1'. 180302 19:03:08 [Note] Event Scheduler: Loaded 0 events 180302 19:03:08 [Note] /usr/libexec/mysqld: ready for connections. Version: '5.5.56-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server 180302 19:05:25 [Note] Hostname 'undercloud-0.redhat.local' does not resolve to '192.0.2.1'. 180302 19:05:25 [Note] Hostname 'undercloud-0.redhat.local' has the following IP addresses: 180302 19:05:25 [Note] - 127.0.0.1
@Maria PM ack ?
patch landed in queens
Verified with instack-undercloud-8.4.0-2.el7ost.noarch Excerpt from uc's update log: ... 2018-04-04 04:13:06,356 INFO: Current mariadb version is: 5.5.56 2018-04-04 04:13:06,760 INFO: Available mariadb version is: 10.1.20 2018-04-04 04:13:06,761 INFO: Major versions differ (5.5 vs 10.1), database needs an upgrade 2018-04-04 04:13:06,761 INFO: Stopping OpenStack database before upgrade 2018-04-04 04:13:08,215 INFO: Database stopped successfully 2018-04-04 04:13:08,215 INFO: Updating full system ... 2018-04-04 04:19:47,606 INFO: Start OpenStack database after upgrade 2018-04-04 04:19:48,354 INFO: Database started successfully 2018-04-04 04:19:48,355 INFO: Run online upgrade of the database 2018-04-04 04:19:48,420 INFO: Phase 1/6: Checking and upgrading mysql database 2018-04-04 04:19:48,435 INFO: Processing databases ... 2018-04-04 04:19:49,784 INFO: Phase 6/6: Running 'FLUSH PRIVILEGES' 2018-04-04 04:19:49,784 INFO: OK 2018-04-04 04:19:49,790 INFO: Database upgraded successfully 2018-04-04 04:19:49,791 INFO: Restart OpenStack database for upgrade to take effect 2018-04-04 04:19:52,533 INFO: Database restarted successfully
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHEA-2018:2086