Bug 1769291

Summary: Mysql Upgrade tasks failing due to podman log-driver not found
Product: Red Hat OpenStack Reporter: Jose Luis Franco <jfrancoa>
Component: openstack-tripleo-heat-templatesAssignee: Cédric Jeanneret <cjeanner>
Status: CLOSED ERRATA QA Contact: Sasha Smolyak <ssmolyak>
Severity: urgent Docs Contact:
Priority: urgent    
Version: 15.0 (Stein)CC: cjeanner, jstransk, mburns
Target Milestone: ---Keywords: Triaged, ZStream
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: openstack-tripleo-heat-templates-10.6.2-0.20191120120453.4d99d7b.el8ost Doc Type: No Doc Update
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-03-05 12:00:28 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1727807    

Description Jose Luis Franco 2019-11-06 10:36:49 UTC
Description of problem:

When upgrading from OSP14 to OSP15, the upgrades run step is running in the following task:

TASK [Bind mounts for temporary container] *************************************                                                                                            
Wednesday 06 November 2019  05:23:55 -0500 (0:00:00.087)       0:02:33.612 ****                                                                                             
ok: [lab-controller01] => {"ansible_facts": {"mysql_upgrade_db_bind_mounts": ["/etc/hosts:/etc/hosts:ro", "/etc/localtime:/etc/localtime:ro", "/etc/pki/ca-trust/extracted:/e
tc/pki/ca-trust/extracted:ro", "/etc/pki/ca-trust/source/anchors:/etc/pki/ca-trust/source/anchors:ro", "/etc/pki/tls/certs/ca-bundle.crt:/etc/pki/tls/certs/ca-bundle.crt:ro"
, "/etc/pki/tls/certs/ca-bundle.trust.crt:/etc/pki/tls/certs/ca-bundle.trust.crt:ro", "/etc/pki/tls/cert.pem:/etc/pki/tls/cert.pem:ro", "/dev/log:/dev/log", "/etc/ssh/ssh_kn
own_hosts:/etc/ssh/ssh_known_hosts:ro", "/etc/puppet:/etc/puppet:ro", "/var/lib/kolla/config_files/mysql.json:/var/lib/kolla/config_files/config.json", "/var/lib/config-data
/puppet-generated/mysql/:/var/lib/kolla/config_files/src:ro", "/var/lib/mysql:/var/lib/mysql"]}, "changed": false}                                                          

TASK [Make sure Mysql upgrade temporary directory exists] **********************                                                                                            
Wednesday 06 November 2019  05:23:55 -0500 (0:00:00.084)       0:02:33.696 ****                                                                                             
ok: [lab-controller01] => {"changed": false, "gid": 0, "group": "root", "mode": "0700", "owner": "root", "path": "/tmp/mariadb-upgrade", "secontext": "unconfined_u:object_r:
user_tmp_t:s0", "size": 6, "state": "directory", "uid": 0}                                                                                                                  
                                                                                                                                                                            
TASK [Upgrade Mysql database from a temporary container] ***********************
Wednesday 06 November 2019  05:23:56 -0500 (0:00:00.331)       0:02:34.028 ****                                                                                             
fatal: [lab-controller01]: FAILED! => {"changed": true, "cmd": "podman run --rm --log-driver=syslog -u root --net=host -e \"KOLLA_CONFIG_STRATEGY=COPY_ALWAYS\" -v /etc/hosts:/etc/hosts:ro -v /etc/localtime:/etc/localtime:ro -v /etc/pki/ca-trust/extracted:/etc/pki/ca-trust/extracted:ro -v /etc/pki/ca-trust/source/anchors:/etc/pki/ca-trust/source
/anchors:ro -v /etc/pki/tls/certs/ca-bundle.crt:/etc/pki/tls/certs/ca-bundle.crt:ro -v /etc/pki/tls/certs/ca-bundle.trust.crt:/etc/pki/tls/certs/ca-bundle.trust.crt:ro -v /e
tc/pki/tls/cert.pem:/etc/pki/tls/cert.pem:ro -v /dev/log:/dev/log -v /etc/ssh/ssh_known_hosts:/etc/ssh/ssh_known_hosts:ro -v /etc/puppet:/etc/puppet:ro -v /var/lib/kolla/config_files/mysql.json:/var/lib/kolla/config_files/config.json -v /var/lib/config-data/puppet-generated/mysql/:/var/lib/kolla/config_files/src:ro -v /var/lib/mysql:/var/lib/my
sql -v /tmp/mariadb-upgrade:/var/log/mariadb:rw \"172.16.0.1:8787/rhosp15-rhel8/openstack-mariadb:pcmklatest\" /bin/bash -ecx \"kolla_set_configs; if mysqladmin ping --silen
t; then exit 0; fi; chown -R mysql:mysql /var/lib/mysql; chown -R mysql:mysql /var/log/mariadb; mysqld_safe --user=mysql --wsrep-provider=none --skip-networking --wsrep-on=o
ff & timeout 60 sh -c 'while ! mysqladmin ping --silent; do sleep 1; done'; mysql_upgrade; mysqladmin shutdown\"", "delta": "0:00:00.094721", "end": "2019-11-06 10:23:56.225916", "msg": "non-zero return code", "rc": 125, "start": "2019-11-06 10:23:56.131195", "stderr": "Error: error running container create option: invalid log driver: invalid a
rgument", "stderr_lines": ["Error: error running container create option: invalid log driver: invalid argument"], "stdout": "", "stdout_lines": []}                         

NO MORE HOSTS LEFT *************************************************************

PLAY RECAP *********************************************************************
lab-controller01           : ok=140  changed=44   unreachable=0    failed=1    skipped=256  rescued=0    ignored=1                                                          

Wednesday 06 November 2019  05:23:56 -0500 (0:00:00.385)       0:02:34.414 ****
===============================================================================

Ansible failed, check log at /var/lib/mistral/292a8b96-1d22-4919-a071-50bf4e6eed0a/ansible.log.  


The problem seems to be caused by a dreprecation of the syslog log-driver in paunch, task: https://github.com/openstack/tripleo-heat-templates/blob/9fbb355289d59a394e410aee0fe7ce675e130127/deployment/database/mysql-pacemaker-puppet.yaml#L587

We need to use k8s-file driver instead and set also the log file to be used.

Version-Release number of selected component (if applicable):


How reproducible:


Steps to Reproduce:
1. Deploy OSP 14 
2. Upgrade UC to OSP15
3. Run first Overcloud Controller upgrade steps


Actual results:


Expected results:


Additional info:

Comment 4 Jose Luis Franco 2019-11-19 15:28:23 UTC
When trying to validate the BZ it did fail again with :

TASK [Upgrade Mysql database from a temporary container] ***********************
Tuesday 19 November 2019  09:26:01 -0500 (0:00:00.308)       0:09:07.672 ****** 
fatal: [controller-0]: FAILED! => {"changed": true, "cmd": "podman run --rm --log-driver=k8s-file --log-opt path=LOG_DIR/db-upgrade.log -u root --net=host -e \"KOLLA_CONFIG_
STRATEGY=COPY_ALWAYS\" -v /etc/hosts:/etc/hosts:ro -v /etc/localtime:/etc/localtime:ro -v /etc/pki/ca-trust/extracted:/etc/pki/ca-trust/extracted:ro -v /etc/pki/ca-trust/sou
rce/anchors:/etc/pki/ca-trust/source/anchors:ro -v /etc/pki/tls/certs/ca-bundle.crt:/etc/pki/tls/certs/ca-bundle.crt:ro -v /etc/pki/tls/certs/ca-bundle.trust.crt:/etc/pki/tl
s/certs/ca-bundle.trust.crt:ro -v /etc/pki/tls/cert.pem:/etc/pki/tls/cert.pem:ro -v /dev/log:/dev/log -v /etc/ssh/ssh_known_hosts:/etc/ssh/ssh_known_hosts:ro -v /etc/puppet:
/etc/puppet:ro -v /var/lib/kolla/config_files/mysql.json:/var/lib/kolla/config_files/config.json:rw,z -v /var/lib/config-data/puppet-generated/mysql/:/var/lib/kolla/config_f
iles/src:ro,z -v /var/lib/mysql:/var/lib/mysql:rw,z -v /tmp/mariadb-upgrade:/var/log/mariadb:rw,z \"192.168.24.1:8787/rh-osbs/rhosp15-openstack-mariadb:pcmklatest\" /bin/bas
h -ecx \"kolla_set_configs; if mysqladmin ping --silent; then exit 0; fi; chown -R mysql:mysql /var/lib/mysql; chown -R mysql:mysql /var/log/mariadb; mysqld_safe --user=mysq
l --wsrep-provider=none --skip-networking --wsrep-on=off & timeout 60 sh -c 'while ! mysqladmin ping --silent; do sleep 1; done'; mysql_upgrade; mysqladmin shutdown\"", "del
ta": "0:00:01.113447", "end": "2019-11-19 14:26:01.884729", "msg": "non-zero return code", "rc": 127, "start": "2019-11-19 14:26:00.771282", "stderr": "[conmon:e]: Failed to
 open log file No such file or directory\nError: write child: broken pipe", "stderr_lines": ["[conmon:e]: Failed to open log file No such file or directory", "Error: write c
hild: broken pipe"], "stdout": "", "stdout_lines": []}

NO MORE HOSTS LEFT *************************************************************

PLAY RECAP *********************************************************************
controller-0               : ok=146  changed=59   unreachable=0    failed=1    skipped=245  rescued=0    ignored=1   

Tuesday 19 November 2019  09:26:02 -0500 (0:00:01.365)       0:09:09.038 ****** 
=============================================================================== 


It seems there is a typo in the fix and the LOG_DIR parameter didn't get replaced: https://review.opendev.org/#/c/693773/2/deployment/database/mysql-pacemaker-puppet.yaml@598 as the parameter was named LOGDIR.

Doing some manual testing in the env passing the right log directory made the command succeed:

[root@controller-0 heat-admin]# podman run --rm --log-driver=k8s-file --log-opt path=/var/log/containers/mysql/db-upgrade.log -u root --net=host -e "KOLLA_CONFIG_STRATEGY=CO
PY_ALWAYS" -v /etc/hosts:/etc/hosts:ro -v /etc/localtime:/etc/localtime:ro -v /etc/pki/ca-trust/extracted:/etc/pki/ca-trust/extracted:ro -v /etc/pki/ca-trust/source/anchors:
/etc/pki/ca-trust/source/anchors:ro -v /etc/pki/tls/certs/ca-bundle.crt:/etc/pki/tls/certs/ca-bundle.crt:ro -v /etc/pki/tls/certs/ca-bundle.trust.crt:/etc/pki/tls/certs/ca-b
undle.trust.crt:ro -v /etc/pki/tls/cert.pem:/etc/pki/tls/cert.pem:ro -v /dev/log:/dev/log -v /etc/ssh/ssh_known_hosts:/etc/ssh/ssh_known_hosts:ro -v /etc/puppet:/etc/puppet:
ro -v /var/lib/kolla/config_files/mysql.json:/var/lib/kolla/config_files/config.json:rw,z -v /var/lib/config-data/puppet-generated/mysql/:/var/lib/kolla/config_files/src:ro,
z -v /var/lib/mysql:/var/lib/mysql:rw,z -v /tmp/mariadb-upgrade:/var/log/mariadb:rw,z "192.168.24.1:8787/rh-osbs/rhosp15-openstack-mariadb:pcmklatest" /bin/bash -ecx "kolla_
set_configs; if mysqladmin ping --silent; then exit 0; fi; chown -R mysql:mysql /var/lib/mysql; chown -R mysql:mysql /var/log/mariadb; mysqld_safe --user=mysql --wsrep-provi
der=none --skip-networking --wsrep-on=off & timeout 60 sh -c 'while ! mysqladmin ping --silent; do sleep 1; done'; mysql_upgrade; mysqladmin shutdown"                       
+ kolla_set_configs
INFO:__main__:Loading config file at /var/lib/kolla/config_files/config.json
INFO:__main__:Validating config file
INFO:__main__:Kolla config strategy set to: COPY_ALWAYS
INFO:__main__:Copying service configuration files
INFO:__main__:Copying /dev/null to /etc/libqb/force-filesystem-sockets
INFO:__main__:Setting permission for /etc/libqb/force-filesystem-sockets
INFO:__main__:Deleting /etc/my.cnf.d/galera.cnf
INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/my.cnf.d/galera.cnf to /etc/my.cnf.d/galera.cnf
INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/sysconfig/clustercheck to /etc/sysconfig/clustercheck
INFO:__main__:Copying /var/lib/kolla/config_files/src/root/.my.cnf to /root/.my.cnf
INFO:__main__:Writing out command to execute
+ mysqladmin ping --silent
+ chown -R mysql:mysql /var/lib/mysql
+ chown -R mysql:mysql /var/log/mariadb
+ timeout 60 sh -c 'while ! mysqladmin ping --silent; do sleep 1; done'
+ mysqld_safe --user=mysql --wsrep-provider=none --skip-networking --wsrep-on=off
191119 15:22:30 mysqld_safe Logging to '/var/log/mariadb/mariadb.log'.

I'll submit the fix for it and link it to the bugzilla.

Comment 6 Jose Luis Franco 2019-11-26 17:20:35 UTC
*** Bug 1776761 has been marked as a duplicate of this bug. ***

Comment 7 Michele Baldessari 2019-12-02 15:21:29 UTC
*** Bug 1769441 has been marked as a duplicate of this bug. ***

Comment 9 Jose Luis Franco 2019-12-13 09:51:03 UTC
Working with THT package:
(undercloud) [stack@undercloud-0 ~]$ rpm -qa | grep tripleo-heat-templates
openstack-tripleo-heat-templates-10.6.2-0.20191202200455.41d9f8a.el8ost.noarch


2019-12-13 03:58:59,191 p=8777 u=mistral |  TASK [Upgrade Mysql database from a temporary container] ***********************
2019-12-13 03:58:59,195 p=8777 u=mistral |  changed: [controller-0] => {"changed": true, "cmd": "podman run --rm --log-driver=k8s-file --log-opt path=/var/log/containers/mysql/db-upgrade.log -u root --net=host -e \"KOLLA_CONFIG_STRATEGY=COPY_ALWAYS\" -v /etc/hosts:/etc/hosts:ro -v /etc/localtime:/etc/localtime:ro -v /etc/pki/ca-trust/extracted:/etc/pki/ca-trust/extracted:ro -v /etc/pki/ca-trust/source/anchors:/etc/pki/ca-trust/source/anchors:ro -v /etc/pki/tls/certs/ca-bundle.crt:/etc/pki/tls/certs/ca-bundle.crt:ro -v /etc/pki/tls/certs/ca-bundle.trust.crt:/etc/pki/tls/certs/ca-bundle.trust.crt:ro -v /etc/pki/tls/cert.pem:/etc/pki/tls/cert.pem:ro -v /dev/log:/dev/log -v /etc/ssh/ssh_known_hosts:/etc/ssh/ssh_known_hosts:ro -v /etc/puppet:/etc/puppet:ro -v /var/lib/kolla/config_files/mysql.json:/var/lib/kolla/config_files/config.json:rw,z -v /var/lib/config-data/puppet-generated/mysql/:/var/lib/kolla/config_files/src:ro,z -v /var/lib/mysql:/var/lib/mysql:rw,z -v /tmp/mariadb-upgrade:/var/log/mariadb:rw,z \"192.168.24.1:8787/rh-osbs/rhosp15-openstack-mariadb:pcmklatest\" /bin/bash -ecx \"kolla_set_configs; if mysqladmin ping --silent; then exit 0; fi; chown -R mysql:mysql /var/lib/mysql; chown -R mysql:mysql /var/log/mariadb; mysqld_safe --user=mysql --wsrep-provider=none --skip-networking --wsrep-on=off & timeout 60 sh -c 'while ! mysqladmin ping --silent; do sleep 1; done'; mysql_upgrade; mysqladmin shutdown\"", "delta": "0:00:04.517007", "end": "2019-12-13 08:58:59.373238", "rc": 0, "start": "2019-12-13 08:58:54.856231", "stderr": "+ kolla_set_configs\nINFO:__main__:Loading config file at /var/lib/kolla/config_files/config.json\nINFO:__main__:Validating config file\nINFO:__main__:Kolla config strategy set to: COPY_ALWAYS\nINFO:__main__:Copying service configuration files\nINFO:__main__:Copying /dev/null to /etc/libqb/force-filesystem-sockets\nINFO:__main__:Setting permission for /etc/libqb/force-filesystem-sockets\nINFO:__main__:Deleting /etc/my.cnf.d/galera.cnf\nINFO:__main__:Copying /var/lib/kolla/config_files/src/etc/my.cnf.d/galera.cnf to /etc/my.cnf.d/galera.cnf\nINFO:__main__:Copying /var/lib/kolla/config_files/src/etc/sysconfig/clustercheck to /etc/sysconfig/clustercheck\nINFO:__main__:Copying /var/lib/kolla/config_files/src/root/.my.cnf to /root/.my.cnf\nINFO:__main__:Writing out command to execute\n+ mysqladmin ping --silent\n+ chown -R mysql:mysql /var/lib/mysql\n+ chown -R mysql:mysql /var/log/mariadb\n+ timeout 60 sh -c 'while ! mysqladmin ping --silent; do sleep 1; done'\n+ mysqld_safe --user=mysql --wsrep-provider=none --skip-networking --wsrep-on=off\n/usr/bin/mysqld_safe: line 702: ulimit: -1: invalid option\nulimit: usage: ulimit [-SHabcdefiklmnpqrstuvxPT] [limit]\n+ mysql_upgrade\n+ mysqladmin shutdown", "stderr_lines": ["+ kolla_set_configs", "INFO:__main__:Loading config file at /var/lib/kolla/config_files/config.json", "INFO:__main__:Validating config file", "INFO:__main__:Kolla config strategy set to: COPY_ALWAYS", "INFO:__main__:Copying service configuration files", "INFO:__main__:Copying /dev/null to /etc/libqb/force-filesystem-sockets", "INFO:__main__:Setting permission for /etc/libqb/force-filesystem-sockets", "INFO:__main__:Deleting /etc/my.cnf.d/galera.cnf", "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/my.cnf.d/galera.cnf to /etc/my.cnf.d/galera.cnf", "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/sysconfig/clustercheck to /etc/sysconfig/clustercheck", "INFO:__main__:Copying /var/lib/kolla/config_files/src/root/.my.cnf to /root/.my.cnf", "INFO:__main__:Writing out command to execute", "+ mysqladmin ping --silent", "+ chown -R mysql:mysql /var/lib/mysql", "+ chown -R mysql:mysql /var/log/mariadb", "+ timeout 60 sh -c 'while ! mysqladmin ping --silent; do sleep 1; done'", "+ mysqld_safe --user=mysql --wsrep-provider=none --skip-networking --wsrep-on=off", "/usr/bin/mysqld_safe: line 702: ulimit: -1: invalid option", "ulimit: usage: ulimit [-SHabcdefiklmnpqrstuvxPT] [limit]", "+ mysql_upgrade", "+ mysqladmin shutdown"], "stdout": "191213 08:58:55 mysqld_safe Logging to '/var/log/mariadb/mariadb.log'.\n191213 08:58:55 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql\nmysqld is alive\nPhase 1/7: Checking and upgrading mysql database\nProcessing databases\nmysql\nmysql.column_stats                                 OK\nmysql.columns_priv                                 OK\nmysql.db                                           OK\nmysql.event                                        OK\nmysql.func                                         OK\nmysql.gtid_slave_pos                               OK\nmysql.help_category                                OK\nmysql.help_keyword                                 OK\nmysql.help_relation                                OK\nmysql.help_topic                                   OK\nmysql.host                                         OK\nmysql.index_stats                                  OK\nmysql.innodb_index_stats                           OK\nmysql.innodb_table_stats                           OK\nmysql.plugin                                       OK\nmysql.proc                                         OK\nmysql.procs_priv                                   OK\nmysql.proxies_priv                                 OK\nmysql.roles_mapping                                OK\nmysql.servers                                      OK\nmysql.table_stats                                  OK\nmysql.tables_priv                                  OK\nmysql.time_zone                                    OK\nmysql.time_zone_leap_second                        OK\nmysql.time_zone_name                               OK\nmysql.time_zone_transition                         OK\nmysql.time_zone_transition_type                    OK\nmysql.user                                         OK\nPhase 2/7: Installing used storage engines... Skipped\nPhase 3/7: Fixing views\nPhase 4/7: Running 'mysql_fix_privilege_tables'\nPhase 5/7: Fixing table and database names\nPhase 6/7: Checking and upgrading tables\nProcessing databases\naodh\naodh.alarm\nWarning  : Row size too large (> 8126). Changing some columns to TEXT or BLOB or using ROW_FORMAT=DYNAMIC or ROW_FORMAT=COMPRESSED may help. In current row format, BLOB prefix of 768 bytes is stored inline.\nstatus   : OK\naodh.alarm_history                                 OK\naodh.alembic_version                               OK\ncinder\ncinder.attachment_specs                            OK\ncinder.backup_metadata                             OK\ncinder.backups\nWarning  : Row size too large (> 8126). Changing some columns to TEXT or BLOB or using ROW_FORMAT=DYNAMIC or ROW_FORMAT=COMPRESSED may help. In current row format, BLOB prefi

Comment 11 errata-xmlrpc 2020-03-05 12:00:28 UTC
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/RHBA-2020:0643