[openstack-dev] [Neutron ML2] Potential DB lock when developing new mechanism driver

Li Ma skywalker.nick at gmail.com
Thu Jun 26 03:49:55 UTC 2014


Sorry, I was thought that the code was straightforward to understand. I can explain what I wanna do.
I try to use postcommit to dynamically set some specific port attribute into port binding when a certain port is created.
So, I write an example to see whether it is working or not. But, 

def create_port_postcommit(self, context):
    port_id = context._port['id']
    session = db_api.get_session()

    # insert some attr in profile
    profile = {'type': 1, 'priority': 2}

    try:
        binding = (session.query(models.PortBinding).
                  filter(models.PortBinding.port_id.startswith(port_id)).
                  one())
        binding.profile = str(profile)
        session.merge(binding)
    except exc.NoResultFound:
        binding = models.PortBinding(
                  port_id=port_id,
                  vif_type=portbindings.VIF_TYPE_UNBOUND,
                  profile=str(profile))
        session.add(binding)
    except Exception as e:
        LOG.error(_("Error with port %(port_id)s"), {'port_id': port_id})  <-- line 95

Message is as follows:

2014-06-25 10:05:17.195 9915 ERROR neutron.plugins.ml2.managers [req-961680da-ce69-43c6-974c-57132def411d None] Mechanism driver 'hello' failed in create_port_postcommit
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers Traceback (most recent call last):
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib/python2.6/site-packages/neutron/plugins/ml2/managers.py", line 158, in _call_on_drivers
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     getattr(driver.obj, method_name)(context)
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib/python2.6/site-packages/neutron/plugins/ml2/drivers/mech_hello.py", line 95, in create_port_postcommit
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     {'port_id': port_id})
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 402, in __exit__
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     self.commit()
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 314, in commit
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     self._prepare_impl()
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 298, in _prepare_impl
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     self.session.flush()
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib/python2.6/site-packages/neutron/openstack/common/db/sqlalchemy/session.py", line 597, in _wrap
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     return f(*args, **kwargs)
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib/python2.6/site-packages/neutron/openstack/common/db/sqlalchemy/session.py", line 836, in flush
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     return super(Session, self).flush(*args, **kwargs)
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 1583, in flush
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     self._flush(objects)
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 1654, in _flush
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     flush_context.execute()
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/unitofwork.py", line 331, in execute
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     rec.execute(self)
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/unitofwork.py", line 475, in execute
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     uow
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/persistence.py", line 64, in save_obj
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     table, insert)
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/persistence.py", line 530, in _emit_insert_statements
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     execute(statement, multiparams)
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 1449, in execute
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     params)
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 1584, in _execute_clauseelement
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     compiled_sql, distilled_params
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 1698, in _execute_context
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     context)
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 1691, in _execute_context
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     context)
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/engine/default.py", line 331, in do_execute
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     cursor.execute(statement, parameters)
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/MySQLdb/cursors.py", line 173, in execute
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     self.errorhandler(self, exc, value)
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers   File "/usr/lib64/python2.6/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers     raise errorclass, errorvalue
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers OperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO ml2_port_bindings (port_id, host, vnic_type, profile, vif_type, vif_details, driver, segment) VALUES (%s, %s, %s, %s, %s, %s, %s, %s)' ('2f7996c2-7a60-4334-a71d-11e82285e272', '', 'normal', "{'type': 1, 'priority': 2}", 'unbound', '', None, None)


Thanks,
Li Ma


----- Original Message -----
From: "Kevin Benton" <blak111 at gmail.com>
To: "OpenStack Development Mailing List (not for usage questions)" <openstack-dev at lists.openstack.org>
Sent: 星期四, 2014年 6 月 26日 上午 10:32:47
Subject: Re: [openstack-dev] [Neutron ML2] Potential DB lock when developing new mechanism driver



What is in the variable named 'query' that you are trying to merge into the session? Can you include the full create_port_postcommit method? The line raising the exception ends with " {'port_id': port_id})" and that doesn't matching anything included in your sample. 



On Wed, Jun 25, 2014 at 6:53 PM, Li Ma < skywalker.nick at gmail.com > wrote: 


Here's a code sample which can raise db lock wait exception: 

def create_port_postcommit(self, context): 

port_id = ... 
with session.begin(subtransactions=True): 
try: 
binding = (session.query(models.PortBinding). 
filter(models.PortBinding.port_id.startswith(port_id)). 
one()) 
# Here I modify some attributes if port binding is existed 
session.merge(query) 
except exc.NoResultFound: 
# Here I insert new port binding record to initialize some attributes 
except ... 
LOG.error("error happened") 

