Launching instance fails in Precise A2 - network/manager.py too many values to unpack

[Kevin Jackson]

I've an out-of-the-box install of Precise A2 which is failing to spin up instances with the following messages in nova-compute.log and nova-network.log

Details replicated here: http://forums.openstack.org/viewtopic.php?f=10&t=728
And relevant paste here http://paste.openstack.org/show/4736/ which includes logs and confs.

Overview:

Single host, Precise A2
eth0 10.10.0.0/16
eth1 172.15.0.0/16
VLAN network, tied to eth0, gives vlan4025.

created networks with the following

1. created relevant user, roles and tenants in keystone, etc.
2. uploaded image to glance
3. created appropriate default security group settings
4. launched instance
5. err spewed

012-02-08 11:02:04,345 DEBUG nova.utils [-] Got semaphore "get_dhcp" for method "_get_dhcp_ip"... from (pid=3270) inner /usr/lib/python2.7/dist-packages/nova/utils.py:817
2012-02-08 11:02:04,436 DEBUG nova.network.manager [-] QUOTA: 1 from (pid=3270) allocate_floating_ip /usr/lib/python2.7/dist-packages/nova/network/manager.py:370
2012-02-08 11:02:04,521 ERROR nova.rpc [-] Exception during message handling
(nova.rpc): TRACE: Traceback (most recent call last):
(nova.rpc): TRACE: File "/usr/lib/python2.7/dist-packages/nova/rpc/amqp.py", line 249, in _process_data
(nova.rpc): TRACE: rval = node_func(context=ctxt, **node_args)
(nova.rpc): TRACE: File "/usr/lib/python2.7/dist-packages/nova/network/manager.py", line 240, in wrapped
(nova.rpc): TRACE: return func(self, context, *args, **kwargs)
(nova.rpc): TRACE: File "/usr/lib/python2.7/dist-packages/nova/network/manager.py", line 303, in allocate_for_instance
(nova.rpc): TRACE: for nw, info in nw_info:
(nova.rpc): TRACE: ValueError: too many values to unpack
(nova.rpc): TRACE:
2012-02-08 11:02:04,522 ERROR nova.rpc [-] Returning exception too many values to unpack to caller
2012-02-08 11:02:04,522 ERROR nova.rpc [-] ['Traceback (most recent call last):\n', ' File "/usr/lib/python2.7/dist-packages/nova/rpc/amqp.py", line 249, in _process_data\n rval = node_func(context=ctxt, **node_args)\n', ' File "/usr/lib/python2.7/dist-packages/nova/network/manager.py", line 240, in wrapped\n return func(self, context, *args, **kwargs)\n', ' File "/usr/lib/python2.7/dist-packages/nova/network/manager.py", line 303, in allocate_for_instance\n for nw, info in nw_info:\n', 'ValueError: too many values to unpack\n']

[Kevin Jackson (kevin-linuxservices)]

On looking at nova-manage floating-list now it shows my attempts, but equally it seems to at least attempt to go some way to allocate the public floating ip:

root@openstack1:~# nova-manage floating list
2012-02-08 13:16:55,769 DEBUG nova.utils [req-07ce2122-4915-4321-8b1a-cec8cde3bce8 None None] backend <module 'nova.db.sqlalchemy.api' from '/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.pyc'> from (pid=14755) __get_backend /usr/lib/python2.7/dist-packages/nova/utils.py:588
15a82b3d665d4fd7883ad0d142c8603c 172.15.1.1 None nova eth1
15a82b3d665d4fd7883ad0d142c8603c 172.15.1.2 None nova eth1
15a82b3d665d4fd7883ad0d142c8603c 172.15.1.3 None nova eth1
15a82b3d665d4fd7883ad0d142c8603c 172.15.1.4 None nova eth1
15a82b3d665d4fd7883ad0d142c8603c 172.15.1.5 None nova eth1
None 172.15.1.6 None nova eth1
None 172.15.1.7 None nova eth1
None 172.15.1.8 None nova eth1
None 172.15.1.9 None nova eth1
None 172.15.1.10 None nova eth1
None 172.15.1.11 None nova eth1
None 172.15.1.12 None nova eth1

