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

Kevin Benton blak111 at gmail.com
Thu Jun 26 04:53:56 UTC 2014


Hi,

I'm trying this code and I can't get it to throw that exception. How are
you triggering it?

See my code here:
https://review.openstack.org/#/c/102715/1/neutron/plugins/ml2/drivers/mech_bigswitch/driver.py


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

> 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
>
> _______________________________________________
> OpenStack-dev mailing list
> OpenStack-dev at lists.openstack.org
> http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev
>



-- 
Kevin Benton
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openstack.org/pipermail/openstack-dev/attachments/20140625/fb4a8702/attachment.html>


More information about the OpenStack-dev mailing list