ironic-dbsync failed on CI

[Vasyl Saienko]

2017-03-28 09:40:02.941 | ++ /opt/stack/new/ironic/devstack/lib/ironic:init_ironic:1174 : /usr/local/bin/ironic-dbsync --config-file=/etc/ironic/ironic.conf
2017-03-28 09:40:04.574 | CRITI [ironic] TypeError: unsupported operand type(s) for -: 'int' and 'str'
2017-03-28 09:40:04.574 | Traceback (most recent call last):
2017-03-28 09:40:04.574 | File "/usr/local/bin/ironic-dbsync", line 10, in <module>
2017-03-28 09:40:04.574 | sys.exit(main())
2017-03-28 09:40:04.574 | File "/opt/stack/new/ironic/ironic/cmd/dbsync.py", line 103, in main
2017-03-28 09:40:04.574 | CONF.command.func()
2017-03-28 09:40:04.574 | File "/opt/stack/new/ironic/ironic/cmd/dbsync.py", line 35, in upgrade
2017-03-28 09:40:04.574 | migration.upgrade(CONF.command.revision)
2017-03-28 09:40:04.574 | File "/opt/stack/new/ironic/ironic/db/migration.py", line 36, in upgrade
2017-03-28 09:40:04.574 | return get_backend().upgrade(version)
2017-03-28 09:40:04.574 | File "/opt/stack/new/ironic/ironic/db/sqlalchemy/migration.py", line 56, in upgrade
2017-03-28 09:40:04.574 | alembic.command.upgrade(config, revision or 'head')
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/alembic/command.py", line 254, in upgrade
2017-03-28 09:40:04.574 | script.run_env()
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/alembic/script/base.py", line 416, in run_env
2017-03-28 09:40:04.574 | util.load_python_file(self.dir, 'env.py')
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/alembic/util/pyfiles.py", line 93, in load_python_file
2017-03-28 09:40:04.574 | module = load_module_py(module_id, path)
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/alembic/util/compat.py", line 75, in load_module_py
2017-03-28 09:40:04.574 | mod = imp.load_source(module_id, path, fp)
2017-03-28 09:40:04.574 | File "/opt/stack/new/ironic/ironic/db/sqlalchemy/alembic/env.py", line 61, in <module>
2017-03-28 09:40:04.574 | run_migrations_online()
2017-03-28 09:40:04.574 | File "/opt/stack/new/ironic/ironic/db/sqlalchemy/alembic/env.py", line 53, in run_migrations_online
2017-03-28 09:40:04.574 | engine = enginefacade.get_legacy_facade().get_engine()
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 1117, in get_legacy_facade
2017-03-28 09:40:04.574 | return _context_manager.get_legacy_facade()
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 775, in get_legacy_facade
2017-03-28 09:40:04.574 | return self._factory.get_legacy_facade()
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 338, in get_legacy_facade
2017-03-28 09:40:04.574 | self._start()
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 480, in _start
2017-03-28 09:40:04.574 | engine_args, maker_args)
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 504, in _setup_for_connection
2017-03-28 09:40:04.574 | sql_connection=sql_connection, **engine_kwargs)
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/engines.py", line 134, in create_engine
2017-03-28 09:40:04.574 | engine = sqlalchemy.create_engine(url, **engine_args)
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/__init__.py", line 386, in create_engine
2017-03-28 09:40:04.574 | return strategy.create(*args, **kwargs)
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/strategies.py", line 119, in create
2017-03-28 09:40:04.574 | pool = poolclass(creator, **pool_args)
2017-03-28 09:40:04.574 | File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 1025, in __init__
2017-03-28 09:40:04.574 | self._overflow = 0 - pool_size
2017-03-28 09:40:04.574 | TypeError: unsupported operand type(s) for -: 'int' and 'str'

More logs can be found: http://logs.openstack.org/70/450670/1/check/gate-tempest-dsvm-ironic-ipa-partition-bios-agent_ipmitool-tinyipa-ubuntu-xenial/22a667b/logs/devstacklog.txt.gz

[Julia Kreger (juliaashleykreger)]

This has been observed in bifrost as well in the OPNFV third party CI. It is a configuration default, however it appears that it is not being loaded. OPNFV's solution is to set the configuration parameters, but it seems like we shouldn't have to as they are defaults. Wrong type loading it seems.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/450733

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/450733
Committed: https://git.openstack.org/cgit/openstack/ironic/commit/?id=d31d984871a03c3e7cc4be85a0f2fb12bda5dc7e
Submitter: Jenkins
Branch: master

commit d31d984871a03c3e7cc4be85a0f2fb12bda5dc7e
Author: Vasyl Saienko <email address hidden>
Date: Tue Mar 28 14:42:29 2017 +0300

    Don't pass sqlite_db in db_options.set_defaults()

    The option sqlite_db was deprecated and removed by
    Id269d921e40edf95eb977b011f1753f633b79d18

    As we passed it as positional argument, another max_pool_size
    var was set automatically.
    This patch removes dropped sqlite_db option.

    Change-Id: Icdd89453ec3ebecd8375a5f2efd1a0d4bf6b4064
    Closes-Bug: #1676809

[Yolanda Robla (yolanda.robla)]

It continues failing and i can reproduce it. Error is on:

  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 1025, in __init__
    self._overflow = 0 - pool_size

I debugged, and pool_size is a blank value, that is causing the issue.

[Yolanda Robla (yolanda.robla)]

Failed job: http://logs.openstack.org/70/450970/6/check/gate-bifrost-integration-tinyipa-ubuntu-xenial/993505b/console.html

[Markos Chandras (hwoarang)]

