** Changed in: neutron
Status: Fix Committed => Fix Released
** Changed in: neutron
Milestone: None => juno-3
--
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1284311
Title:
lb-agent: delete_vlan_bridge() logs too many errors
Status in OpenStack Neutron (virtual network service):
Fix Released
Bug description:
https://github.com/openstack/neutron/blob/14cb886809e5cccbf799a0dc2e5b99f31b1ab3be/neutron/plugins/linuxbridge/agent/linuxbridge_neutron_agent.py#L419
There are a few problems with delete_vlan_bridge():
1. It does not allow for get_interfaces_on_bridge returning None.
2. It does not wrap a couple of ip link calls in try/except.
3. It logs at level ERROR, but WARN would be more appropriate.
The last line in the function logs an error every time a network
is deleted, as delete_vlan_bridge() always gets called twice:
once by daemon_loop() and once by the network_delete() rpc.
These causes errors and exceptions to be logged which are overstated
becuase the problems are of no consequence.
Here is a stacktrace of a race between the rpc and daemon_loop
threads. In the network_delete() rpc thread, delete_vlan_bridge()
calls device_exists() which returns True. Then it calls
get_interfaces_on_bridge() which also calls device_exists() but now it
returned False because the main green thread running daemon_loop has
deleted the bridge in the time in between.
2014-02-24 13:14:22.885 6475 DEBUG neutron.agent.linux.utils [-] Running
command: ['sudo', '/usr/local/bin/neutron-rootwrap',
'/etc/neutron/rootwrap.conf', 'ip', 'link', 'show', 'dev', 'brqa0fdcdd0-27']
create_process /opt/stack/neutron/neutron/agent/linux/utils.py:48
2014-02-24 13:14:23.165 6475 DEBUG neutron.agent.linux.utils [-]
Command: ['sudo', '/usr/local/bin/neutron-rootwrap',
'/etc/neutron/rootwrap.conf', 'ip', 'link', 'show', 'dev', 'brqa0fdcdd0-27']
Exit code: 0
Stdout: '156: brqa0fdcdd0-27: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500
qdisc noqueue state DOWN \n link/ether 00:00:00:00:00:00 brd
ff:ff:ff:ff:ff:ff\n'
Stderr: '' execute /opt/stack/neutron/neutron/agent/linux/utils.py:74
2014-02-24 13:14:23.167 6475 DEBUG neutron.agent.linux.utils [-] Running
command: ['sudo', '/usr/local/bin/neutron-rootwrap',
'/etc/neutron/rootwrap.conf', 'ip', 'link', 'show', 'dev', 'brqa0fdcdd0-27']
create_process /opt/stack/neutron/neutron/agent/linux/utils.py:48
2014-02-24 13:14:23.373 6475 DEBUG neutron.agent.linux.utils [-]
Command: ['sudo', '/usr/local/bin/neutron-rootwrap',
'/etc/neutron/rootwrap.conf', 'ip', 'link', 'show', 'dev', 'brqa0fdcdd0-27']
Exit code: 0
Stdout: '156: brqa0fdcdd0-27: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500
qdisc noqueue state DOWN \n link/ether 00:00:00:00:00:00 brd
ff:ff:ff:ff:ff:ff\n'
Stderr: '' execute /opt/stack/neutron/neutron/agent/linux/utils.py:74
2014-02-24 13:14:23.374 6475 DEBUG
neutron.plugins.linuxbridge.agent.linuxbridge_neutron_agent [-] Deleting bridge
brqa0fdcdd0-27 delete_vlan_bridge
/opt/stack/neutron/neutron/plugins/linuxbridge/agent/linuxbridge_neutron_agent.py:440
2014-02-24 13:14:23.375 6475 DEBUG neutron.agent.linux.utils [-] Running
command: ['sudo', '/usr/local/bin/neutron-rootwrap',
'/etc/neutron/rootwrap.conf', 'ip', 'link', 'set', 'brqa0fdcdd0-27', 'down']
create_process /opt/stack/neutron/neutron/agent/linux/utils.py:48
2014-02-24 13:14:23.418 6475 DEBUG neutron.openstack.common.rpc.amqp [-]
Making asynchronous cast on q-plugin... cast
/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583
2014-02-24 13:14:23.420 6475 DEBUG neutron.openstack.common.rpc.amqp [-]
UNIQUE_ID is 479398d47cc24de9b03195654ac262b5. _add_unique_id
/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342
2014-02-24 13:14:23.548 6475 DEBUG neutron.openstack.common.rpc.amqp [-]
received {u'_context_roles': [u'_member_', u'admin'], u'_context_request_id':
u'req-143cf938-461f-4c2c-b72b-84f67df9a78e', u'_context_read_deleted': u'no',
u'_context_user_name': u'admin', u'_context_project_name': u'admin',
u'namespace': None, u'_context_tenant_id': u'e4ead7e65ee94a11b86bd404cb03848d',
u'args': {u'network_id': u'a0fdcdd0-27f5-4ef5-bc5c-19537de1fd46'},
u'_context_tenant': u'e4ead7e65ee94a11b86bd404cb03848d', u'_unique_id':
u'ad76c8f0bb52408894657236f98ac564', u'_context_is_admin': True, u'version':
u'1.1', u'_context_timestamp': u'2014-02-24 13:14:23.460752',
u'_context_tenant_name': u'admin', u'_context_user':
u'7d0f5cc1d41949188da11301926e3a6a', u'_context_user_id':
u'7d0f5cc1d41949188da11301926e3a6a', u'method': u'network_delete',
u'_context_project_id': u'e4ead7e65ee94a11b86bd404cb03848d'} _safe_log
/opt/stack/neutron/neutron/openstack/common/rpc/common.py:276
2014-02-24 13:14:23.549 6475 DEBUG neutron.openstack.common.rpc.amqp [-]
unpacked context: {'project_name': u'admin', 'user_id':
u'7d0f5cc1d41949188da11301926e3a6a', 'roles': [u'_member_', u'admin'],
'tenant_id': u'e4ead7e65ee94a11b86bd404cb03848d', 'timestamp': u'2014-02-24
13:14:23.460752', 'is_admin': True, 'read_deleted': u'no', 'request_id':
u'req-143cf938-461f-4c2c-b72b-84f67df9a78e', 'tenant_name': u'admin',
'project_id': u'e4ead7e65ee94a11b86bd404cb03848d', 'user_name': u'admin',
'tenant': u'e4ead7e65ee94a11b86bd404cb03848d', 'user':
u'7d0f5cc1d41949188da11301926e3a6a'} _safe_log
/opt/stack/neutron/neutron/openstack/common/rpc/common.py:276
2014-02-24 13:14:23.556 6475 DEBUG
neutron.plugins.linuxbridge.agent.linuxbridge_neutron_agent
[req-143cf938-461f-4c2c-b72b-84f67df9a78e None] network_delete received
network_delete
/opt/stack/neutron/neutron/plugins/linuxbridge/agent/linuxbridge_neutron_agent.py:625
2014-02-24 13:14:23.561 6475 DEBUG
neutron.plugins.linuxbridge.agent.linuxbridge_neutron_agent
[req-143cf938-461f-4c2c-b72b-84f67df9a78e None] Delete brqa0fdcdd0-27
network_delete
/opt/stack/neutron/neutron/plugins/linuxbridge/agent/linuxbridge_neutron_agent.py:628
2014-02-24 13:14:23.563 6475 DEBUG neutron.agent.linux.utils
[req-143cf938-461f-4c2c-b72b-84f67df9a78e None] Running command: ['sudo',
'/usr/local/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'link',
'show', 'dev', 'brqa0fdcdd0-27'] create_process
/opt/stack/neutron/neutron/agent/linux/utils.py:48
2014-02-24 13:14:23.725 6475 DEBUG neutron.agent.linux.utils
[req-143cf938-461f-4c2c-b72b-84f67df9a78e None]
Command: ['sudo', '/usr/local/bin/neutron-rootwrap',
'/etc/neutron/rootwrap.conf', 'ip', 'link', 'set', 'brqa0fdcdd0-27', 'down']
Exit code: 0
Stdout: ''
Stderr: '' execute /opt/stack/neutron/neutron/agent/linux/utils.py:74
2014-02-24 13:14:23.726 6475 DEBUG neutron.agent.linux.utils
[req-143cf938-461f-4c2c-b72b-84f67df9a78e None] Running command: ['sudo',
'/usr/local/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'brctl',
'delbr', 'brqa0fdcdd0-27'] create_process
/opt/stack/neutron/neutron/agent/linux/utils.py:48
2014-02-24 13:14:24.081 6475 DEBUG neutron.agent.linux.utils
[req-143cf938-461f-4c2c-b72b-84f67df9a78e None]
Command: ['sudo', '/usr/local/bin/neutron-rootwrap',
'/etc/neutron/rootwrap.conf', 'ip', 'link', 'show', 'dev', 'brqa0fdcdd0-27']
Exit code: 0
Stdout: '156: brqa0fdcdd0-27: <BROADCAST,MULTICAST> mtu 1500 qdisc noqueue
state DOWN \n link/ether 00:00:00:00:00:00 brd ff:ff:ff:ff:ff:ff\n'
Stderr: '' execute /opt/stack/neutron/neutron/agent/linux/utils.py:74
2014-02-24 13:14:24.082 6475 DEBUG neutron.agent.linux.utils
[req-143cf938-461f-4c2c-b72b-84f67df9a78e None] Running command: ['sudo',
'/usr/local/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'link',
'show', 'dev', 'brqa0fdcdd0-27'] create_process
/opt/stack/neutron/neutron/agent/linux/utils.py:48
2014-02-24 13:14:24.126 6475 DEBUG neutron.agent.linux.utils
[req-143cf938-461f-4c2c-b72b-84f67df9a78e None]
Command: ['sudo', '/usr/local/bin/neutron-rootwrap',
'/etc/neutron/rootwrap.conf', 'brctl', 'delbr', 'brqa0fdcdd0-27']
Exit code: 0
Stdout: ''
Stderr: '' execute /opt/stack/neutron/neutron/agent/linux/utils.py:74
2014-02-24 13:14:24.127 6475 DEBUG
neutron.plugins.linuxbridge.agent.linuxbridge_neutron_agent
[req-143cf938-461f-4c2c-b72b-84f67df9a78e None] Done deleting bridge
brqa0fdcdd0-27 delete_vlan_bridge
/opt/stack/neutron/neutron/plugins/linuxbridge/agent/linuxbridge_neutron_agent.py:447
2014-02-24 13:14:24.128 6475 DEBUG
neutron.plugins.linuxbridge.agent.linuxbridge_neutron_agent
[req-143cf938-461f-4c2c-b72b-84f67df9a78e None] Loop iteration exceeded
interval (2 vs. 2.8396191597)! daemon_loop
/opt/stack/neutron/neutron/plugins/linuxbridge/agent/linuxbridge_neutron_agent.py:976
2014-02-24 13:14:24.350 6475 DEBUG neutron.agent.linux.utils
[req-143cf938-461f-4c2c-b72b-84f67df9a78e None]
Command: ['sudo', '/usr/local/bin/neutron-rootwrap',
'/etc/neutron/rootwrap.conf', 'ip', 'link', 'show', 'dev', 'brqa0fdcdd0-27']
Exit code: 1
Stdout: ''
Stderr: 'Device "brqa0fdcdd0-27" does not exist.\n' execute
/opt/stack/neutron/neutron/agent/linux/utils.py:74
2014-02-24 13:14:24.351 6475 ERROR neutron.openstack.common.rpc.amqp
[req-143cf938-461f-4c2c-b72b-84f67df9a78e None] Exception during message
handling
2014-02-24 13:14:24.351 6475 TRACE neutron.openstack.common.rpc.amqp
Traceback (most recent call last):
2014-02-24 13:14:24.351 6475 TRACE neutron.openstack.common.rpc.amqp File
"/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py", line 462, in
_process_data
2014-02-24 13:14:24.351 6475 TRACE neutron.openstack.common.rpc.amqp
**args)
2014-02-24 13:14:24.351 6475 TRACE neutron.openstack.common.rpc.amqp File
"/opt/stack/neutron/neutron/openstack/common/rpc/dispatcher.py", line 172, in
dispatch
2014-02-24 13:14:24.351 6475 TRACE neutron.openstack.common.rpc.amqp
result = getattr(proxyobj, method)(ctxt, **kwargs)
2014-02-24 13:14:24.351 6475 TRACE neutron.openstack.common.rpc.amqp File
"/opt/stack/neutron/neutron/plugins/linuxbridge/agent/linuxbridge_neutron_agent.py",
line 629, in network_delete
2014-02-24 13:14:24.351 6475 TRACE neutron.openstack.common.rpc.amqp
self.agent.br_mgr.delete_vlan_bridge(bridge_name)
2014-02-24 13:14:24.351 6475 TRACE neutron.openstack.common.rpc.amqp File
"/opt/stack/neutron/neutron/plugins/linuxbridge/agent/linuxbridge_neutron_agent.py",
line 422, in delete_vlan_bridge
2014-02-24 13:14:24.351 6475 TRACE neutron.openstack.common.rpc.amqp for
interface in interfaces_on_bridge:
2014-02-24 13:14:24.351 6475 TRACE neutron.openstack.common.rpc.amqp
TypeError: 'NoneType' object is not iterable
To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1284311/+subscriptions
--
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to : [email protected]
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help : https://help.launchpad.net/ListHelp
