nova.api.openstack.extensions AttributeError: '_TransactionFactory' object has no attribute '_writer_maker'

Bug #1515326 reported by Yongli He
10
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
High
Sergey Nikitin
oslo.db
Fix Released
High
Mike Bayer

Bug Description

full log:
http://52.27.155.124/240218/5/
http://52.27.155.124/240218/5/screen-logs/n-api.log.gz

pip freeze:
http://52.27.155.124/240218/5/pip-freeze.txt.gz

F.Y.I a bug seems same but it's not: https://bugs.launchpad.net/oslo.db/+bug/1477080

related exception for your convenient:

opt/stack/nova/nova/api/openstack/wsgi.py:792
2015-11-11 22:02:42.644 ERROR nova.api.openstack.extensions [req-3e331369-71d7-448f-bb06-6ef34762bb73 tempest-InputScenarioUtils-640491222 tempest-InputScenarioUtils-1686267846] Unexpected exception in API method
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions Traceback (most recent call last):
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/api/openstack/extensions.py", line 478, in wrapped
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions return f(*args, **kwargs)
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/api/openstack/compute/flavors.py", line 39, in index
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions limited_flavors = self._get_flavors(req)
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/api/openstack/compute/flavors.py", line 110, in _get_flavors
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions limit=limit, marker=marker)
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/compute/flavors.py", line 200, in get_all_flavors_sorted_list
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions marker=marker)
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 171, in wrapper
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions result = fn(cls, context, *args, **kwargs)
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/objects/flavor.py", line 269, in get_all
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions marker=marker)
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/db/api.py", line 1442, in flavor_get_all
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions sort_dir=sort_dir, limit=limit, marker=marker)
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 204, in wrapper
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions return f(*args, **kwargs)
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 4698, in flavor_get_all
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions query = _flavor_get_query(context, read_deleted=read_deleted)
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 4673, in _flavor_get_query
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions read_deleted=read_deleted).\
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 266, in model_query
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions session = get_session(use_slave=use_slave)
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 172, in get_session
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions use_slave=use_slave, **kwargs)
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 977, in get_session
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions return self._factory._writer_maker(**kwargs)
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions AttributeError: '_TransactionFactory' object has no attribute '_writer_maker'
2015-11-11 22:02:42.644 36750 ERROR nova.api.openstack.extensions

Revision history for this message
Davanum Srinivas (DIMS) (dims-v) wrote :
Revision history for this message
Mike Bayer (zzzeek) wrote :

davanum -

is the fix in https://review.openstack.org/#/c/205646/ released? it prevents this specific exception from occurring. the issue is that when the connection fails due to mis-configuration or other issue, then the enginefacade is called a second time, it fails to go through the whole process again and assumes its initialized.

Revision history for this message
Mike Bayer (zzzeek) wrote :

OK, this is a different codepath, so in that case if the enginefacade started improperly this path can still be hit.

However it is still a secondary error to something else not being done correctly in the first place - the _TransactionFactory will have a _writer_maker if the database config was established.

Revision history for this message
Yongli He (yongli-he) wrote :

so, this is not a configuration error, is should be a defect in some code in nova i think. leading to occasionally hit this path.

Revision history for this message
Mike Bayer (zzzeek) wrote :

Here's the bug in Nova.

First, they are calling upon the private _factory member inappropriately:

def get_engine(use_slave=False):
    return main_context_manager._factory.get_legacy_facade().get_engine(
        use_slave=use_slave)

def get_api_engine():
    return api_context_manager._factory.get_legacy_facade().get_engine()

def get_session(use_slave=False, **kwargs):
    return main_context_manager._factory.get_legacy_facade().get_session(
        use_slave=use_slave, **kwargs)

So that a LegacyEngineFacade is created without actually initializing the factory. Then, the code that's failing here fails to call the configure() function, which would establish the factory with engine parameters.

In oslo.db I can add a more descriptive exception message but you'd still get an error, and this error doesn't know about Nova having a function called "configure()" either.

Revision history for this message
Davanum Srinivas (DIMS) (dims-v) wrote :

I am hoping the stuff in the pipeline will fix some of these:
https://review.openstack.org/#/q/project:openstack/nova+topic:bp/new-oslodb-enginefacade,n,z

Revision history for this message
Mike Bayer (zzzeek) wrote :

I'm actually not quite sure how they're getting to this point but a fix so that the same descriptive error is raised consistently is in https://review.openstack.org/#/c/244323/

Changed in oslo.db:
assignee: nobody → Mike Bayer (zzzeek)
status: New → In Progress
Revision history for this message
Matt Riedemann (mriedem) wrote :
Download full text (3.4 KiB)

Seen here in an openstackclient job:

http://logs.openstack.org/04/240804/3/gate/gate-osc-dsvm-functional/9a34c38/logs/screen-n-api.txt.gz?level=TRACE#_2015-11-11_22_52_34_533

2015-11-11 22:52:34.533 ERROR nova.api.openstack.extensions [req-4895a748-50ec-4d45-bfaa-28c170f6dee3 admin admin] Unexpected exception in API method
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions Traceback (most recent call last):
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions File "/opt/stack/new/nova/nova/api/openstack/extensions.py", line 478, in wrapped
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions return f(*args, **kwargs)
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 73, in wrapper
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions return func(*args, **kwargs)
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 73, in wrapper
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions return func(*args, **kwargs)
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions File "/opt/stack/new/nova/nova/api/openstack/compute/flavor_manage.py", line 80, in _create
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions is_public=is_public)
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions File "/opt/stack/new/nova/nova/compute/flavors.py", line 175, in create
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions flavor.create()
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 213, in wrapper
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions return fn(self, *args, **kwargs)
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions File "/opt/stack/new/nova/nova/objects/flavor.py", line 177, in create
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions db_flavor = db.flavor_create(self._context, updates, projects=projects)
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions File "/opt/stack/new/nova/nova/db/api.py", line 1434, in flavor_create
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions return IMPL.flavor_create(context, values, projects=projects)
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 4638, in flavor_create
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions session = get_session()
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 172, in get_session
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions use_slave=use_slave, **kwargs)
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 977, in get_session
2015-11-11 22:52:34.533 22634 ERROR nova.api.openstack.extensions ...

Read more...

Changed in oslo.db:
importance: Undecided → High
Changed in nova:
importance: Undecided → High
Revision history for this message
Davanum Srinivas (DIMS) (dims-v) wrote :
Changed in oslo.db:
status: In Progress → Fix Committed
Changed in nova:
status: New → In Progress
assignee: nobody → Sergey Nikitin (snikitin)
Changed in oslo.db:
milestone: none → 3.2.0
status: Fix Committed → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (master)

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

Revision history for this message
Yongli He (yongli-he) wrote :

this problem begin to affect SRIOV testing for Neutron, example log:
http://52.27.155.124/sriov/206033/10/screen-logs/n-api.log.gz

Revision history for this message
Sergey Nikitin (snikitin) wrote :
Changed in nova:
status: In Progress → Fix Committed
Changed in nova:
status: Fix Committed → Fix Released
Changed in nova:
milestone: none → mitaka-1
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.