The exception is as follows: 
2014-06-25 10:05:17.195 9915 ERROR neutron.plugins.ml2.managers [req-961680da-ce69-43c6-974c-57132def411d None] Mechanism driver 'hello' failed in create_port_postcommit 
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers Traceback (most recent call last): 
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers File "/usr/lib/python2.6/site-packages/neutron/plugins/ml2/managers.py", line 158, in _call_on_drivers 
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers getattr(driver.obj, method_name)(context) 
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers File "/usr/lib/python2.6/site-packages/neutron/plugins/ml2/drivers/mech_hello.py", line 95, in create_port_postcommit 
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers {'port_id': port_id}) 
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 402, in __exit__ 
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers self.commit() 
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 314, in commit 
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers self._prepare_impl() 
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers File "/usr/lib64/python2.6/site-packages/SQLAlchemy-0.7.8-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 298, in _prepare_impl 
2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers self.session.flush() 

... 

2014-06-25 10:05:17.195 9915 TRACE neutron.plugins.ml2.managers OperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO ml2_port_bindings (port_id, host, vnic_type, profile, vif_type, vif_details, driver, segment) VALUES (%s, %s, %s, %s, %s, %s, %s, %s)' (...) 

It seems that the transaction in the postcommit cannot be committed. 

Thanks a lot, 

Li Ma 

----- Original Message ----- 

From: "Li Ma" < skywalker.nick at gmail.com > 
To: "OpenStack Development Mailing List (not for usage questions)" < openstack-dev at lists.openstack.org > 


Sent: 星期三, 2014年 6 月 25日 下午 6:21:10 
Subject: Re: [openstack-dev] [Neutron ML2] Potential DB lock when developing new mechanism driver 

Hi Kevin, 

Thanks for your reply. Actually, it is not that straightforward. 
Even if postcommit is outside the 'with' statement, the transaction is not 'truly' committed immediately. Because when I put my db code (reading and writing ml2-related tables) in postcommit, db lock wait exception is still thrown. 

Li Ma 

----- Original Message ----- 
From: "Kevin Benton" < blak111 at gmail.com > 
To: "OpenStack Development Mailing List (not for usage questions)" < openstack-dev at lists.openstack.org > 
Sent: 星期三, 2014年 6 月 25日 下午 4:59:26 
Subject: Re: [openstack-dev] [Neutron ML2] Potential DB lock when developing new mechanism driver 



The post_commit methods occur outside of the transactions. You should be able to perform the necessary database calls there. 


If you look at the code snippet in the email you provided, you can see that the 'try' block surrounding the postcommit method is at the same indentation-level as the 'with' statement for the transaction so it will be closed at that point. 


Cheers, 
Kevin Benton 


-- 
Kevin Benton 



On Tue, Jun 24, 2014 at 8:33 PM, Li Ma < skywalker.nick at gmail.com > wrote: 


Hi all, 

I'm developing a new mechanism driver. I'd like to access ml2-related tables in create_port_precommit and create_port_postcommit. However I find it hard to do that because the two functions are both inside an existed database transaction defined in create_port function of ml2/plugin.py. 

The related code is as follows: 

def create_port(self, context, port): 
... 
session = context.session 
with session.begin(subtransactions=True): 
... 
self.mechanism_manager.create_port_precommit(mech_context) 
try: 
self.mechanism_manager.create_port_postcommit(mech_context) 
... 
... 
return result 

As a result, I need to carefully deal with the database nested transaction issue to prevent from db lock when I develop my own mechanism driver. Right now, I'm trying to get the idea behind the scene. Is it possible to refactor it in order to make precommit and postcommit out of the db transaction? I think it is perfect for those who develop mechanism driver and do not know well about the functioning context of the whole ML2 plugin. 

Thanks, 
Li Ma 

_______________________________________________ 
OpenStack-dev mailing list 
OpenStack-dev at lists.openstack.org 
http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev 




-- 

Kevin Benton 
_______________________________________________ 
OpenStack-dev mailing list 
OpenStack-dev at lists.openstack.org 
http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev 

_______________________________________________ 
OpenStack-dev mailing list 
OpenStack-dev at lists.openstack.org 
http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev 




-- 

Kevin Benton 
_______________________________________________
OpenStack-dev mailing list
OpenStack-dev at lists.openstack.org
http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev



More information about the OpenStack-dev mailing list