centos-binary-swift-object failed with cannot load glue library: libibverbs.so.1: cannot open shared object file: No such file or directory"

[Arx Cruz]

http://logs.rdoproject.org/openstack-periodic/git.openstack.org/openstack-infra/tripleo-ci/master/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-rocky/4cee386/logs/undercloud/home/zuul/overcloud_deploy.log.txt.gz

2019-01-14 13:31:27 | "stdout: \u001b[0;32mInfo: Loading facts\u001b[0m",
2019-01-14 13:31:27 | "\u001b[0;32mInfo: Loading facts\u001b[0m",
2019-01-14 13:31:27 | "\u001b[mNotice: hiera(): Cannot load backend module_data: cannot load such file -- hiera/backend/module_data_backend\u001b[0m",
2019-01-14 13:31:27 | "\u001b[mNotice: Compiled catalog for overcloud-controller-0.localdomain in environment production in 1.70 seconds\u001b[0m",
2019-01-14 13:31:27 | "\u001b[0;32mInfo: Applying configuration version '1547472613'\u001b[0m",
2019-01-14 13:31:27 | "\u001b[mNotice: /Stage[main]/Neutron::Agents::Ml2::Ovs/Neutron::Plugins::Ovs::Bridge[datacentre:br-ex]/Vs_bridge[br-ex]/external_ids: external_ids changed 'PMD: net_mlx5: cannot load glue library: libibverbs.so.1: cannot open shared object file: No such file or directory,PMD: net_mlx5: cannot initialize PMD due to missing run-time dependency on rdma-core libraries (libibverbs, libmlx5),PMD: net_mlx4: cannot load glue library: libibverbs.so.1: cannot open shared object file: No such file or directory,PMD: net_mlx4: cannot initialize PMD due to missing run-time dependency on rdma-core libraries (libibverbs, libmlx4)' to 'bridge-id=br-ex'\u001b[0m",
2019-01-14 13:31:27 | "\u001b[0;32mInfo: Neutron::Plugins::Ovs::Bridge[datacentre:br-ex]: Unscheduling all events on Neutron::Plugins::Ovs::Bridge[datacentre:br-ex]\u001b[0m",
2019-01-14 13:31:27 | "\u001b[0;32mInfo: Creating state file /var/lib/puppet/state/state.yaml\u001b[0m",
2019-01-14 13:31:27 | "\u001b[mNotice: Applied catalog in 0.26 seconds\u001b[0m",
2019-01-14 13:31:27 | "stderr: PMD: net_mlx5: cannot load glue library: libibverbs.so.1: cannot open shared object file: No such file or directory",
2019-01-14 13:31:27 | "PMD: net_mlx5: cannot initialize PMD due to missing run-time dependency on rdma-core libraries (libibverbs, libmlx5)",
2019-01-14 13:31:27 | "PMD: net_mlx4: cannot load glue library: libibverbs.so.1: cannot open shared object file: No such file or directory",
2019-01-14 13:31:27 | "PMD: net_mlx4: cannot initialize PMD due to missing run-time dependency on rdma-core libraries (libibverbs, libmlx4)",
2019-01-14 13:31:27 | "PMD: net_mlx5: cannot load glue library: libibverbs.so.1: cannot open shared object file: No such file or directory",
2019-01-14 13:31:27 | "\u001b[1;33mWarning: Undefined variable 'deploy_config_name'; ",
2019-01-14 13:31:27 | " (file & line not available)\u001b[0m",
2019-01-14 13:31:27 | "\u001b[1;33mWarning: This method is deprecated, please use the stdlib validate_legacy function,",
2019-01-14 13:31:27 | " with Stdlib::Compat::Array. There is further documentation for validate_legacy function in the README. at [\"/etc/puppet/modules/neutron/manifests/agents/ml2/ovs.pp\", 214]:[\"unknown\", 1]",
2019-01-14 13:31:27 | " (at /etc/puppet/modules/stdlib/lib/puppet/functions/deprecation.rb:28:in `deprecation')\u001b[0m",
2019-01-14 13:31:27 | "stderr: Deprecated: Option \"logdir\" from group \"DEFAULT\" is deprecated. Use option \"log-dir\" from group \"DEFAULT\".",
2019-01-14 13:31:27 | "stdout: Upgraded database to: rocky_expand02, current revision(s): rocky_expand02",
2019-01-14 13:31:27 | "Database migration is up to date. No migration needed.",
2019-01-14 13:31:27 | "Upgraded database to: rocky_contract02, current revision(s): rocky_contract02",
2019-01-14 13:31:27 | "Database is synced successfully.",
2019-01-14 13:31:27 | "stderr: + sudo -E kolla_set_configs",
2019-01-14 13:31:27 | "INFO:__main__:Loading config file at /var/lib/kolla/config_files/config.json",
2019-01-14 13:31:27 | "INFO:__main__:Validating config file",
2019-01-14 13:31:27 | "INFO:__main__:Kolla config strategy set to: COPY_ALWAYS",
2019-01-14 13:31:27 | "INFO:__main__:Copying service configuration files",
2019-01-14 13:31:27 | "INFO:__main__:Deleting /etc/glance/glance-api.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/glance/glance-api.conf to /etc/glance/glance-api.conf",
2019-01-14 13:31:27 | "INFO:__main__:Deleting /etc/glance/glance-cache.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/glance/glance-cache.conf to /etc/glance/glance-cache.conf",
2019-01-14 13:31:27 | "INFO:__main__:Deleting /etc/glance/glance-image-import.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/glance/glance-image-import.conf to /etc/glance/glance-image-import.conf",
2019-01-14 13:31:27 | "INFO:__main__:Deleting /etc/glance/glance-swift.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/glance/glance-swift.conf to /etc/glance/glance-swift.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/my.cnf.d/tripleo.cnf to /etc/my.cnf.d/tripleo.cnf",
2019-01-14 13:31:27 | "INFO:__main__:Writing out command to execute",
2019-01-14 13:31:27 | "INFO:__main__:Setting permission for /var/lib/glance",
2019-01-14 13:31:27 | "++ cat /run_command",
2019-01-14 13:31:27 | "+ CMD='/usr/bin/glance-api --config-file /usr/share/glance/glance-api-dist.conf --config-file /etc/glance/glance-api.conf --config-file /etc/glance/glance-image-import.conf'",
2019-01-14 13:31:27 | "+ ARGS=",
2019-01-14 13:31:27 | "+ [[ ! -n '' ]]",
2019-01-14 13:31:27 | "+ . kolla_extend_start",
2019-01-14 13:31:27 | "++ [[ ! -d /var/log/kolla/glance ]]",
2019-01-14 13:31:27 | "++ mkdir -p /var/log/kolla/glance",
2019-01-14 13:31:27 | "+++ stat -c %a /var/log/kolla/glance",
2019-01-14 13:31:27 | "++ [[ 2755 != \\7\\5\\5 ]]",
2019-01-14 13:31:27 | "++ chmod 755 /var/log/kolla/glance",
2019-01-14 13:31:27 | "++ . /usr/local/bin/kolla_glance_extend_start",
2019-01-14 13:31:27 | "+++ [[ -n 0 ]]",
2019-01-14 13:31:27 | "+++ glance-manage db_sync",
2019-01-14 13:31:27 | "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py:1352: OsloDBDeprecationWarning: EngineFacade is deprecated; please use oslo_db.sqlalchemy.enginefacade",
2019-01-14 13:31:27 | " expire_on_commit=expire_on_commit, _conf=conf)",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Context impl MySQLImpl.",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Will assume non-transactional DDL.",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade -> liberty, liberty initial",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade liberty -> mitaka01, add index on created_at and updated_at columns of 'images' table",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade mitaka01 -> mitaka02, update metadef os_nova_server",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade mitaka02 -> ocata_expand01, add visibility to images",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade ocata_expand01 -> pike_expand01, empty expand for symmetry with pike_contract01",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade pike_expand01 -> queens_expand01",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade queens_expand01 -> rocky_expand01, add os_hidden column to images table",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade rocky_expand01 -> rocky_expand02, add os_hash_algo and os_hash_value columns to images table",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade mitaka02 -> ocata_contract01, remove is_public from images",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade ocata_contract01 -> pike_contract01, drop glare artifacts tables",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade pike_contract01 -> queens_contract01",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade queens_contract01 -> rocky_contract01",
2019-01-14 13:31:27 | "INFO [alembic.runtime.migration] Running upgrade rocky_contract01 -> rocky_contract02",
2019-01-14 13:31:27 | "+++ glance-manage db_load_metadefs",
2019-01-14 13:31:27 | "+++ exit 0",
2019-01-14 13:31:27 | "stdout: '/swift_ringbuilder/etc/swift/account.ring.gz' -> '/etc/swift/account.ring.gz'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/container.ring.gz' -> '/etc/swift/container.ring.gz'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/object.ring.gz' -> '/etc/swift/object.ring.gz'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/account.builder' -> '/etc/swift/account.builder'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/container.builder' -> '/etc/swift/container.builder'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/object.builder' -> '/etc/swift/object.builder'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/backups' -> '/etc/swift/backups'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/backups/1547471768.account.builder' -> '/etc/swift/backups/1547471768.account.builder'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/backups/1547471768.object.builder' -> '/etc/swift/backups/1547471768.object.builder'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/backups/1547471769.container.builder' -> '/etc/swift/backups/1547471769.container.builder'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/backups/1547471772.object.builder' -> '/etc/swift/backups/1547471772.object.builder'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/backups/1547471772.object.ring.gz' -> '/etc/swift/backups/1547471772.object.ring.gz'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/backups/1547471773.account.builder' -> '/etc/swift/backups/1547471773.account.builder'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/backups/1547471773.account.ring.gz' -> '/etc/swift/backups/1547471773.account.ring.gz'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/backups/1547471773.container.builder' -> '/etc/swift/backups/1547471773.container.builder'",
2019-01-14 13:31:27 | "'/swift_ringbuilder/etc/swift/backups/1547471773.container.ring.gz' -> '/etc/swift/backups/1547471773.container.ring.gz'",
2019-01-14 13:31:27 | "INFO:__main__:Creating directory /etc/keystone/fernet-keys",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/keystone/fernet-keys/0 to /etc/keystone/fernet-keys/0",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/keystone/fernet-keys/1 to /etc/keystone/fernet-keys/1",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.d/10-keystone_wsgi_admin.conf to /etc/httpd/conf.d/10-keystone_wsgi_admin.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.d/10-keystone_wsgi_main.conf to /etc/httpd/conf.d/10-keystone_wsgi_main.conf",
2019-01-14 13:31:27 | "INFO:__main__:Deleting /etc/httpd/conf.d/ssl.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.d/ssl.conf to /etc/httpd/conf.d/ssl.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/access_compat.load to /etc/httpd/conf.modules.d/access_compat.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/actions.load to /etc/httpd/conf.modules.d/actions.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/alias.conf to /etc/httpd/conf.modules.d/alias.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/alias.load to /etc/httpd/conf.modules.d/alias.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/auth_basic.load to /etc/httpd/conf.modules.d/auth_basic.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/auth_digest.load to /etc/httpd/conf.modules.d/auth_digest.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/authn_anon.load to /etc/httpd/conf.modules.d/authn_anon.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/authn_core.load to /etc/httpd/conf.modules.d/authn_core.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/authn_dbm.load to /etc/httpd/conf.modules.d/authn_dbm.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/authn_file.load to /etc/httpd/conf.modules.d/authn_file.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/authz_core.load to /etc/httpd/conf.modules.d/authz_core.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/authz_dbm.load to /etc/httpd/conf.modules.d/authz_dbm.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/authz_groupfile.load to /etc/httpd/conf.modules.d/authz_groupfile.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/authz_host.load to /etc/httpd/conf.modules.d/authz_host.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/authz_owner.load to /etc/httpd/conf.modules.d/authz_owner.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/authz_user.load to /etc/httpd/conf.modules.d/authz_user.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/autoindex.conf to /etc/httpd/conf.modules.d/autoindex.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/autoindex.load to /etc/httpd/conf.modules.d/autoindex.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/cache.load to /etc/httpd/conf.modules.d/cache.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/cgi.load to /etc/httpd/conf.modules.d/cgi.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/dav.load to /etc/httpd/conf.modules.d/dav.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/dav_fs.conf to /etc/httpd/conf.modules.d/dav_fs.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/dav_fs.load to /etc/httpd/conf.modules.d/dav_fs.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/deflate.conf to /etc/httpd/conf.modules.d/deflate.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/deflate.load to /etc/httpd/conf.modules.d/deflate.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/dir.conf to /etc/httpd/conf.modules.d/dir.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/dir.load to /etc/httpd/conf.modules.d/dir.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/env.load to /etc/httpd/conf.modules.d/env.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/expires.load to /etc/httpd/conf.modules.d/expires.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/ext_filter.load to /etc/httpd/conf.modules.d/ext_filter.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/filter.load to /etc/httpd/conf.modules.d/filter.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/include.load to /etc/httpd/conf.modules.d/include.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/log_config.load to /etc/httpd/conf.modules.d/log_config.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/logio.load to /etc/httpd/conf.modules.d/logio.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/mime.conf to /etc/httpd/conf.modules.d/mime.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/mime.load to /etc/httpd/conf.modules.d/mime.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/mime_magic.conf to /etc/httpd/conf.modules.d/mime_magic.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/mime_magic.load to /etc/httpd/conf.modules.d/mime_magic.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/negotiation.conf to /etc/httpd/conf.modules.d/negotiation.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/negotiation.load to /etc/httpd/conf.modules.d/negotiation.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/prefork.conf to /etc/httpd/conf.modules.d/prefork.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/prefork.load to /etc/httpd/conf.modules.d/prefork.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/rewrite.load to /etc/httpd/conf.modules.d/rewrite.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/setenvif.conf to /etc/httpd/conf.modules.d/setenvif.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/setenvif.load to /etc/httpd/conf.modules.d/setenvif.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/socache_shmcb.load to /etc/httpd/conf.modules.d/socache_shmcb.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/speling.load to /etc/httpd/conf.modules.d/speling.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/ssl.load to /etc/httpd/conf.modules.d/ssl.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/status.conf to /etc/httpd/conf.modules.d/status.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/status.load to /etc/httpd/conf.modules.d/status.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/substitute.load to /etc/httpd/conf.modules.d/substitute.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/suexec.load to /etc/httpd/conf.modules.d/suexec.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/systemd.load to /etc/httpd/conf.modules.d/systemd.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/unixd.load to /etc/httpd/conf.modules.d/unixd.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/usertrack.load to /etc/httpd/conf.modules.d/usertrack.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/version.load to /etc/httpd/conf.modules.d/version.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/vhost_alias.load to /etc/httpd/conf.modules.d/vhost_alias.load",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/wsgi.conf to /etc/httpd/conf.modules.d/wsgi.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf.modules.d/wsgi.load to /etc/httpd/conf.modules.d/wsgi.load",
2019-01-14 13:31:27 | "INFO:__main__:Deleting /etc/httpd/conf/httpd.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf/httpd.conf to /etc/httpd/conf/httpd.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/httpd/conf/ports.conf to /etc/httpd/conf/ports.conf",
2019-01-14 13:31:27 | "INFO:__main__:Creating directory /etc/keystone/credential-keys",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/keystone/credential-keys/0 to /etc/keystone/credential-keys/0",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/keystone/credential-keys/1 to /etc/keystone/credential-keys/1",
2019-01-14 13:31:27 | "INFO:__main__:Deleting /etc/keystone/fernet-keys/0",
2019-01-14 13:31:27 | "INFO:__main__:Deleting /etc/keystone/fernet-keys/1",
2019-01-14 13:31:27 | "INFO:__main__:Deleting /etc/keystone/keystone.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/keystone/keystone.conf to /etc/keystone/keystone.conf",
2019-01-14 13:31:27 | "INFO:__main__:Creating directory /etc/systemd/system/httpd.service.d",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/etc/systemd/system/httpd.service.d/httpd.conf to /etc/systemd/system/httpd.service.d/httpd.conf",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/var/spool/cron/keystone to /var/spool/cron/keystone",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/var/www/cgi-bin/keystone/keystone-admin to /var/www/cgi-bin/keystone/keystone-admin",
2019-01-14 13:31:27 | "INFO:__main__:Copying /var/lib/kolla/config_files/src/var/www/cgi-bin/keystone/keystone-public to /var/www/cgi-bin/keystone/keystone-public",
2019-01-14 13:31:27 | "+ CMD='/usr/sbin/httpd -DFOREGROUND'",
2019-01-14 13:31:27 | "++ [[ centos =~ debian|ubuntu ]]",
2019-01-14 13:31:27 | "++ rm -rf /var/run/httpd/htcacheclean /run/httpd/htcacheclean '/tmp/httpd*'",
2019-01-14 13:31:27 | "++ KEYSTONE_LOG_DIR=/var/log/kolla/keystone",
2019-01-14 13:31:27 | "++ [[ ! -d /var/log/kolla/keystone ]]",
2019-01-14 13:31:27 | "++ mkdir -p /var/log/kolla/keystone",
2019-01-14 13:31:27 | "+++ stat -c %U:%G /var/log/kolla/keystone",
2019-01-14 13:31:27 | "++ [[ root:kolla != \\k\\e\\y\\s\\t\\o\\n\\e\\:\\k\\o\\l\\l\\a ]]",
2019-01-14 13:31:27 | "++ chown keystone:kolla /var/log/kolla/keystone",
2019-01-14 13:31:27 | "++ '[' '!' -f /var/log/kolla/keystone/keystone.log ']'",
2019-01-14 13:31:27 | "++ touch /var/log/kolla/keystone/keystone.log",
2019-01-14 13:31:27 | "+++ stat -c %U:%G /var/log/kolla/keystone/keystone.log",
2019-01-14 13:31:27 | "++ [[ root:kolla != \\k\\e\\y\\s\\t\\o\\n\\e\\:\\k\\e\\y\\s\\t\\o\\n\\e ]]",
2019-01-14 13:31:27 | "++ chown keystone:keystone /var/log/kolla/keystone/keystone.log",
2019-01-14 13:31:27 | "+++ stat -c %a /var/log/kolla/keystone",
2019-01-14 13:31:27 | "++ chmod 755 /var/log/kolla/keystone",
2019-01-14 13:31:27 | "++ EXTRA_KEYSTONE_MANAGE_ARGS=",
2019-01-14 13:31:27 | "++ [[ -n '' ]]",
2019-01-14 13:31:27 | "++ [[ -n 0 ]]",
2019-01-14 13:31:27 | "++ sudo -H -u keystone keystone-manage db_sync",
2019-01-14 13:31:27 | "++ exit 0",
2019-01-14 13:31:27 | "Error running ['docker', 'run', '--name', 'neutron_db_sync', '--label', 'config_id=tripleo_step3', '--label', 'container_name=neutron_db_sync', '--label', 'managed_by=paunch', '--label', 'config_data={\"command\": [\"/usr/bin/bootstrap_host_exec\", \"neutron_api\", \"neutron-db-manage\", \"upgrade\", \"heads\"], \"user\": \"root\", \"volumes\": [\"/etc/hosts:/etc/hosts:ro\", \"/etc/localtime:/etc/localtime:ro\", \"/etc/pki/ca-trust/extracted:/etc/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_known_hosts:/etc/ssh/ssh_known_hosts:ro\", \"/etc/puppet:/etc/puppet:ro\", \"/var/log/containers/neutron:/var/log/neutron\", \"/var/log/containers/httpd/neutron-api:/var/log/httpd\", \"/var/lib/config-data/neutron/etc/my.cnf.d/tripleo.cnf:/etc/my.cnf.d/tripleo.cnf:ro\", \"/var/lib/config-data/neutron/etc/neutron:/etc/neutron:ro\", \"/var/lib/config-data/neutron/usr/share/neutron:/usr/share/neutron:ro\"], \"image\": \"192.168.24.1:8787/tripleorocky/centos-binary-neutron-server:tripleo-ci-testing-updated-20190114112536\", \"detach\": false, \"net\": \"host\", \"privileged\": false}', '--net=host', '--privileged=false', '--user=root', '--volume=/etc/hosts:/etc/hosts:ro', '--volume=/etc/localtime:/etc/localtime:ro', '--volume=/etc/pki/ca-trust/extracted:/etc/pki/ca-trust/extracted:ro', '--volume=/etc/pki/ca-trust/source/anchors:/etc/pki/ca-trust/source/anchors:ro', '--volume=/etc/pki/tls/certs/ca-bundle.crt:/etc/pki/tls/certs/ca-bundle.crt:ro', '--volume=/etc/pki/tls/certs/ca-bundle.trust.crt:/etc/pki/tls/certs/ca-bundle.trust.crt:ro', '--volume=/etc/pki/tls/cert.pem:/etc/pki/tls/cert.pem:ro', '--volume=/dev/log:/dev/log', '--volume=/etc/ssh/ssh_known_hosts:/etc/ssh/ssh_known_hosts:ro', '--volume=/etc/puppet:/etc/puppet:ro', '--volume=/var/log/containers/neutron:/var/log/neutron', '--volume=/var/log/containers/httpd/neutron-api:/var/log/httpd', '--volume=/var/lib/config-data/neutron/etc/my.cnf.d/tripleo.cnf:/etc/my.cnf.d/tripleo.cnf:ro', '--volume=/var/lib/config-data/neutron/etc/neutron:/etc/neutron:ro', '--volume=/var/lib/config-data/neutron/usr/share/neutron:/usr/share/neutron:ro', '192.168.24.1:8787/tripleorocky/centos-binary-neutron-server:tripleo-ci-testing-updated-20190114112536', '/usr/bin/bootstrap_host_exec', 'neutron_api', 'neutron-db-manage', 'upgrade', 'heads']. [1]",
2019-01-14 13:31:27 | "stderr: Traceback (most recent call last):",
2019-01-14 13:31:27 | " File \"/usr/bin/neutron-db-manage\", line 10, in <module>",
2019-01-14 13:31:27 | " sys.exit(main())",
2019-01-14 13:31:27 | " File \"/usr/lib/python2.7/site-packages/neutron/db/migration/cli.py\", line 653, in main",
2019-01-14 13:31:27 | " return_val |= bool(CONF.command.func(config, CONF.command.name))",
2019-01-14 13:31:27 | " File \"/usr/lib/python2.7/site-packages/neutron/db/migration/cli.py\", line 172, in do_upgrade",
2019-01-14 13:31:27 | " run_sanity_checks(config, revision)",
2019-01-14 13:31:27 | " File \"/usr/lib/python2.7/site-packages/neutron/db/migration/cli.py\", line 637, in run_sanity_checks",
2019-01-14 13:31:27 | " script_dir.run_env()",
2019-01-14 13:31:27 | " File \"/usr/lib/python2.7/site-packages/alembic/script/base.py\", line 425, in run_env",
2019-01-14 13:31:27 | " util.load_python_file(self.dir, 'env.py')",
2019-01-14 13:31:27 | " File \"/usr/lib/python2.7/site-packages/alembic/util/pyfiles.py\", line 81, in load_python_file",
2019-01-14 13:31:27 | " module = load_module_py(module_id, path)",
2019-01-14 13:31:27 | " File \"/usr/lib/python2.7/site-packages/alembic/util/compat.py\", line 141, in load_module_py",
2019-01-14 13:31:27 | " mod = imp.load_source(module_id, path, fp)",
2019-01-14 13:31:27 | " File \"/usr/lib/python2.7/site-packages/neutron/db/migration/alembic_migrations/env.py\", line 120, in <module>",
2019-01-14 13:31:27 | " run_migrations_online()",
2019-01-14 13:31:27 | " File \"/usr/lib/python2.7/site-packages/neutron/db/migration/alembic_migrations/env.py\", line 106, in run_migrations_online",
2019-01-14 13:31:27 | " with DBConnection(neutron_config.database.connection, connection) as conn:",
2019-01-14 13:31:27 | " File \"/usr/lib/python2.7/site-packages/neutron/db/migration/connection.py\", line 32, in __enter__",
2019-01-14 13:31:27 | " self.engine = session.create_engine(self.connection_url)",
2019-01-14 13:31:27 | " File \"/usr/lib/python2.7/site-packages/debtcollector/renames.py\", line 43, in decorator",
2019-01-14 13:31:27 | " return wrapped(*args, **kwargs)",
2019-01-14 13:31:27 | " File \"/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py\", line 153, in create_engine",
2019-01-14 13:31:27 | " url = sqlalchemy.engine.url.make_url(sql_connection)",
2019-01-14 13:31:27 | " File \"/usr/lib64/python2.7/site-packages/sqlalchemy/engine/url.py\", line 211, in make_url",
2019-01-14 13:31:27 | " return _parse_rfc1738_args(name_or_url)",
2019-01-14 13:31:27 | " File \"/usr/lib64/python2.7/site-packages/sqlalchemy/engine/url.py\", line 270, in _parse_rfc1738_args",
2019-01-14 13:31:27 | " \"Could not parse rfc1738 URL from string '%s'\" % name)",
2019-01-14 13:31:27 | "sqlalchemy.exc.ArgumentError: Could not parse rfc1738 URL from string ''",
2019-01-14 13:31:27 | "stdout: 82c2ab2d1d574e2c50f034abca8aaf0dffe86922d5108b613f924291c4704824",
2019-01-14 13:31:27 | "stdout: af0e41bcf7334909b3c23844d437120303f6b2a52078290b029788e2c2879156",
2019-01-14 13:31:27 | "stdout: (cellv2) Creating default cell_v2 cell",
2019-01-14 13:31:27 | "stdout: 7e82c6f3eec48919fdcc57150f45d0743f54cd898b0eeb33aa6406bca70cf51e",
2019-01-14 13:31:27 | "stdout: 11c54ffcc44ef735a9bc63a7b635f739e736d93bd48d6e5645693ec4c46c3f65",
2019-01-14 13:31:27 | "stderr: /usr/lib/python2.7/site-packages/pymysql/cursors.py:170: Warning: (1831, u'Duplicate index `block_device_mapping_instance_uuid_virtual_name_device_name_idx`. This is deprecated and will be disallowed in a future release.')",
2019-01-14 13:31:27 | " result = self._query(query)",
2019-01-14 13:31:27 | "/usr/lib/python2.7/site-packages/pymysql/cursors.py:170: Warning: (1831, u'Duplicate index `uniq_instances0uuid`. This is deprecated and will be disallowed in a future release.')",
2019-01-14 13:31:27 | "stdout: 1c0208c30c1d8401176355da18545c399892b96c8687d62bffee8c15fb8d5326"
2019-01-14 13:31:27 | ]
2019-01-14 13:31:27 | }

