Bug 1854637 - bifrost fails when running ironic-dbsync create_schema
Summary: bifrost fails when running ironic-dbsync create_schema
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: mariadb
Version: 32
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: Michal Schorm
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2020-07-07 19:45 UTC by Iury Gregory Melo Ferreira
Modified: 2020-09-11 03:48 UTC (History)
13 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2020-09-11 03:48:07 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description Iury Gregory Melo Ferreira 2020-07-07 19:45:35 UTC
1. Please describe the problem:

While deploying bifrost in a fresh F32 env, the installation fails when trying to create the DB schema http://paste.openstack.org/show/795623/ with version
mysql  Ver 15.1 Distrib 10.4.13-MariaDB, for Linux (x86_64)

2. Specify used package versions
# dnf list installed | grep -i -e maria -e mysql -e galera

mysql  Ver 15.1 Distrib 10.4.13-MariaDB, for Linux (x86_64) 

[root@]# dnf list installed | grep -i -e maria -e mysql -e galera
mariadb.x86_64                                    3:10.4.13-2.fc32                 @updates                 
mariadb-backup.x86_64                             3:10.4.13-2.fc32                 @updates                 
mariadb-common.x86_64                             3:10.4.13-2.fc32                 @updates                 
mariadb-connector-c.x86_64                        3.1.8-1.fc32                     @updates                 
mariadb-connector-c-config.noarch                 3.1.8-1.fc32                     @updates                 
mariadb-cracklib-password-check.x86_64            3:10.4.13-2.fc32                 @updates                 
mariadb-errmsg.x86_64                             3:10.4.13-2.fc32                 @updates                 
mariadb-gssapi-server.x86_64                      3:10.4.13-2.fc32                 @updates                 
mariadb-server.x86_64                             3:10.4.13-2.fc32                 @updates                 
mariadb-server-utils.x86_64                       3:10.4.13-2.fc32                 @updates                 
mysql-selinux.noarch                              1.0.0-9.fc32                     @beaker-Fedora-Everything
perl-DBD-MySQL.x86_64                             4.050-6.fc32                     @beaker-Fedora-Everything
python3-PyMySQL.noarch                            0.9.3-2.fc32                     @beaker-Fedora-Everything


3. Does a systemd journal say anything about the issue?

Interesting stacktrace: http://paste.openstack.org/show/795634/ 

# journalctl -xe -u mariadb -u mysqld - output below

-- The unit mariadb.service completed and consumed the indicated resources.
-- The unit mariadb.service completed and consumed the indicated resources.
-- The unit mariadb.service completed and consumed the indicated resources.
Jul 07 15:04:49 shiftstack-nuc07.tpb.lab.eng.brq.redhat.com systemd[1]: mariadb.service: Scheduled restart job, restart counter is at 1.
-- Subject: Automatic restarting of a unit has been scheduled
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Automatic restarting of the unit mariadb.service has been scheduled, as the result for
-- the configured Restart= setting for the unit.
Jul 07 15:04:49 shiftstack-nuc07.tpb.lab.eng.brq.redhat.com systemd[1]: Stopped MariaDB 10.4 database server.
-- Subject: A stop job for unit mariadb.service has finished
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- A stop job for unit mariadb.service has finished.
-- 
-- The job identifier is 2624 and the job result is done.
Jul 07 15:04:49 shiftstack-nuc07.tpb.lab.eng.brq.redhat.com systemd[1]: mariadb.service: Consumed 4.503s CPU time.
-- Subject: Resources consumed by unit runtime
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- The unit mariadb.service completed and consumed the indicated resources.
Jul 07 15:04:49 shiftstack-nuc07.tpb.lab.eng.brq.redhat.com systemd[1]: Starting MariaDB 10.4 database server...
-- Subject: A start job for unit mariadb.service has begun execution
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- A start job for unit mariadb.service has begun execution.
-- 
-- The job identifier is 2624.
Jul 07 15:04:49 shiftstack-nuc07.tpb.lab.eng.brq.redhat.com mysql-check-socket[26801]: Socket file /var/lib/mysql/mysql.sock exists.
Jul 07 15:04:49 shiftstack-nuc07.tpb.lab.eng.brq.redhat.com mysql-check-socket[26801]: No process is using /var/lib/mysql/mysql.sock, which means it is a garbage, so it will be removed automatically.
Jul 07 15:04:49 shiftstack-nuc07.tpb.lab.eng.brq.redhat.com mysql-prepare-db-dir[26827]: Database MariaDB is probably initialized in /var/lib/mysql already, nothing is done.
Jul 07 15:04:49 shiftstack-nuc07.tpb.lab.eng.brq.redhat.com mysql-prepare-db-dir[26827]: If this is not the case, make sure the /var/lib/mysql is empty before running mysql-prepare-db-dir.
Jul 07 15:04:49 shiftstack-nuc07.tpb.lab.eng.brq.redhat.com mysqld[26862]: 2020-07-07 15:04:49 0 [Note] /usr/libexec/mysqld (mysqld 10.4.13-MariaDB) starting as process 26862 ...
Jul 07 15:04:50 shiftstack-nuc07.tpb.lab.eng.brq.redhat.com systemd[1]: Started MariaDB 10.4 database server.
-- Subject: A start job for unit mariadb.service has finished successfully
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- A start job for unit mariadb.service has finished successfully.
-- 
-- The job identifier is 2624.


