Comment 15 for bug 1110807

Revision history for this message
Spatialist (fsluiter) wrote : Re: [Bug 1110807] Re: Openstack quantum, race condition in ip address creation when starting 50 VMs on a 5-node cluster

Hi,

it was with postgresql. However I expect it to be an issue with more
databases, as I think it has to do with not locking the record.
Postgresql supports concurrent transactions, which means that a record
can be accessed for read concurrently. Updates of course lock a
record.
Now in the code I noticed a select and a few lines down the update.
This will not give the expected behaviour of finding and locking a ip
address, as in between these statements another thread can grab the ip
address.

I am not sure how transactions are implemented in mysql, but I would
expect that they behave similar. Maybe try creating 255 ports in one
go?
multiple times?

Cheers,
Floris

2013/2/4 dan wendlandt <email address hidden>:
> i have run this in parallel in several different ways (including the one
> you describe above) and I do not see the error with mysql.
>
> When you say you have reproduced it with the above script, is that with
> mysql or postgresql?
>
> we'll address this issue either way, its just a matter of understanding
> the scope of who is impacted.
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1110807
>
> Title:
> Openstack quantum, race condition in ip address creation when starting
> 50 VMs on a 5-node cluster
>
> Status in OpenStack Quantum (virtual network service):
> New
>
> Bug description:
> When starting many VMs the same ip address is allocated to two different ports.
> We use quantum in combination with openvswitch and a postgresql database. This affects folsom 2012-2
>
> 2013-01-30 16:21:28 DEBUG [quantum.db.db_base_plugin_v2] Generated mac for network 66b5d6c2-3869-4d5f-b239-3896ff502022 is fa:16:3e:85:44:35
> 2013-01-30 16:21:28 DEBUG [quantum.db.db_base_plugin_v2] Allocated IP - 10.200.200.24 from 10.200.200.24 to 10.200.200.254
> 2013-01-30 16:21:28 DEBUG [quantum.db.db_base_plugin_v2] Allocated IP 10.200.200.24 (66b5d6c2-3869-4d5f-b239-3896ff502022/73b7eb77-c987-4c83-9ea7-45e57c89869d/e8e60edc-e5ce-46a3-8dbd-cfe5648c07b9)
> 2013-01-30 16:21:28 DEBUG [routes.middleware] No route matched for POST /ports.json
> 2013-01-30 16:21:28 DEBUG [routes.middleware] Matched POST /ports.json
> 2013-01-30 16:21:28 DEBUG [routes.middleware] Route path: '/ports{.format}', defaults: {'action': u'create', 'controller': wsgify(quantum.api.v2.resource.resource, RequestClass=<class 'quantum.api.v2.resource.Request'>)}
> 2013-01-30 16:21:28 DEBUG [routes.middleware] Match dict: {'action': u'create', 'controller': wsgify(quantum.api.v2.resource.resource, RequestClass=<class 'quantum.api.v2.resource.Request'>), 'format': u'json'}
> 2013-01-30 16:21:28 DEBUG [quantum.openstack.common.rpc.amqp] Sending port.create.start on notifications.info
> 2013-01-30 16:21:28 ERROR [quantum.api.v2.resource] create failed
> Traceback (most recent call last):
> File "/usr/lib/python2.7/dist-packages/quantum/api/v2/resource.py", line 96, in resource
> result = method(request=request, **args)
> File "/usr/lib/python2.7/dist-packages/quantum/api/v2/base.py", line 335, in create
> obj = obj_creator(request.context, **kwargs)
> File "/usr/lib/python2.7/dist-packages/quantum/db/db_base_plugin_v2.py", line 1216, in create_port
> context.session.add(allocated)
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 402, in __exit__
> self.commit()
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 314, in commit
> self._prepare_impl()
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 298, in _prepare_impl
> self.session.flush()
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1583, in flush
> self._flush(objects)
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1654, in _flush
> flush_context.execute()
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 331, in execute
> rec.execute(self)
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 475, in execute
> uow
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 64, in save_obj
> table, insert)
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 530, in _emit_insert_statements
> execute(statement, multiparams)
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1449, in execute
> params)
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1584, in _execute_clauseelement
> compiled_sql, distilled_params
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1698, in _execute_context
> context)
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1691, in _execute_context
> context)
> File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 331, in do_execute
> cursor.execute(statement, parameters)
> IntegrityError: (IntegrityError) duplicate key value violates unique constraint "ipallocations_pkey"
> DETAIL: Key (ip_address, subnet_id, network_id)=(10.200.200.24, 73b7eb77-c987-4c83-9ea7-45e57c89869d, 66b5d6c2-3869-4d5f-b239-3896ff502022) already exists.
> 'INSERT INTO ipallocations (port_id, ip_address, subnet_id, network_id, expiration) VALUES (%(port_id)s, %(ip_address)s, %(subnet_id)s, %(network_id)s, %(expiration)s)' {'network_id': u'66b5d6c2-3869-4d5f-b239-3896ff502022', 'subnet_id': u'73b7eb77-c987-4c83-9ea7-45e57c89869d', 'port_id': 'e8e60edc-e5ce-46a3-8dbd-cfe5648c07b9', 'ip_address': u'10.200.200.24', 'expiration': datetime.datetime(2013, 1, 30, 21, 23, 28, 665181)}
> 2013-01-30 16:21:28 DEBUG [eventlet.wsgi.server] 192.168.119.14 - - [30/Jan/2013 16:21:28] "POST /v2.0/ports.json HTTP/1.1" 500 215 0.240021
> 2013-01-30 16:21:28 DEBUG [amqplib] Closed channel #1
> 2013-01-30 16:21:28 DEBUG [amqplib] using channel_id: 1
> 2013-01-30 16:21:28 DEBUG [amqplib] Channel open
> 2013-01-30 16:21:28 DEBUG [quantum.openstack.common.rpc.amqp] Sending port.create.start on notifications.info
> 2013-01-30 16:21:28 DEBUG [amqplib] Closed channel #1
> 2013-01-30 16:21:28 DEBUG [amqplib] using channel_id: 1
> 2013-01-30 16:21:28 DEBUG [amqplib] Channel open
> :
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/quantum/+bug/1110807/+subscriptions