[Arx Cruz (arxcruz)]

Also, on keystone db sync in the same job we are seeing:

 2019-01-14 13:31:27 | "sqlalchemy.exc.ArgumentError: Could not parse rfc1738 URL from string ''",

[Arx Cruz (arxcruz)]

Same error on featureset035:

http://logs.rdoproject.org/openstack-periodic/git.openstack.org/openstack-infra/tripleo-ci/master/periodic-tripleo-ci-centos-7-ovb-3ctlr_1comp-featureset035-rocky/919312d/logs/undercloud/home/zuul/overcloud_deploy.log.txt.gz

[wes hayutin (weshayutin)]

hrm..
https://bugzilla.redhat.com/show_bug.cgi?id=1587899
https://bugzilla.redhat.com/show_bug.cgi?id=1642742

Not directly related but seems to be a mysterious bug.
Arx, we need to know how often this is happening, please a logstash query.

[Bernard Cafarelli (bcafarel)]

Here is the oldest BZ relevant to this topic:
https://bugzilla.redhat.com/show_bug.cgi?id=1619387

tl;dr the libibverbs.so line is a harmless warning printed out in newer ovs when this library is not installed (it is used for mellanox stuff but not needed for vanilla ovs).
On a more detailed note, this caused some issues in neutron where any output on stderr would be recognized as failure (now fixed), and we have work in progress to replace CLI parsing by direct DB queries.

Still though, this is just a harmless warning, and the actual error seems to be farther down when running neutron-db-manage:

2019-01-14 13:31:27 | " \"Could not parse rfc1738 URL from string '%s'\" % name)",
2019-01-14 13:31:27 | "sqlalchemy.exc.ArgumentError: Could not parse rfc1738 URL from string ''",

[yatin (yatinkarel)]

Yes, bcafarel is correct about warning also related BZ:- https://bugzilla.redhat.com/show_bug.cgi?id=1658141 and i think the issue is still valid as per below details.

For the failure in this job:-
Could not parse rfc1738 URL from string '%s'\" % name)", seems the actual error, i can't see 'neutron' config dir at https://logs.rdoproject.org/openstack-periodic/git.openstack.org/openstack-infra/tripleo-ci/master/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-rocky/4cee386/logs/overcloud-controller-0/var/log/config-data/neutron
The above issue is possible when neutron config directory is not present, since it's not happening always may be a race? can someone check what can be the reason for that directory to be not present when docker run neutron_db_sync is executed.