[Kevin Jackson (kevin-linuxservices)]

value of nw_info when adding it to debug:

[VIF({'network': Network({'bridge': 'br4025', 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': 'fixed', 'floating_ips': [], 'address': '10.0.0.12'})], 'version': 4, 'meta': {'dhcp_server': '10.0.0.4'}, 'dns': [], 'routes': [], 'cidr': '10.0.0.0/26', 'gateway': IP({'meta': {}, 'version': 4, 'type': 'gateway', 'address': '10.0.0.1'})}), Subnet({'ips': [], 'version': None, 'meta': {'dhcp_server': '10.0.0.4'}, 'dns': [], 'routes': [], 'cidr': None, 'gateway': IP({'meta': {}, 'version': None, 'type': 'gateway', 'address': None})})], 'meta': {'multi_host': True, 'should_create_bridge': True, 'should_create_vlan': True, 'bridge_interface': 'eth0', 'tenant_id': '15a82b3d665d4fd7883ad0d142c8603c', 'vlan': 4025L}, 'id': '76828f39-8bef-4d80-8c68-f3b8b601580a', 'label': 'vmnet'}), 'meta': {}, 'id': '2b55771b-e488-4b19-8f5a-255bf67d72f0', 'address': '02:16:3e:18:fb:15'})]

[Adam Gandelman (gandelman-a)]

Hey Kevin, thanks for reporting and testing on Precise. I see you've created the pool of floating IPs, are you also creating the private network using the 'nova-manage network create' command?

[OpenStack Infra (hudson-openstack)]

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

[Kevin Jackson (kevin-linuxservices)]

I've tried attached fixes to nova/api/openstack/common.py and nova/network/manager.py

Instances now spawn, but "nova list" and "euca-describe-instances" are not reporting floating ip assigned:

RESERVATION r-pohewxbm 408b94858fdb44569478a0e984fbe5a5 default
INSTANCE i-00000003 ami-00000002 server-3 server-3 running demo (408b94858fdb44569478a0e984fbe5a5, openstack2) 1 m1.tiny 2012-02-20T11:21:39Z nova aki-00000001

+--------------------------------------+----------+--------+----------------+
| ID | Name | Status | Networks |
+--------------------------------------+----------+--------+----------------+
| 37181b44-50f1-4007-8ff7-b336391ad153 | Server 3 | ACTIVE | vmnet=10.0.0.5 |
+--------------------------------------+----------+--------+----------------+

On viewing the used floating pool I see:

408b94858fdb44569478a0e984fbe5a5 172.15.1.1 None nova eth1
408b94858fdb44569478a0e984fbe5a5 172.15.1.2 37181b44-50f1-4007-8ff7-
b336391ad153 nova eth1
None 172.15.1.3 None nova eth1
None 172.15.1.4 None nova eth1
... etc

and I can connect to the new instance on 172.15.1.2

[Jason Kölker (jason-koelker)]

I'm not going to have time to write the tests. I'm unassigning so someone else can if they feel it is necessary for essex.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/5056
Committed: http://github.com/openstack/nova/commit/c63c42146704fdf19f2f163ade62033313e27dc9
Submitter: Jenkins
Branch: master

commit c63c42146704fdf19f2f163ade62033313e27dc9
Author: John Griffith <email address hidden>
Date: Wed Mar 7 17:45:12 2012 -0700

    Update floating auto assignment to use the model

     * addresses bug 928819
     * previously submitted changes (#change,4236)
     * unit tests added that don't use fakes for everything
     * added testAssert to check assignment process
     * added call to deallocate as well

    Change-Id: I46503e6e88031a6e1ab3ac76163402091168c6b0