Comment 11 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 Dan,

I first ran your test:

> set port_quota in quantum.conf to -1 (unlimited) and restart quantum-
> server
> In one window, i run:
> quantum net-create test1
> quantum subnet-create test1 10.0.0.0/24
>
> Then I start two windows in parallel with the same command:
> for i in `seq 1 50`; do quantum port-create test1 | grep fixed_ips; done

But that didn show the bug.
But now I slightly modified your test and created 10 parallel hreads
(all in one go pasted in in the same xterm):

quantum net-create bugtest1
quantum subnet-create bugtest1 10.0.0.0/24
for i in `seq 1 10`; do quantum port-create bugtest1 | grep fixed_ips; done&
for i in `seq 1 10`; do quantum port-create bugtest1 | grep fixed_ips; done&
for i in `seq 1 10`; do quantum port-create bugtest1 | grep fixed_ips; done&
for i in `seq 1 10`; do quantum port-create bugtest1 | grep fixed_ips; done&
for i in `seq 1 10`; do quantum port-create bugtest1 | grep fixed_ips; done&
for i in `seq 1 10`; do quantum port-create bugtest1 | grep fixed_ips; done&
for i in `seq 1 10`; do quantum port-create bugtest1 | grep fixed_ips; done&
for i in `seq 1 10`; do quantum port-create bugtest1 | grep fixed_ips; done&
for i in `seq 1 10`; do quantum port-create bugtest1 | grep fixed_ips; done&
for i in `seq 1 10`; do quantum port-create bugtest1 | grep fixed_ips; done&

Now this failed 3 times:
"Request Failed: internal server error while processing your request."
ANd the server.log shows the same errors as above: "create failed"
Now this test might seem artificial, however if you use dashboard to
create 50 VMs (and yes we do in production), it uses multiple Apache
threads to handle the calls. And Apache in turn calls quantum in
parallel.

Can you reproduce my errors?

Kind regards,
Floris

2013/2/1 F.Sluiter <email address hidden>:
> Actually i think it will also happen with mysql if the requests are handled
> by multiple quantum threads.
>
> Op 1 feb. 2013 08:01 schreef "dan wendlandt" <email address hidden>
> het volgende:
>
>> Ah, from your earlier comment, looks like you already have tracked this
>> down to a difference of how selects will work between mysql and
>> postgresql. If so, we should update the title of the bug to indicate
>> this.
>>
>> --
>> 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