4. Please check and attach the MariaDB or MySQL server log?  ("/var/log/mariadb/mariadb.log" or "/var/log/mysql/mysqld.log")

ironic-dbsync.log - http://paste.openstack.org/show/795626/
mariadb.log - http://paste.openstack.org/show/795627/

5. Please check and paste your configuration here; remove sensitive information.
# /usr/libexec/mysqld --print-defaults

/usr/libexec/mysqld would have been started with the following arguments:
--datadir=/var/lib/mysql --socket=/var/lib/mysql/mysql.sock --log-error=/var/log/mariadb/mariadb.log --pid-file=/run/mariadb/mariadb.pid

5. Can you reproduce this issue? If so, please provide the steps to reproduce the issue below:

In a fresh enviroment with Fedora32;
1- dnf install git
2- dnf install @virtualization
3- systemctl start libvirtd
4- git clone https://opendev.org/openstack/bifrost.git
5- cd bifrost/
6- ./bifrost-cli install

Comment 1 Lukas Javorsky 2020-07-08 09:41:15 UTC
I can see that this error occurs since version update from mariadb-10.3.22 to mariadb-10.4.13 (It passes on Fedora 31)

There were some changes in behavior, which should be properly documented, which may cause the error:
https://mariadb.com/kb/en/upgrading-from-mariadb-103-to-mariadb-104/  

Please look at them, if you find something that may affect the bifrost tool.

If not, I think the right thing here is to pass this error directly to the upstream's jira because, it
looks like something deeper than maintaining error and they will have better insight then we do.

Comment 2 Riccardo Pittau 2020-07-08 16:21:24 UTC
Hi,

This seems to pass on F32 with mariadb 10.4.12, so the issue is between micro versions .12 and .13

Downgrading the packages before running the bifrost installer works as intended.

$ cat /etc/fedora-release 
Fedora release 32 (Thirty Two)

$ rpm -qa | grep -i mariadb
mariadb-connector-c-3.1.8-1.fc32.x86_64
mariadb-server-utils-10.4.12-3.fc32.x86_64
mariadb-backup-10.4.12-3.fc32.x86_64
mariadb-connector-c-config-3.1.8-1.fc32.noarch
mariadb-cracklib-password-check-10.4.12-3.fc32.x86_64
mariadb-10.4.12-3.fc32.x86_64
mariadb-common-10.4.12-3.fc32.x86_64
mariadb-gssapi-server-10.4.12-3.fc32.x86_64
mariadb-errmsg-10.4.12-3.fc32.x86_64
mariadb-server-10.4.12-3.fc32.x86_64

Comment 3 Lukas Javorsky 2020-07-09 10:08:31 UTC
I've just tried to downgrade it to 10.4.12-3 but it fails too.
The failure is different tho.

The error message is here (formatting is really ugly, but I just copy pasted it): http://paste.openstack.org/show/795693/

Comment 4 Lukas Javorsky 2020-07-09 10:13:34 UTC
This is ironic-dbsync.log from previous comment: http://paste.openstack.org/show/795694/

Comment 5 Iury Gregory Melo Ferreira 2020-07-13 12:22:53 UTC
Hi Lukas, I will try locally using version 10.4.12 to see how it goes for me.

Comment 6 Lukas Javorsky 2020-07-16 09:29:53 UTC
Hi Iury,

Any update?

Comment 7 Iury Gregory Melo Ferreira 2020-07-16 10:32:38 UTC
Hi Lukas,

I asked Jacob to do the test since I got busy with other things, he will report shortly the test using 10.4.12-3.

Thanks!

Comment 8 Jacob Anders 2020-07-16 10:42:12 UTC
Hi Lukas,

I've been helping Iury out with this so let me provide an update on his behalf.

First, I reproduced the issue:

http://paste.openstack.org/show/795991/

