openstack team mailing list archive

[Dan Wendlandt <dan@xxxxxxxxxx>]

Hi Gary,

Thanks for reporting this.

After some digging, the bug seems to have been introduced by an error in a
blanket changeset to switch Nova from using json to jasonutils.  During
that translation, a "return" statement was dropped, meaning the serializer
always returned Null regardless of what data was pushed in.  See:
https://github.com/openstack/nova/commit/ba76b954e69de56f76f9db5cade1780bc351be67#L5L42

Another bug where having Quantum be part of the gating process would have
helped... so we really need to find resources to help get that work
complete.

Patch here is trivial, so I'll push it and hopefully it can get reviewed
quickly by the Nova core team.

Dan




On Thu, May 17, 2012 at 12:24 AM, Gary Kotton <gkotton@xxxxxxxxxx> wrote:

> **
> Hi,
> Running devstack this morning the following happens:
>
> + /opt/stack/nova/bin/nova-manage network create private 10.0.0.0/24 1 256
> 2012-05-17 03:22:05 WARNING nova.network.quantum.manager
> [req-5458d926-54d1-4877-9c46-d04035742eaf None None] QuantumManager does
> not use 'bridge' parameter.
> 2012-05-17 03:22:05 WARNING nova.network.quantum.manager
> [req-5458d926-54d1-4877-9c46-d04035742eaf None None] QuantumManager does
> not use 'bridge_interface' parameter.
> 2012-05-17 03:22:05 DEBUG nova.network.quantum.quantum_connection
> [req-5458d926-54d1-4877-9c46-d04035742eaf None None] Quantum Client
> Request: POST /v1.1/tenants/default/networks.json from (pid=3826)
> do_request /opt/stack/nova/nova/network/quantum/client.py:178
> 2012-05-17 03:22:05 DEBUG nova.network.quantum.quantum_connection
> [req-5458d926-54d1-4877-9c46-d04035742eaf None None] Quantum Client Reply
> (code = 400) :
>  {"Error": {"message": "The server could not comply with the request since
> it is either malformed or otherwise incorrect.", "code": 400}} from
> (pid=3826) do_request /opt/stack/nova/nova/network/quantum/client.py:189
> Command failed, please check log for more info
> 2012-05-17 03:22:05 CRITICAL nova
> [req-5458d926-54d1-4877-9c46-d04035742eaf None None] Server 400 error:
> {"Error": {"message": "The server could not comply with the request since
> it is either malformed or otherwise incorrect.", "code": 400}}
> 2012-05-17 03:22:05 TRACE nova Traceback (most recent call last):
> 2012-05-17 03:22:05 TRACE nova   File "/opt/stack/nova/bin/nova-manage",
> line 1755, in <module>
> 2012-05-17 03:22:05 TRACE nova     main()
> 2012-05-17 03:22:05 TRACE nova   File "/opt/stack/nova/bin/nova-manage",
> line 1742, in main
> 2012-05-17 03:22:05 TRACE nova     fn(*fn_args, **fn_kwargs)
> 2012-05-17 03:22:05 TRACE nova   File "/opt/stack/nova/bin/nova-manage",
> line 817, in create
> 2012-05-17 03:22:05 TRACE nova     fixed_cidr=fixed_cidr)
> 2012-05-17 03:22:05 TRACE nova   File
> "/opt/stack/nova/nova/network/quantum/manager.py", line 232, in
> create_networks
> 2012-05-17 03:22:05 TRACE nova     nova_id=nova_id)
> 2012-05-17 03:22:05 TRACE nova   File
> "/opt/stack/nova/nova/network/quantum/quantum_connection.py", line 67, in
> create_network
> 2012-05-17 03:22:05 TRACE nova     resdict =
> self.client.create_network(data, tenant=tenant_id)
> 2012-05-17 03:22:05 TRACE nova   File
> "/opt/stack/nova/nova/network/quantum/client.py", line 82, in with_params
> 2012-05-17 03:22:05 TRACE nova     ret = self.func(instance, *args,
> **kwargs)
> 2012-05-17 03:22:05 TRACE nova   File
> "/opt/stack/nova/nova/network/quantum/client.py", line 250, in
> create_network
> 2012-05-17 03:22:05 TRACE nova     return self.do_request("POST",
> self.networks_path, body=body)
> 2012-05-17 03:22:05 TRACE nova   File
> "/opt/stack/nova/nova/network/quantum/client.py", line 204, in do_request
> 2012-05-17 03:22:05 TRACE nova     % locals())
> 2012-05-17 03:22:05 TRACE nova QuantumServerException: Server 400 error:
> {"Error": {"message": "The server could not comply with the request since
> it is either malformed or otherwise incorrect.", "code": 400}}
> 2012-05-17 03:22:05 TRACE nova
> ++ failed
> ++ local r=1
> ++ set +o xtrace
>
> Thanks
> Gary
>
>
> On 05/17/2012 12:07 AM, Dan Wendlandt wrote:
>
>
>
> On Wed, May 16, 2012 at 2:01 PM, Sumit Naiksatam (snaiksat) <
> snaiksat@xxxxxxxxx> wrote:
>
>>  The interesting data point here is that this only happens to the
>> default network created when the installation is done via DevStack. For all
>> network created subsequently I am not seeing this issue. I earlier thought
>> that this might have something to do with the exercises script getting
>> executed and possibly leaving a residue. However, in spite of not running
>> the exercises script I am still seeing this issue. It seems that for some
>> reason, the initialize_gateway() was getting called only when a new VM was
>> being created. But here it seems to be getting called before that (thus
>> leading to the creation of the bridge and the gateway devices), not sure
>> why. I am just trying to figure out how I can test the fix with respect to
>> the devstack setup (since this happens only on installation)…
>>
>
>  Your explanation makes sense.  I think there was a recent comment to
> automatically initialize all networks when nova-network is started, in case
> nova-network was started on a new host (e.g., in an HA configuration) or
> after a host reboot.  Since devstack creates the network using nova-manage
> before starting nova-network, this would trigger the behavior your
> describe.  For more info, see:
> https://github.com/openstack/nova/commit/30c8293ea7d4c9464e0139fb488e202fd0947f52
>
>  I suspect you should hit this every time you re-run stack.sh, no?
>
>
>
>
>
>>
>>
>> *From:* Dan Wendlandt [mailto:dan@xxxxxxxxxx]
>> *Sent:* Wednesday, May 16, 2012 7:55 AM
>> *To:* gkotton@xxxxxxxxxx
>> *Cc:* Sumit Naiksatam (snaiksat); netstack@xxxxxxxxxxxxxxxxxxx
>> *Subject:* Re: [Netstack] Fwd: [Openstack] [devstack/quantum]
>> Configuration issue
>>
>>
>>
>>
>>
>> On Wed, May 16, 2012 at 1:43 AM, Gary Kotton <gkotton@xxxxxxxxxx> wrote:
>>
>> Thanks!
>> As far as I recall, and I may certain be wrong here, but in the past I
>> did not see the GW created until the first VM was deployed. Now I am seeing
>> the GW created when the various services are started.
>>
>>
>>
>> I have noticed this as well.  I'm not aware of any changes to
>> QuantumManager that had this affect, though its possible someone pushed a
>> change that I didn't notice.  I primarily use the OVS interface-driver and
>> didn't notice any issues, so I suspect Sumit is correct that we can at
>> least work around this with a change to the LB interface-driver (even
>> though the change that caused the issue was likely somewhere else).
>>
>>
>>
>> This is a good example of why we need Quantum integrated into devstack
>> commit-gating, as it will catch this type of complex integration issues.
>>  Anyone have cycles to help push on this?  I'm unlikely to make much
>> progress on it in the next week or two due to the F-1 release.
>>
>>
>>
>> Dan
>>
>>
>>
>>
>>
>>
>>
>>  Thanks
>> Gary
>>
>>
>>
>> On 05/16/2012 10:54 AM, Sumit Naiksatam (snaiksat) wrote:
>>
>> This is probably not a devstack issue. The problem is with the LB gateway
>> driver wherein the IP address is trying to be set on a bridge device which
>> already has an IP address. The check for an existing bridge is being
>> performed, but the IP address is being set outside that check. Ideally,
>> this code should not have been invoked if the gateway was already set.
>> Something seems to have changed in the QuantumManager as result of which
>> this code is being invoked again. At any rate, I will fix the LB gateway
>> driver, and we will not see this.
>>
>>
>>
>> Thanks,
>>
>> ~Sumit.
>>
>>
>>
>> *From:* netstack-bounces+snaiksat=cisco.com@xxxxxxxxxxxxxxxxxxx [
>> mailto:netstack-bounces+snaiksat=cisco.com@xxxxxxxxxxxxxxxxxxx<netstack-bounces+snaiksat=cisco.com@xxxxxxxxxxxxxxxxxxx>]
>> *On Behalf Of *Gary Kotton
>> *Sent:* Monday, May 14, 2012 11:19 PM
>> *To:* <netstack@xxxxxxxxxxxxxxxxxxx> <netstack@xxxxxxxxxxxxxxxxxxx>
>> *Subject:* [Netstack] Fwd: [Openstack] [devstack/quantum] Configuration
>> issue
>>
>>
>>
>>
>>
>> -------- Original Message --------
>>
>> *Subject: *
>>
>> [Openstack] [devstack/quantum] Configuration issue
>>
>> *Date: *
>>
>> Tue, 15 May 2012 09:00:52 +0300
>>
>> *From: *
>>
>> Gary Kotton <gkotton@xxxxxxxxxx> <gkotton@xxxxxxxxxx>
>>
>> *Reply-To: *
>>
>> gkotton@xxxxxxxxxx
>>
>> *Organization: *
>>
>> Red Hat
>>
>> *To: *
>>
>> openstack@xxxxxxxxxxxxxxxxxxx
>>
>>
>>
>> Hi,
>>
>> This morning I encountered a problem (which did not happen a few days
>>
>> ago :)). When devstack is launched, with quantum configured, the gateway
>>
>> and bridge devices are created. This causes problems with quantum.
>>
>>
>>
>> For example when devstack is up and running prior to deploying an
>>
>> instance we have:
>>
>>
>>
>> brq744ec2f4-c0 Link encap:Ethernet  HWaddr fa:16:3e:03:a6:55
>>
>>           inet addr:10.0.0.1  Bcast:0.0.0.0  Mask:255.255.255.0
>>
>>           UP BROADCAST MULTICAST  MTU:1500  Metric:1
>>
>>           RX packets:0 errors:0 dropped:0 overruns:0 frame:0
>>
>>           TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
>>
>>           collisions:0 txqueuelen:0
>>
>>           RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)
>>
>>
>>
>> gw-744ec2f4-c0 Link encap:Ethernet  HWaddr fa:16:3e:03:a6:55
>>
>>           inet addr:10.0.0.1  Bcast:10.0.0.255  Mask:255.255.255.0
>>
>>           UP BROADCAST MULTICAST  MTU:1500  Metric:1
>>
>>           RX packets:0 errors:0 dropped:0 overruns:0 frame:0
>>
>>           TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
>>
>>           collisions:0 txqueuelen:500
>>
>>           RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)
>>
>>
>>
>> When an instance is deployed the following happens:
>>
>>
>>
>> 2012-05-15 01:59:18 DEBUG nova.utils
>>
>> [req-4d50ed10-46e1-406c-9074-dc45da860365
>>
>> df07eec326434b25800f3ebc17202fb3 2cafe0be4d7740098a89be39ffd1b72e]
>>
>> Running cmd (subprocess): sudo /usr/local/bin/nova-rootwrap ip address
>>
>> add 10.0.0.1/24 dev brq744ec2f4-c0 from (pid=4234) execute
>>
>> /opt/stack/nova/nova/utils.py:178
>>
>> 2012-05-15 01:59:18 DEBUG nova.utils
>>
>> [req-4d50ed10-46e1-406c-9074-dc45da860365
>>
>> df07eec326434b25800f3ebc17202fb3 2cafe0be4d7740098a89be39ffd1b72e]
>>
>> Result was 254 from (pid=4234) execute /opt/stack/nova/nova/utils.py:194
>>
>> 2012-05-15 01:59:18 ERROR nova.rpc.amqp
>>
>> [req-4d50ed10-46e1-406c-9074-dc45da860365
>>
>> df07eec326434b25800f3ebc17202fb3 2cafe0be4d7740098a89be39ffd1b72e]
>>
>> Exception during message handling
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp Traceback (most recent call last):
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp   File
>>
>> "/opt/stack/nova/nova/rpc/amqp.py", line 263, in _process_data
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp     rval =
>>
>> node_func(context=ctxt, **node_args)
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp   File
>>
>> "/opt/stack/nova/nova/network/quantum/manager.py", line 390, in
>>
>> allocate_for_instance
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp     network, vif_rec,
>>
>> network['net_tenant_id'])
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp   File
>>
>> "/opt/stack/nova/nova/utils.py", line 880, in inner
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp     retval = f(*args, **kwargs)
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp   File
>>
>> "/opt/stack/nova/nova/network/quantum/manager.py", line 501, in enable_dhcp
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp
>>
>> self.l3driver.initialize_gateway(network_ref)
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp   File
>>
>> "/opt/stack/nova/nova/network/l3.py", line 98, in initialize_gateway
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp
>>
>> gateway=(network_ref['gateway'] is not None))
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp   File
>>
>> "/opt/stack/nova/nova/network/linux_net.py", line 900, in plug
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp     return
>>
>> _get_interface_driver().plug(network, mac_address, gateway)
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp   File
>>
>> "/opt/stack/nova/nova/network/linux_net.py", line 1160, in plug
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp     run_as_root=True)
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp   File
>>
>> "/opt/stack/nova/nova/utils.py", line 201, in execute
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp     cmd=' '.join(cmd))
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp ProcessExecutionError:
>>
>> Unexpected error while running command.
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp Command: sudo
>>
>> /usr/local/bin/nova-rootwrap ip address add 10.0.0.1/24 dev brq744ec2f4-c0
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp Exit code: 254
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp Stdout: ''
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp Stderr: 'RTNETLINK answers: File
>>
>> exists\n'
>>
>> 2012-05-15 01:59:18 TRACE nova.rpc.amqp
>>
>> 2012-05-15 01:59:18 ERROR nova.rpc.common
>>
>> [req-4d50ed10-46e1-406c-9074-dc45da860365
>>
>> df07eec326434b25800f3ebc17202fb3 2cafe0be4d7740098a89be39ffd1b72e]
>>
>> Returning exception Unexpected error while running command.
>>
>> Command: sudo /usr/local/bin/nova-rootwrap ip address add 10.0.0.1/24
>>
>> dev brq744ec2f4-c0
>>
>> Exit code: 254
>>
>> Stdout: ''
>>
>> Stderr: 'RTNETLINK answers: File exists\n' to caller
>>
>> 2012-05-15 01:59:18 ERROR nova.rpc.common
>>
>> [req-4d50ed10-46e1-406c-9074-dc45da860365
>>
>> df07eec326434b25800f3ebc17202fb3 2cafe0be4d7740098a89be39ffd1b72e]
>>
>> ['Traceback (most recent call last):\n', '  File
>>
>> "/opt/stack/nova/nova/rpc/amqp.py", line 263, in _process_data\n    rval
>>
>> = node_func(context=ctxt, **node_args)\n', '  File
>>
>> "/opt/stack/nova/nova/network/quantum/manager.py", line 390, in
>>
>> allocate_for_instance\n    network, vif_rec,
>>
>> network[\'net_tenant_id\'])\n', '  File "/opt/stack/nova/nova/utils.py",
>>
>> line 880, in inner\n    retval = f(*args, **kwargs)\n', '  File
>>
>> "/opt/stack/nova/nova/network/quantum/manager.py", line 501, in
>>
>> enable_dhcp\n    self.l3driver.initialize_gateway(network_ref)\n', '
>>
>> File "/opt/stack/nova/nova/network/l3.py", line 98, in
>>
>> initialize_gateway\n    gateway=(network_ref[\'gateway\'] is not
>>
>> None))\n', '  File "/opt/stack/nova/nova/network/linux_net.py", line
>>
>> 900, in plug\n    return _get_interface_driver().plug(network,
>>
>> mac_address, gateway)\n', '  File
>>
>> "/opt/stack/nova/nova/network/linux_net.py", line 1160, in plug\n
>>
>> run_as_root=True)\n', '  File "/opt/stack/nova/nova/utils.py", line 201,
>>
>> in execute\n    cmd=\' \'.join(cmd))\n', "ProcessExecutionError:
>>
>> Unexpected error while running command.\nCommand: sudo
>>
>> /usr/local/bin/nova-rootwrap ip address add 10.0.0.1/24 dev
>>
>> brq744ec2f4-c0\nExit code: 254\nStdout: ''\nStderr: 'RTNETLINK answers:
>>
>> File exists\\n'\n"]
>>
>>
>>
>>
>>
>> My guess is that this can be solved with the nova configuration. Sadly I
>>
>> am not too familiar with these. Any help would be great.
>>
>> Thanks
>>
>> Gary
>>
>>
>>
>> _______________________________________________
>>
>> Mailing list: https://launchpad.net/~openstack
>>
>> Post to     : openstack@xxxxxxxxxxxxxxxxxxx
>>
>> Unsubscribe : https://launchpad.net/~openstack
>>
>> More help   : https://help.launchpad.net/ListHelp
>>
>>
>>
>>
>> --
>> Mailing list: https://launchpad.net/~netstack
>> Post to     : netstack@xxxxxxxxxxxxxxxxxxx
>> Unsubscribe : https://launchpad.net/~netstack
>> More help   : https://help.launchpad.net/ListHelp
>>
>>
>>
>>
>>
>> --
>> ~~~~~~~~~~~~~~~~~~~~~~~~~~~
>> Dan Wendlandt
>>
>> Nicira, Inc: www.nicira.com
>>
>> twitter: danwendlandt
>> ~~~~~~~~~~~~~~~~~~~~~~~~~~~
>>
>>
>>
>
>
>
>  --
> ~~~~~~~~~~~~~~~~~~~~~~~~~~~
> Dan Wendlandt
> Nicira, Inc: www.nicira.com
> twitter: danwendlandt
> ~~~~~~~~~~~~~~~~~~~~~~~~~~~
>
>
>


-- 
~~~~~~~~~~~~~~~~~~~~~~~~~~~
Dan Wendlandt
Nicira, Inc: www.nicira.com
twitter: danwendlandt
~~~~~~~~~~~~~~~~~~~~~~~~~~~