fwiw, the ironic version used in the bifrost jobs has this fix in it but it seems it is not enough

2017-03-29 17:33:19.657426 | INFO:zuul.Cloner:Updating origin remote in repo openstack/ironic to git://git.openstack.org/openstack/ironic
2017-03-29 17:33:21.764070 | INFO:zuul.Cloner:upstream repo has branch master
2017-03-29 17:33:25.519823 | INFO:zuul.Cloner:Falling back to branch master
2017-03-29 17:33:25.552308 | INFO:zuul.Cloner:Prepared openstack/ironic repo with branch master at commit a5c68120d3dbb4b6808ed7b81514092ed79804de

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/ironic-inspector 5.1.0 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/ironic 8.0.0 release.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/ocata
Review: https://review.openstack.org/459455

[Ruby Loo (rloo)]

Looks like this is failing in our grenade jobs gate-grenade-dsvm-ironic-ubuntu-xenial & gate-grenade-dsvm-ironic-multinode-multitenant-ubuntu-xenial-nv

First patch that it fails is from Apr 22: https://review.openstack.org/#/c/350831/40

What changed? We thought upper constraints were used for ocata, which is oslo.db===4.17.0 (https://github.com/openstack/requirements/blob/stable/ocata/upper-constraints.txt#L239).

2017-04-24 13:10:49.165 | + /opt/stack/new/ironic/devstack/upgrade/upgrade.sh:main:71 : /usr/local/bin/ironic-dbsync --config-file=/etc/ironic/ironic.conf
2017-04-24 13:10:51.600 | CRITI [ironic] TypeError: unsupported operand type(s) for -: 'int' and 'str'
2017-04-24 13:10:51.600 | Traceback (most recent call last):
2017-04-24 13:10:51.600 | File "/usr/local/bin/ironic-dbsync", line 10, in <module>
2017-04-24 13:10:51.600 | sys.exit(main())
2017-04-24 13:10:51.600 | File "/opt/stack/old/ironic/ironic/cmd/dbsync.py", line 103, in main
2017-04-24 13:10:51.600 | CONF.command.func()
2017-04-24 13:10:51.601 | File "/opt/stack/old/ironic/ironic/cmd/dbsync.py", line 35, in upgrade
2017-04-24 13:10:51.601 | migration.upgrade(CONF.command.revision)
2017-04-24 13:10:51.601 | File "/opt/stack/old/ironic/ironic/db/migration.py", line 36, in upgrade
2017-04-24 13:10:51.601 | return get_backend().upgrade(version)
2017-04-24 13:10:51.601 | File "/opt/stack/old/ironic/ironic/db/sqlalchemy/migration.py", line 56, in upgrade
2017-04-24 13:10:51.601 | alembic.command.upgrade(config, revision or 'head')
2017-04-24 13:10:51.601 | File "/usr/local/lib/python2.7/dist-packages/alembic/command.py", line 254, in upgrade
2017-04-24 13:10:51.601 | script.run_env()
2017-04-24 13:10:51.601 | File "/usr/local/lib/python2.7/dist-packages/alembic/script/base.py", line 416, in run_env
2017-04-24 13:10:51.601 | util.load_python_file(self.dir, 'env.py')
2017-04-24 13:10:51.601 | File "/usr/local/lib/python2.7/dist-packages/alembic/util/pyfiles.py", line 93, in load_python_file
2017-04-24 13:10:51.601 | module = load_module_py(module_id, path)
2017-04-24 13:10:51.601 | File "/usr/local/lib/python2.7/dist-packages/alembic/util/compat.py", line 75, in load_module_py
2017-04-24 13:10:51.601 | mod = imp.load_source(module_id, path, fp)
2017-04-24 13:10:51.601 | File "/opt/stack/old/ironic/ironic/db/sqlalchemy/alembic/env.py", line 61, in <module>
2017-04-24 13:10:51.601 | run_migrations_online()
2017-04-24 13:10:51.601 | File "/opt/stack/old/ironic/ironic/db/sqlalchemy/alembic/env.py", line 53, in run_migrations_online
2017-04-24 13:10:51.601 | engine = enginefacade.get_legacy_facade().get_engine()
2017-04-24 13:10:51.601 | File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 1117, in get_legacy_facade
2017-04-24 13:10:51.601 | return _context_manager.get_legacy_facade()
2017-04-24 13:10:51.601 | File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 775, in get_legacy_facade
2017-04-24 13:10:51.601 | return self._factory.get_legacy_facade()
2017-04-24 13:10:51.601 | File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqla...

[milan k (vetrisko)]

This also affects inspector's gate:

http://logs.openstack.org/03/439603/10/check/gate-grenade-dsvm-ironic-inspector-ubuntu-xenial/ebd5f14/logs/grenade.sh.txt.gz#_2017-04-23_19_47_00_250

http://logs.openstack.org/24/454724/9/gate/gate-grenade-dsvm-ironic-inspector-ubuntu-xenial/da01b0d/logs/grenade.sh.txt.gz#_2017-04-24_10_16_16_264

[OpenStack Infra (hudson-openstack)]

Change abandoned by Ruby Loo (<email address hidden>) on branch: stable/ocata
Review: https://review.openstack.org/459455
Reason: As mentioned by Vasyl, not the correct solution.

[OpenStack Infra (hudson-openstack)]

Change abandoned by Ruby Loo (<email address hidden>) on branch: stable/ocata
Review: https://review.openstack.org/459455
Reason: Thanks Vladyslav for looking into the issue. Julia pushed up the fix (which will need to be backported): https://review.openstack.org/468061.

Abandoning (again) :-)