Then I dropped the ironic and inspector DBs, downgraded MariaDB packages to the following versions:

http://paste.openstack.org/show/795988/

and re-ran bifrost install. It passed the DB tasks without issues.

Downgrading packages to 10.4.12-3.fc32 seems to fix the issue for me.

Please let us know if we can assist any further.

Thanks, cheers,
Jacob

Comment 9 Lukas Javorsky 2020-07-16 11:01:46 UTC
Okay I see it, this bug has occurred since rebase from mariadb-10.4.12-3 to  mariadb-10.4.13-2

I will create jira issue and communicate it with upstream, if they have some clue what could cause the problem.

Thanks for helping.

Comment 10 Lukas Javorsky 2020-07-16 11:34:08 UTC
Jira issue is created: https://jira.mariadb.org/browse/MDEV-23193

You can watch it and maybe add some additional info to it

Comment 11 Lukas Javorsky 2020-08-05 07:29:21 UTC
According to this comment https://jira.mariadb.org/browse/MDEV-23193?focusedCommentId=161972&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-161972 ,
the issue should be fixed in upcoming version (10.4.14).

After the release and our rebase, I will give an update if it's fixing the issue

Comment 12 Michal Schorm 2020-09-07 00:45:58 UTC
The 10.4.14 updates are now in Fedora testing repository.
Please try them and let us know, it they fix the issue for you.

https://bodhi.fedoraproject.org/updates/?search=mariadb-10.4.14-2

Comment 13 Jacob Anders 2020-09-11 01:37:56 UTC
Hi Lukas and Michal,

I am happy to confirm that with the current FC32 version of MariaDB I was able to install bifrost without issues:

(bifrost) [stack@fedoravm bifrost]$ export OS_CLOUD=bifrost
(bifrost) [stack@fedoravm bifrost]$ ./bifrost-cli install --testenv
Using release master detected from the checkout

PLAY [Install Ironic on the target host.] ****************************************************************************************************************************************************************************************************

TASK [Gathering Facts] ***********************************************************************************************************************************************************************************************************************
ok: [127.0.0.1]

TASK [bifrost-prep-for-install : ensure installation root folder exists] *********************************************************************************************************************************************************************
[WARNING]: The value 0 (type int) in a string field was converted to '0' (type string). If this does not look like what you expect, quote the entire value to ensure it does not change.
ok: [127.0.0.1]
(...)
TASK [bifrost-create-dib-image : Restore proper context on created data for http_boot] *******************************************************************************************************************************************************
skipping: [127.0.0.1]

PLAY RECAP ***********************************************************************************************************************************************************************************************************************************
127.0.0.1                  : ok=134  changed=90   unreachable=0    failed=0    skipped=257  rescued=0    ignored=0   

Ironic is installed and running, try it yourself:
  $ source /opt/stack/bifrost/bin/activate
  $ export OS_CLOUD=bifrost
  $ baremetal driver list
See documentation for next steps
(bifrost) [stack@fedoravm bifrost]$ echo $?
0
(bifrost) [stack@fedoravm bifrost]$ 


[stack@fedoravm ~]$ sudo rpm -qa | grep maria
mariadb-connector-c-3.1.9-5.fc32.x86_64
mariadb-server-utils-10.4.14-2.fc32.x86_64
mariadb-connector-c-config-3.1.9-5.fc32.noarch
mariadb-cracklib-password-check-10.4.14-2.fc32.x86_64
mariadb-backup-10.4.14-2.fc32.x86_64
mariadb-server-10.4.14-2.fc32.x86_64
mariadb-errmsg-10.4.14-2.fc32.x86_64
mariadb-common-10.4.14-2.fc32.x86_64
mariadb-gssapi-server-10.4.14-2.fc32.x86_64
mariadb-10.4.14-2.fc32.x86_64
[stack@fedoravm ~]$ sudo su -
Last login: Fri Sep 11 01:27:21 UTC 2020 on tty1
[root@fedoravm ~]# mysql
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 19
Server version: 10.4.14-MariaDB MariaDB Server

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [(none)]> show databases
    -> ;
+--------------------+
| Database           |
+--------------------+
| information_schema |
| inspector          |
| ironic             |
| mysql              |
| performance_schema |
+--------------------+
5 rows in set (0.001 sec)

MariaDB [(none)]> 

As far as I am concerned this is fixed & fix confirmed. This BZ can be closed.

Thank you for your assistance.

Comment 14 Michal Schorm 2020-09-11 03:48:07 UTC
Thank you for confirming it works for you well.

If the issue would appear again, feel free to open a new BZ and link this one to it.


Note You need to log in before you can comment on or make changes to this bug.