Table of Contents
OpenStack ODL Debug
OVSDB Integration
No Router Iface, l3, dhcp not working
neutron/server.log
2014-11-28 11:19:30.189 3378 DEBUG routes.middleware [-] Match dict: {'action': u'create', 'controller': <wsgify at 65954256 wrapping <function resource at 0x3e628c0>>, 'format': u'json'} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:103
2014-11-28 11:19:30.190 3378 DEBUG neutron.openstack.common.rpc.amqp [req-3040047f-2862-43d1-91b7-5762f50d313d None] Sending network.create.start on notifications.info notify /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/amqp.py:622
2014-11-28 11:19:30.190 3378 DEBUG neutron.openstack.common.rpc.amqp [req-3040047f-2862-43d1-91b7-5762f50d313d None] UNIQUE_ID is e7f544916c6744cd8de8dd09c0c9a94c. _add_unique_id /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/amqp.py:342
2014-11-28 11:19:30.194 3378 DEBUG neutron.api.v2.base [req-3040047f-2862-43d1-91b7-5762f50d313d None] Request body: {u'network': {u'name': u'test-net', u'admin_state_up': True}} prepare_request_body /usr/lib/python2.7/site-packages/neutron/api/v2/base.py:590
2014-11-28 11:19:30.343 3378 DEBUG neutron.plugins.ml2.drivers.type_gre [req-3040047f-2862-43d1-91b7-5762f50d313d None] Allocating gre tunnel id 2 allocate_tenant_segment /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/type_gre.py:103
2014-11-28 11:19:30.364 3378 INFO neutron.plugins.ml2.db [req-3040047f-2862-43d1-91b7-5762f50d313d None] Added segment e2fd6c27-70b8-4bb1-bc89-f65b214c621e of type gre for network e1d51a62-2fd0-4b95-a6e2-54c858e5b263
2014-11-28 11:19:30.379 3378 DEBUG neutron.openstack.common.lockutils [req-3040047f-2862-43d1-91b7-5762f50d313d None] Got semaphore "odl-sync-full" lock /usr/lib/python2.7/site-packages/neutron/openstack/common/lockutils.py:168
2014-11-28 11:19:30.379 3378 DEBUG neutron.openstack.common.lockutils [req-3040047f-2862-43d1-91b7-5762f50d313d None] Got semaphore / lock "sync_full" inner /usr/lib/python2.7/site-packages/neutron/openstack/common/lockutils.py:248
2014-11-28 11:19:30.419 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending URL (http://10.10.11.4:8080/controller/nb/v2/neutron/networks/04f88f1f-6fdd-484e-892c-99a09beacbdb) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:312
2014-11-28 11:19:30.419 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending JSON (None) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:313
2014-11-28 11:19:30.420 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:19:32.237 3378 DEBUG urllib3.connectionpool [-] "GET /controller/nb/v2/neutron/networks?limit=1 HTTP/1.1" 200 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:19:32.239 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:19:32.249 3378 DEBUG urllib3.connectionpool [-] "GET /controller/nb/v2/neutron/networks/04f88f1f-6fdd-484e-892c-99a09beacbdb HTTP/1.1" 404 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:19:32.250 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending URL (http://10.10.11.4:8080/controller/nb/v2/neutron/networks/e1d51a62-2fd0-4b95-a6e2-54c858e5b263) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:312
2014-11-28 11:19:32.250 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending JSON (None) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:313
2014-11-28 11:19:32.251 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:19:32.262 3378 DEBUG urllib3.connectionpool [-] "GET /controller/nb/v2/neutron/networks/e1d51a62-2fd0-4b95-a6e2-54c858e5b263 HTTP/1.1" 404 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:19:32.263 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending URL (http://10.10.11.4:8080/controller/nb/v2/neutron/networks) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:312
2014-11-28 11:19:32.264 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending JSON ({'networks': [{'router:external': False, 'name': u'admin-net', 'provider:physical_network': None, 'admin_state_up': True, 'tenant_id': u'8375014457084665b46e960adc939012', 'provider:network_type': u'gre', 'shared': False, 'id': u'04f88f1f-6fdd-484e-892c-99a09beacbdb', 'provider:segmentation_id': 1L}, {'router:external': False, 'name': u'test-net', 'provider:physical_network': None, 'admin_state_up': True, 'tenant_id': u'8375014457084665b46e960adc939012', 'provider:network_type': u'gre', 'shared': False, 'id': u'e1d51a62-2fd0-4b95-a6e2-54c858e5b263', 'provider:segmentation_id': 2L}]}) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:313
2014-11-28 11:19:32.265 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:19:32.435 3378 DEBUG urllib3.connectionpool [-] "POST /controller/nb/v2/neutron/networks HTTP/1.1" 201 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:19:32.443 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending URL (http://10.10.11.4:8080/controller/nb/v2/neutron/subnets/a6d8fbe6-7609-4a88-af4c-64d9c62c4dd5) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:312
2014-11-28 11:19:32.443 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending JSON (None) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:313
2014-11-28 11:19:32.445 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:19:32.450 3378 DEBUG urllib3.connectionpool [-] "GET /controller/nb/v2/neutron/subnets/a6d8fbe6-7609-4a88-af4c-64d9c62c4dd5 HTTP/1.1" 404 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:19:32.451 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending URL (http://10.10.11.4:8080/controller/nb/v2/neutron/subnets) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:312
2014-11-28 11:19:32.452 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending JSON ({'subnet': [{'name': u'admin-subnet', 'enable_dhcp': True, 'network_id': u'04f88f1f-6fdd-484e-892c-99a09beacbdb', 'tenant_id': u'8375014457084665b46e960adc939012', 'dns_nameservers': [], 'gateway_ip': u'192.168.1.1', 'ipv6_ra_mode': None, 'allocation_pools': [{'start': u'192.168.1.2', 'end': u'192.168.1.254'}], 'host_routes': [], 'shared': False, 'ip_version': 4L, 'ipv6_address_mode': None, 'cidr': u'192.168.1.0/24', 'id': u'a6d8fbe6-7609-4a88-af4c-64d9c62c4dd5'}]}) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:313
2014-11-28 11:19:32.453 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:19:32.484 3378 DEBUG urllib3.connectionpool [-] "POST /controller/nb/v2/neutron/subnets HTTP/1.1" 201 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:19:32.484 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending URL (http://10.10.11.4:8080/controller/nb/v2/neutron/ports/0a069038-a71a-4a04-a13e-5694f7f546b6) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:312
2014-11-28 11:19:32.485 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending JSON (None) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:313
2014-11-28 11:19:32.486 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:19:32.490 3378 DEBUG urllib3.connectionpool [-] "GET /controller/nb/v2/neutron/ports/0a069038-a71a-4a04-a13e-5694f7f546b6 HTTP/1.1" 404 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:19:32.491 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending URL (http://10.10.11.4:8080/controller/nb/v2/neutron/ports/1121dfce-392b-46bc-9d26-e8a9b8831362) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:312
2014-11-28 11:19:32.491 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending JSON (None) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:313
2014-11-28 11:19:32.492 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:19:32.496 3378 DEBUG urllib3.connectionpool [-] "GET /controller/nb/v2/neutron/ports/1121dfce-392b-46bc-9d26-e8a9b8831362 HTTP/1.1" 404 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:19:32.502 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending URL (http://10.10.11.4:8080/controller/nb/v2/neutron/ports/88b3516a-3ee6-4997-a041-8b8632a3687f) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:312
2014-11-28 11:19:32.503 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending JSON (None) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:313
2014-11-28 11:19:32.504 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:19:32.508 3378 DEBUG urllib3.connectionpool [-] "GET /controller/nb/v2/neutron/ports/88b3516a-3ee6-4997-a041-8b8632a3687f HTTP/1.1" 404 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:19:32.509 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending URL (http://10.10.11.4:8080/controller/nb/v2/neutron/ports/e2878286-6e48-4216-adec-47922a593656) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:312
2014-11-28 11:19:32.509 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending JSON (None) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:313
2014-11-28 11:19:32.510 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:19:32.514 3378 DEBUG urllib3.connectionpool [-] "GET /controller/nb/v2/neutron/ports/e2878286-6e48-4216-adec-47922a593656 HTTP/1.1" 404 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:19:32.520 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending URL (http://10.10.11.4:8080/controller/nb/v2/neutron/ports) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:312
2014-11-28 11:19:32.521 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-3040047f-2862-43d1-91b7-5762f50d313d None] ODL-----> sending JSON ({'ports': [{'binding:host_id': u'devcontroller.localdomain', 'name': u'', 'allowed_address_pairs': [], 'admin_state_up': True, 'network_id': u'04f88f1f-6fdd-484e-892c-99a09beacbdb', 'tenant_id': u'8375014457084665b46e960adc939012', 'extra_dhcp_opts': [], 'binding:vif_details': {u'port_filter': True}, 'binding:vif_type': u'ovs', 'device_owner': u'network:dhcp', 'mac_address': u'FA:16:3E:E8:CC:C5', 'binding:profile': {}, 'binding:vnic_type': u'normal', 'fixed_ips': [{'subnet_id': u'a6d8fbe6-7609-4a88-af4c-64d9c62c4dd5', 'ip_address': u'192.168.1.44'}], 'id': u'0a069038-a71a-4a04-a13e-5694f7f546b6', 'security_groups': [], 'device_id': u'dhcpa67a2221-2380-5b16-9888-acbe88b87895-04f88f1f-6fdd-484e-892c-99a09beacbdb'}, {'binding:host_id': u'devcompute.localdomain', 'name': u'', 'allowed_address_pairs': [], 'admin_state_up': True, 'network_id': u'04f88f1f-6fdd-484e-892c-99a09beacbdb', 'tenant_id': u'8375014457084665b46e960adc939012', 'extra_dhcp_opts': [], 'binding:vif_details': {u'port_filter': True}, 'binding:vif_type': u'ovs', 'device_owner': u'compute:None', 'mac_address': u'FA:16:3E:34:AE:52', 'binding:profile': {}, 'binding:vnic_type': u'normal', 'fixed_ips': [{'subnet_id': u'a6d8fbe6-7609-4a88-af4c-64d9c62c4dd5', 'ip_address': u'192.168.1.45'}], 'id': u'1121dfce-392b-46bc-9d26-e8a9b8831362', 'security_groups': [{'tenant_id': u'8375014457084665b46e960adc939012', 'name': u'default', 'description': u'default', 'security_group_rules': [{'remote_group_id': None, 'direction': u'egress', 'remote_ip_prefix': None, 'protocol': None, 'tenant_id': u'8375014457084665b46e960adc939012', 'port_range_max': None, 'security_group_id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad', 'port_range_min': None, 'ethertype': u'IPv4', 'id': u'34167e29-6cdb-459e-a277-9d73a5ec8d9e'}, {'remote_group_id': None, 'direction': u'egress', 'remote_ip_prefix': None, 'protocol': None, 'tenant_id': u'8375014457084665b46e960adc939012', 'port_range_max': None, 'security_group_id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad', 'port_range_min': None, 'ethertype': u'IPv6', 'id': u'7f292c69-760b-4b3e-a5b9-500cff61c014'}, {'remote_group_id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad', 'direction': u'ingress', 'remote_ip_prefix': None, 'protocol': None, 'tenant_id': u'8375014457084665b46e960adc939012', 'port_range_max': None, 'security_group_id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad', 'port_range_min': None, 'ethertype': u'IPv6', 'id': u'9b0dcd91-dac4-4cde-a7de-39ef27bb9c51'}, {'remote_group_id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad', 'direction': u'ingress', 'remote_ip_prefix': None, 'protocol': None, 'tenant_id': u'8375014457084665b46e960adc939012', 'port_range_max': None, 'security_group_id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad', 'port_range_min': None, 'ethertype': u'IPv4', 'id': u'b1a2ff18-6159-4c7e-983f-648f853a0c2e'}], 'id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad'}], 'device_id': u'3ca9e84c-8eca-46a8-95eb-da2d142a2b7d'}, {'binding:host_id': u'devcontroller.localdomain', 'name': u'', 'allowed_address_pairs': [], 'admin_state_up': True, 'network_id': u'04f88f1f-6fdd-484e-892c-99a09beacbdb', 'tenant_id': u'8375014457084665b46e960adc939012', 'extra_dhcp_opts': [], 'binding:vif_details': {u'port_filter': True}, 'binding:vif_type': u'ovs', 'device_owner': u'network:router_interface', 'mac_address': u'FA:16:3E:8A:4A:7A', 'binding:profile': {}, 'binding:vnic_type': u'normal', 'fixed_ips': [{'subnet_id': u'a6d8fbe6-7609-4a88-af4c-64d9c62c4dd5', 'ip_address': u'192.168.1.1'}], 'id': u'88b3516a-3ee6-4997-a041-8b8632a3687f', 'security_groups': [], 'device_id': u'6bb70a0b-b612-44f5-bb09-4dfb4ecea942'}, {'binding:host_id': u'devcompute.localdomain', 'name': u'', 'allowed_address_pairs': [], 'admin_state_up': True, 'network_id': u'04f88f1f-6fdd-484e-892c-99a09beacbdb', 'tenant_id': u'8375014457084665b46e960adc939012', 'extra_dhcp_opts': [], 'binding:vif_details': {u'port_filter': True}, 'binding:vif_type': u'ovs', 'device_owner': u'compute:None', 'mac_address': u'FA:16:3E:6E:01:8D', 'binding:profile': {}, 'binding:vnic_type': u'normal', 'fixed_ips': [{'subnet_id': u'a6d8fbe6-7609-4a88-af4c-64d9c62c4dd5', 'ip_address': u'192.168.1.46'}], 'id': u'e2878286-6e48-4216-adec-47922a593656', 'security_groups': [{'tenant_id': u'8375014457084665b46e960adc939012', 'name': u'default', 'description': u'default', 'security_group_rules': [{'remote_group_id': None, 'direction': u'egress', 'remote_ip_prefix': None, 'protocol': None, 'tenant_id': u'8375014457084665b46e960adc939012', 'port_range_max': None, 'security_group_id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad', 'port_range_min': None, 'ethertype': u'IPv4', 'id': u'34167e29-6cdb-459e-a277-9d73a5ec8d9e'}, {'remote_group_id': None, 'direction': u'egress', 'remote_ip_prefix': None, 'protocol': None, 'tenant_id': u'8375014457084665b46e960adc939012', 'port_range_max': None, 'security_group_id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad', 'port_range_min': None, 'ethertype': u'IPv6', 'id': u'7f292c69-760b-4b3e-a5b9-500cff61c014'}, {'remote_group_id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad', 'direction': u'ingress', 'remote_ip_prefix': None, 'protocol': None, 'tenant_id': u'8375014457084665b46e960adc939012', 'port_range_max': None, 'security_group_id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad', 'port_range_min': None, 'ethertype': u'IPv6', 'id': u'9b0dcd91-dac4-4cde-a7de-39ef27bb9c51'}, {'remote_group_id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad', 'direction': u'ingress', 'remote_ip_prefix': None, 'protocol': None, 'tenant_id': u'8375014457084665b46e960adc939012', 'port_range_max': None, 'security_group_id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad', 'port_range_min': None, 'ethertype': u'IPv4', 'id': u'b1a2ff18-6159-4c7e-983f-648f853a0c2e'}], 'id': u'ae80d6ce-5833-43ab-9b41-bf60860a51ad'}], 'device_id': u'a5c4dd6c-303d-4559-973e-27652d1acc5c'}]}) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:313
2014-11-28 11:19:32.522 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:19:32.622 3378 DEBUG urllib3.connectionpool [-] "POST /controller/nb/v2/neutron/ports HTTP/1.1" 201 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:19:32.623 3378 DEBUG neutron.openstack.common.lockutils [req-3040047f-2862-43d1-91b7-5762f50d313d None] Semaphore / lock released "sync_full" inner /usr/lib/python2.7/site-packages/neutron/openstack/common/lockutils.py:252
2014-11-28 11:19:32.624 3378 DEBUG neutron.openstack.common.rpc.amqp [req-3040047f-2862-43d1-91b7-5762f50d313d None] Sending network.create.end on notifications.info notify /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/amqp.py:622
2014-11-28 11:19:32.624 3378 DEBUG neutron.openstack.common.rpc.amqp [req-3040047f-2862-43d1-91b7-5762f50d313d None] UNIQUE_ID is dbeff673e1f748179897d520bfe1489d. _add_unique_id /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/amqp.py:342
2014-11-28 11:19:32.636 3378 INFO neutron.wsgi [req-3040047f-2862-43d1-91b7-5762f50d313d None] 192.168.201.29 - - [28/Nov/2014 11:19:32] "POST /v2.0/networks.json HTTP/1.1" 201 497 2.629854
2014-11-28 11:19:34.114 3378 DEBUG neutron.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_context_request_id': u'req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8', u'_context_read_deleted': u'no', u'_context_user_name': None, u'_context_project_name': None, u'namespace': None, u'_context_tenant_id': None, u'args': {u'agent_state': {u'agent_state': {u'topic': u'l3_agent', u'binary': u'neutron-l3-agent', u'host': u'devcontroller.localdomain', u'agent_type': u'L3 agent', u'configurations': {u'router_id': u'', u'gateway_external_network_id': u'', u'handle_internal_only_routers': True, u'use_namespaces': True, u'routers': 0, u'interfaces': 0, u'floating_ips': 0, u'interface_driver': u'neutron.agent.linux.interface.OVSInterfaceDriver', u'ex_gw_ports': 0}}}, u'time': u'2014-11-28T10:19:34.110852'}, u'_context_tenant': None, u'_unique_id': u'e9d4ba6e1272483a81df2400dd56d054', u'_context_is_admin': True, u'version': u'1.0', u'_context_timestamp': u'2014-11-27 17:23:07.710676', u'_context_tenant_name': None, u'_context_user': None, u'_context_user_id': None, u'method': u'report_state', u'_context_project_id': None} _safe_log /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/common.py:280
2014-11-28 11:19:34.115 3378 DEBUG neutron.openstack.common.rpc.amqp [-] unpacked context: {'project_name': None, 'user_id': None, 'roles': [u'admin'], 'tenant_id': None, 'timestamp': u'2014-11-27 17:23:07.710676', 'is_admin': True, 'read_deleted': u'no', 'request_id': u'req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8', 'tenant_name': None, 'project_id': None, 'user_name': None, 'tenant': None, 'user': None} _safe_log /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/common.py:280
2014-11-28 11:19:34.116 3378 DEBUG neutron.context [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] Arguments dropped when creating context: {'project_name': None, 'tenant': None} __init__ /usr/lib/python2.7/site-packages/neutron/context.py:84
Headline
[root@devcontroller fedora]# tail -n200 /var/log/neutron/server.log
2014-11-28 11:38:36.017 3378 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 65942672 wrapping <function resource at 0x3ee26e0>>, 'format': u'json'} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:103
2014-11-28 11:38:36.036 3378 INFO neutron.wsgi [req-56670678-4d33-4e0c-9453-b89aacd158e5 None] 192.168.201.29 - - [28/Nov/2014 11:38:36] "GET //v2.0/subnets.json HTTP/1.1" 200 954 0.020633
2014-11-28 11:38:36.050 3378 INFO neutron.wsgi [req-56670678-4d33-4e0c-9453-b89aacd158e5 None] (3378) accepted ('192.168.201.29', 35034)
2014-11-28 11:38:36.063 3378 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:666
2014-11-28 11:38:36.063 3378 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:725
2014-11-28 11:38:36.064 3378 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1124
2014-11-28 11:38:36.064 3378 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1234
2014-11-28 11:38:36.065 3378 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: acb62c98a2cb4b379bca82ea936314a9 with project_id : 8375014457084665b46e960adc939012 and roles: admin _build_user_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1021
2014-11-28 11:38:36.066 3378 DEBUG routes.middleware [-] Matched PUT /routers/634e45bc-f246-49c7-b544-7e7bd8f2dcd3/add_router_interface.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:100
2014-11-28 11:38:36.066 3378 DEBUG routes.middleware [-] Route path: '/routers/:(id)/add_router_interface.:(format)', defaults: {'action': u'add_router_interface', 'controller': <wsgify at 66026000 wrapping <function resource at 0x3ee2ed8>>} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:102
2014-11-28 11:38:36.066 3378 DEBUG routes.middleware [-] Match dict: {'action': u'add_router_interface', 'controller': <wsgify at 66026000 wrapping <function resource at 0x3ee2ed8>>, 'id': u'634e45bc-f246-49c7-b544-7e7bd8f2dcd3', 'format': u'json'} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:103
2014-11-28 11:38:36.104 3378 DEBUG neutron.db.db_base_plugin_v2 [req-8403343c-189e-476d-ae37-6e0d827c9c58 None] Generated mac for network e1d51a62-2fd0-4b95-a6e2-54c858e5b263 is fa:16:3e:f5:1c:70 _generate_mac /usr/lib/python2.7/site-packages/neutron/db/db_base_plugin_v2.py:321
2014-11-28 11:38:36.128 3378 DEBUG neutron.db.db_base_plugin_v2 [req-8403343c-189e-476d-ae37-6e0d827c9c58 None] Allocated IP 10.2.2.1 (e1d51a62-2fd0-4b95-a6e2-54c858e5b263/f543c5c7-ddc3-423b-b296-35c416abf5e1/cb17afc0-9b8e-430e-963c-0a94eb637080) create_port /usr/lib/python2.7/site-packages/neutron/db/db_base_plugin_v2.py:1399
2014-11-28 11:38:36.311 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-8403343c-189e-476d-ae37-6e0d827c9c58 None] ODL-----> sending URL (http://10.10.11.4:8080/controller/nb/v2/neutron/ports) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:312
2014-11-28 11:38:36.311 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-8403343c-189e-476d-ae37-6e0d827c9c58 None] ODL-----> sending JSON ({'port': {'binding:host_id': '', 'name': '', 'allowed_address_pairs': [], 'admin_state_up': True, 'network_id': u'e1d51a62-2fd0-4b95-a6e2-54c858e5b263', 'tenant_id': u'8375014457084665b46e960adc939012', 'binding:vif_details': {}, 'binding:vnic_type': 'normal', 'binding:vif_type': 'unbound', 'device_owner': 'network:router_interface', 'mac_address': 'FA:16:3E:F5:1C:70', 'binding:profile': {}, 'fixed_ips': [{'subnet_id': u'f543c5c7-ddc3-423b-b296-35c416abf5e1', 'ip_address': u'10.2.2.1'}], 'id': 'cb17afc0-9b8e-430e-963c-0a94eb637080', 'security_groups': [], 'device_id': u'634e45bc-f246-49c7-b544-7e7bd8f2dcd3'}}) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:313
2014-11-28 11:38:36.313 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:38:36.320 3378 DEBUG urllib3.connectionpool [-] "POST /controller/nb/v2/neutron/ports HTTP/1.1" 201 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:38:36.429 3378 DEBUG neutron.scheduler.l3_agent_scheduler [req-8403343c-189e-476d-ae37-6e0d827c9c58 None] Router 634e45bc-f246-49c7-b544-7e7bd8f2dcd3 is scheduled to L3 agent 78de7d4b-55df-4116-89dd-16149145d2eb bind_router /usr/lib/python2.7/site-packages/neutron/scheduler/l3_agent_scheduler.py:158
2014-11-28 11:38:36.471 3378 DEBUG neutron.api.rpc.agentnotifiers.l3_rpc_agent_api [req-8403343c-189e-476d-ae37-6e0d827c9c58 None] Notify agent at l3_agent.devcontroller.localdomain the message routers_updated _agent_notification /usr/lib/python2.7/site-packages/neutron/api/rpc/agentnotifiers/l3_rpc_agent_api.py:62
2014-11-28 11:38:36.471 3378 DEBUG neutron.openstack.common.rpc.amqp [req-8403343c-189e-476d-ae37-6e0d827c9c58 None] Making asynchronous cast on l3_agent.devcontroller.localdomain... cast /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/amqp.py:583
2014-11-28 11:38:36.471 3378 DEBUG neutron.openstack.common.rpc.amqp [req-8403343c-189e-476d-ae37-6e0d827c9c58 None] UNIQUE_ID is ff99a51bd0e0406ca20cf794cfcb7fb4. _add_unique_id /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/amqp.py:342
2014-11-28 11:38:36.483 3378 DEBUG neutron.openstack.common.rpc.amqp [req-8403343c-189e-476d-ae37-6e0d827c9c58 None] Sending router.interface.create on notifications.info notify /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/amqp.py:622
2014-11-28 11:38:36.483 3378 DEBUG neutron.openstack.common.rpc.amqp [req-8403343c-189e-476d-ae37-6e0d827c9c58 None] UNIQUE_ID is fa2fc7fe719e4da297bf19b681bc75b9. _add_unique_id /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/amqp.py:342
2014-11-28 11:38:36.488 3378 INFO neutron.wsgi [req-8403343c-189e-476d-ae37-6e0d827c9c58 None] 192.168.201.29 - - [28/Nov/2014 11:38:36] "PUT //v2.0/routers/634e45bc-f246-49c7-b544-7e7bd8f2dcd3/add_router_interface.json HTTP/1.1" 200 389 0.425251
2014-11-28 11:38:36.489 3378 INFO neutron.wsgi [req-8403343c-189e-476d-ae37-6e0d827c9c58 None] (3378) accepted ('192.168.201.29', 35036)
2014-11-28 11:38:36.489 3378 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:666
2014-11-28 11:38:36.489 3378 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:725
2014-11-28 11:38:36.490 3378 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1124
2014-11-28 11:38:36.490 3378 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1234
2014-11-28 11:38:36.490 3378 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: acb62c98a2cb4b379bca82ea936314a9 with project_id : 8375014457084665b46e960adc939012 and roles: admin _build_user_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1021
2014-11-28 11:38:36.491 3378 DEBUG routes.middleware [-] No route matched for GET /ports/cb17afc0-9b8e-430e-963c-0a94eb637080.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:97
2014-11-28 11:38:36.491 3378 DEBUG routes.middleware [-] Matched GET /ports/cb17afc0-9b8e-430e-963c-0a94eb637080.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:100
2014-11-28 11:38:36.492 3378 DEBUG routes.middleware [-] Route path: '/ports/{id}{.format}', defaults: {'action': u'show', 'controller': <wsgify at 65957776 wrapping <function resource at 0x3ee2488>>} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:102
2014-11-28 11:38:36.492 3378 DEBUG routes.middleware [-] Match dict: {'action': u'show', 'controller': <wsgify at 65957776 wrapping <function resource at 0x3ee2488>>, 'id': u'cb17afc0-9b8e-430e-963c-0a94eb637080', 'format': u'json'} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:103
2014-11-28 11:38:36.522 3378 INFO neutron.wsgi [req-aa3fa031-f435-4720-8049-52cc3bb022bd None] 192.168.201.29 - - [28/Nov/2014 11:38:36] "GET //v2.0/ports/cb17afc0-9b8e-430e-963c-0a94eb637080.json HTTP/1.1" 200 842 0.032808
2014-11-28 11:38:36.560 3378 INFO neutron.wsgi [req-aa3fa031-f435-4720-8049-52cc3bb022bd None] (3378) accepted ('192.168.201.29', 35037)
2014-11-28 11:38:36.561 3378 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:666
2014-11-28 11:38:36.561 3378 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:725
2014-11-28 11:38:36.562 3378 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1124
2014-11-28 11:38:36.562 3378 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1234
2014-11-28 11:38:36.563 3378 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: acb62c98a2cb4b379bca82ea936314a9 with project_id : 8375014457084665b46e960adc939012 and roles: admin _build_user_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1021
2014-11-28 11:38:36.564 3378 DEBUG routes.middleware [-] Matched GET /routers/634e45bc-f246-49c7-b544-7e7bd8f2dcd3.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:100
2014-11-28 11:38:36.565 3378 DEBUG routes.middleware [-] Route path: '/routers/:(id).:(format)', defaults: {'action': u'show', 'controller': <wsgify at 66026000 wrapping <function resource at 0x3ee2ed8>>} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:102
2014-11-28 11:38:36.565 3378 DEBUG routes.middleware [-] Match dict: {'action': u'show', 'controller': <wsgify at 66026000 wrapping <function resource at 0x3ee2ed8>>, 'id': u'634e45bc-f246-49c7-b544-7e7bd8f2dcd3', 'format': u'json'} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:103
2014-11-28 11:38:36.583 3378 INFO neutron.wsgi [req-e6555a10-5ea9-4a00-89fb-603783656c05 None] 192.168.201.29 - - [28/Nov/2014 11:38:36] "GET //v2.0/routers/634e45bc-f246-49c7-b544-7e7bd8f2dcd3.json HTTP/1.1" 200 409 0.021874
2014-11-28 11:38:36.583 3378 INFO neutron.wsgi [req-e6555a10-5ea9-4a00-89fb-603783656c05 None] (3378) accepted ('192.168.201.29', 35038)
2014-11-28 11:38:36.584 3378 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:666
2014-11-28 11:38:36.584 3378 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:725
2014-11-28 11:38:36.584 3378 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1124
2014-11-28 11:38:36.584 3378 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1234
2014-11-28 11:38:36.585 3378 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: acb62c98a2cb4b379bca82ea936314a9 with project_id : 8375014457084665b46e960adc939012 and roles: admin _build_user_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1021
2014-11-28 11:38:36.585 3378 DEBUG routes.middleware [-] No route matched for GET /ports.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:97
2014-11-28 11:38:36.585 3378 DEBUG routes.middleware [-] Matched GET /ports.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:100
2014-11-28 11:38:36.585 3378 DEBUG routes.middleware [-] Route path: '/ports{.format}', defaults: {'action': u'index', 'controller': <wsgify at 65957776 wrapping <function resource at 0x3ee2488>>} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:102
2014-11-28 11:38:36.586 3378 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 65957776 wrapping <function resource at 0x3ee2488>>, 'format': u'json'} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:103
2014-11-28 11:38:36.600 3378 INFO neutron.wsgi [req-a9fd19c6-59a9-47eb-b9f8-0cc83932f4ce None] 192.168.201.29 - - [28/Nov/2014 11:38:36] "GET //v2.0/ports.json?device_id=634e45bc-f246-49c7-b544-7e7bd8f2dcd3 HTTP/1.1" 200 845 0.016001
2014-11-28 11:38:39.147 3378 DEBUG neutron.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_msg_id': u'2743bd1fc7964e6489f4280ead0a8341', u'args': {u'host': u'devcontroller.localdomain', u'router_ids': [u'634e45bc-f246-49c7-b544-7e7bd8f2dcd3']}, u'_context_read_deleted': u'no', u'_context_user_name': None, u'_context_request_id': u'req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8', u'_reply_q': u'reply_bb71473f306f46309dabc4d1c460d4e7', u'_context_tenant_id': None, u'_context_tenant_name': None, u'_context_tenant': None, u'_unique_id': u'fd1b92e7c8dd422bb061ec69255a318e', u'_context_project_name': None, u'_context_is_admin': True, u'version': u'1.0', u'_context_project_id': None, u'_context_timestamp': u'2014-11-27 17:23:07.710676', u'_context_user': None, u'_context_user_id': None, u'namespace': None, u'method': u'sync_routers'} _safe_log /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/common.py:280
2014-11-28 11:38:39.148 3378 DEBUG neutron.openstack.common.rpc.amqp [-] unpacked context: {'project_name': None, 'user_id': None, 'roles': [u'admin'], 'tenant_id': None, 'timestamp': u'2014-11-27 17:23:07.710676', 'is_admin': True, 'read_deleted': u'no', 'request_id': u'req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8', 'tenant_name': None, 'project_id': None, 'user_name': None, 'tenant': None, 'user': None} _safe_log /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/common.py:280
2014-11-28 11:38:39.149 3378 DEBUG neutron.context [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] Arguments dropped when creating context: {'project_name': None, 'tenant': None} __init__ /usr/lib/python2.7/site-packages/neutron/context.py:84
2014-11-28 11:38:39.157 3378 DEBUG neutron.scheduler.l3_agent_scheduler [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] Router 634e45bc-f246-49c7-b544-7e7bd8f2dcd3 has already been hosted by L3 agent 78de7d4b-55df-4116-89dd-16149145d2eb auto_schedule_routers /usr/lib/python2.7/site-packages/neutron/scheduler/l3_agent_scheduler.py:81
2014-11-28 11:38:39.218 3378 DEBUG neutron.db.l3_rpc_base [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] Checking router: 634e45bc-f246-49c7-b544-7e7bd8f2dcd3 for host: devcontroller.localdomain _ensure_host_set_on_ports /usr/lib/python2.7/site-packages/neutron/db/l3_rpc_base.py:71
2014-11-28 11:38:39.463 3378 DEBUG neutron.plugins.ml2.managers [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] Attempting to bind port cb17afc0-9b8e-430e-963c-0a94eb637080 on host devcontroller.localdomain for vnic_type normal with profile {} bind_port /usr/lib/python2.7/site-packages/neutron/plugins/ml2/managers.py:455
2014-11-28 11:38:39.463 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] Attempting to bind port cb17afc0-9b8e-430e-963c-0a94eb637080 on network e1d51a62-2fd0-4b95-a6e2-54c858e5b263 bind_port /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:327
2014-11-28 11:38:39.463 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] Bound using segment: {'segmentation_id': 2L, 'physical_network': None, 'id': u'e2fd6c27-70b8-4bb1-bc89-f65b214c621e', 'network_type': u'gre'} bind_port /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:334
2014-11-28 11:38:39.464 3378 DEBUG neutron.plugins.ml2.managers [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] Bound port: cb17afc0-9b8e-430e-963c-0a94eb637080, host: devcontroller.localdomain, vnic_type: normal, profile: {}driver: opendaylight, vif_type: ovs, vif_details: {"port_filter": true}, segment: e2fd6c27-70b8-4bb1-bc89-f65b214c621e bind_port /usr/lib/python2.7/site-packages/neutron/plugins/ml2/managers.py:474
2014-11-28 11:38:39.617 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] ODL-----> sending URL (http://10.10.11.4:8080/controller/nb/v2/neutron/ports/cb17afc0-9b8e-430e-963c-0a94eb637080) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:312
2014-11-28 11:38:39.617 3378 DEBUG neutron.plugins.ml2.drivers.mechanism_odl [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] ODL-----> sending JSON ({'port': {'binding:host_id': u'devcontroller.localdomain', 'name': u'', 'allowed_address_pairs': [], 'admin_state_up': True, 'extra_dhcp_opts': [], 'binding:vnic_type': u'normal', 'binding:vif_type': 'ovs', 'device_owner': u'network:router_interface', 'binding:profile': {}, 'binding:vif_details': {u'port_filter': True}, 'security_groups': [], 'device_id': u'634e45bc-f246-49c7-b544-7e7bd8f2dcd3'}}) <-----ODL sendjson /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/mechanism_odl.py:313
2014-11-28 11:38:39.618 3378 INFO urllib3.connectionpool [-] Starting new HTTP connection (1): 10.10.11.4
2014-11-28 11:38:39.625 3378 DEBUG urllib3.connectionpool [-] "PUT /controller/nb/v2/neutron/ports/cb17afc0-9b8e-430e-963c-0a94eb637080 HTTP/1.1" 200 None _make_request /usr/lib/python2.7/site-packages/urllib3/connectionpool.py:357
2014-11-28 11:38:39.626 3378 DEBUG neutron.openstack.common.rpc.amqp [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] Making asynchronous fanout cast... fanout_cast /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/amqp.py:592
2014-11-28 11:38:39.626 3378 DEBUG neutron.openstack.common.rpc.amqp [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] UNIQUE_ID is 27765d4620df47b7b85d198b5f65f006. _add_unique_id /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/amqp.py:342
2014-11-28 11:38:39.629 3378 DEBUG neutron.db.l3_rpc_base [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] Routers returned to l3 agent:
[
{
"status": "ACTIVE",
"external_gateway_info": null,
"name": "test-router",
"gw_port_id": null,
"admin_state_up": true,
"tenant_id": "8375014457084665b46e960adc939012",
"_interfaces": [
{
"status": "DOWN",
"binding:host_id": "",
"allowed_address_pairs": [],
"extra_dhcp_opts": [],
"device_owner": "network:router_interface",
"binding:profile": {},
"fixed_ips": [
{
"subnet_id": "f543c5c7-ddc3-423b-b296-35c416abf5e1",
"ip_address": "10.2.2.1"
}
],
"id": "cb17afc0-9b8e-430e-963c-0a94eb637080",
"security_groups": [],
"device_id": "634e45bc-f246-49c7-b544-7e7bd8f2dcd3",
"subnet": {
"cidr": "10.2.2.0/24",
"gateway_ip": "10.2.2.1",
"id": "f543c5c7-ddc3-423b-b296-35c416abf5e1"
},
"name": "",
"admin_state_up": true,
"network_id": "e1d51a62-2fd0-4b95-a6e2-54c858e5b263",
"tenant_id": "8375014457084665b46e960adc939012",
"binding:vif_details": {},
"binding:vnic_type": "normal",
"binding:vif_type": "unbound",
"mac_address": "fa:16:3e:f5:1c:70"
}
],
"routes": [],
"id": "634e45bc-f246-49c7-b544-7e7bd8f2dcd3"
}
] sync_routers /usr/lib/python2.7/site-packages/neutron/db/l3_rpc_base.py:65
2014-11-28 11:38:39.629 3378 DEBUG neutron.openstack.common.rpc.amqp [-] UNIQUE_ID is f99c27182766451aa5a59ae0515f99cf. _add_unique_id /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/amqp.py:342
2014-11-28 11:38:39.640 3378 DEBUG neutron.openstack.common.rpc.amqp [-] UNIQUE_ID is 45057e738d6b4e3f908a5894683fe735. _add_unique_id /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/amqp.py:342
2014-11-28 11:38:55.359 3378 INFO neutron.wsgi [-] (3378) accepted ('10.10.11.3', 35609)
2014-11-28 11:38:55.360 3378 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:666
2014-11-28 11:38:55.360 3378 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:725
2014-11-28 11:38:55.361 3378 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1124
2014-11-28 11:38:55.361 3378 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1234
2014-11-28 11:38:55.361 3378 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: ecb59e3524644f0db90e64175cb20d76 with project_id : 36f745b5144842bca10af053071c6cfd and roles: admin _build_user_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1021
2014-11-28 11:38:55.362 3378 DEBUG routes.middleware [-] No route matched for GET /ports.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:97
2014-11-28 11:38:55.362 3378 DEBUG routes.middleware [-] Matched GET /ports.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:100
2014-11-28 11:38:55.362 3378 DEBUG routes.middleware [-] Route path: '/ports{.format}', defaults: {'action': u'index', 'controller': <wsgify at 65957776 wrapping <function resource at 0x3ee2488>>} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:102
2014-11-28 11:38:55.362 3378 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 65957776 wrapping <function resource at 0x3ee2488>>, 'format': u'json'} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:103
2014-11-28 11:38:55.371 3378 INFO neutron.wsgi [req-78d87523-32ce-4416-9f05-dd5d773197f9 None] 10.10.11.3 - - [28/Nov/2014 11:38:55] "GET /v2.0/ports.json?tenant_id=8375014457084665b46e960adc939012&device_id=a5c4dd6c-303d-4559-973e-27652d1acc5c HTTP/1.1" 200 914 0.010886
2014-11-28 11:38:55.374 3378 INFO neutron.wsgi [req-78d87523-32ce-4416-9f05-dd5d773197f9 None] (3378) accepted ('10.10.11.3', 35610)
2014-11-28 11:38:55.375 3378 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:666
2014-11-28 11:38:55.375 3378 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:725
2014-11-28 11:38:55.375 3378 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1124
2014-11-28 11:38:55.375 3378 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1234
2014-11-28 11:38:55.376 3378 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: ecb59e3524644f0db90e64175cb20d76 with project_id : 36f745b5144842bca10af053071c6cfd and roles: admin _build_user_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1021
2014-11-28 11:38:55.376 3378 DEBUG routes.middleware [-] No route matched for GET /networks.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:97
2014-11-28 11:38:55.376 3378 DEBUG routes.middleware [-] Matched GET /networks.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:100
2014-11-28 11:38:55.376 3378 DEBUG routes.middleware [-] Route path: '/networks{.format}', defaults: {'action': u'index', 'controller': <wsgify at 65954256 wrapping <function resource at 0x3e628c0>>} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:102
2014-11-28 11:38:55.377 3378 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 65954256 wrapping <function resource at 0x3e628c0>>, 'format': u'json'} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:103
2014-11-28 11:38:55.386 3378 INFO neutron.wsgi [req-f0bc039a-8e19-41cc-a8dd-f58ab2c473f5 None] 10.10.11.3 - - [28/Nov/2014 11:38:55] "GET /v2.0/networks.json?id=04f88f1f-6fdd-484e-892c-99a09beacbdb HTTP/1.1" 200 560 0.011404
2014-11-28 11:38:55.388 3378 INFO neutron.wsgi [req-f0bc039a-8e19-41cc-a8dd-f58ab2c473f5 None] (3378) accepted ('10.10.11.3', 35611)
2014-11-28 11:38:55.389 3378 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:666
2014-11-28 11:38:55.389 3378 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:725
2014-11-28 11:38:55.390 3378 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1124
2014-11-28 11:38:55.390 3378 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1234
2014-11-28 11:38:55.390 3378 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: ecb59e3524644f0db90e64175cb20d76 with project_id : 36f745b5144842bca10af053071c6cfd and roles: admin _build_user_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1021
2014-11-28 11:38:55.391 3378 DEBUG routes.middleware [-] Matched GET /floatingips.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:100
2014-11-28 11:38:55.391 3378 DEBUG routes.middleware [-] Route path: '/floatingips.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 66028880 wrapping <function resource at 0x3ee2f50>>} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:102
2014-11-28 11:38:55.392 3378 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 66028880 wrapping <function resource at 0x3ee2f50>>, 'format': u'json'} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:103
2014-11-28 11:38:55.395 3378 INFO neutron.wsgi [req-c878e7bf-e007-403b-bf1d-f201cd10aaf9 None] 10.10.11.3 - - [28/Nov/2014 11:38:55] "GET /v2.0/floatingips.json?fixed_ip_address=192.168.1.46&port_id=e2878286-6e48-4216-adec-47922a593656 HTTP/1.1" 200 208 0.005445
2014-11-28 11:38:55.397 3378 INFO neutron.wsgi [req-c878e7bf-e007-403b-bf1d-f201cd10aaf9 None] (3378) accepted ('10.10.11.3', 35612)
2014-11-28 11:38:55.398 3378 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:666
2014-11-28 11:38:55.398 3378 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:725
2014-11-28 11:38:55.399 3378 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1124
2014-11-28 11:38:55.399 3378 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1234
2014-11-28 11:38:55.399 3378 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: ecb59e3524644f0db90e64175cb20d76 with project_id : 36f745b5144842bca10af053071c6cfd and roles: admin _build_user_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1021
2014-11-28 11:38:55.400 3378 DEBUG routes.middleware [-] No route matched for GET /subnets.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:97
2014-11-28 11:38:55.400 3378 DEBUG routes.middleware [-] Matched GET /subnets.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:100
2014-11-28 11:38:55.400 3378 DEBUG routes.middleware [-] Route path: '/subnets{.format}', defaults: {'action': u'index', 'controller': <wsgify at 65942672 wrapping <function resource at 0x3ee26e0>>} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:102
2014-11-28 11:38:55.400 3378 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 65942672 wrapping <function resource at 0x3ee26e0>>, 'format': u'json'} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:103
2014-11-28 11:38:55.408 3378 INFO neutron.wsgi [req-aa251eb9-ad67-45c0-9e9d-9726defa2263 None] 10.10.11.3 - - [28/Nov/2014 11:38:55] "GET /v2.0/subnets.json?id=a6d8fbe6-7609-4a88-af4c-64d9c62c4dd5 HTTP/1.1" 200 585 0.010412
2014-11-28 11:38:55.411 3378 INFO neutron.wsgi [req-aa251eb9-ad67-45c0-9e9d-9726defa2263 None] (3378) accepted ('10.10.11.3', 35613)
2014-11-28 11:38:55.412 3378 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:666
2014-11-28 11:38:55.412 3378 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:725
2014-11-28 11:38:55.412 3378 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token _cache_get /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1124
2014-11-28 11:38:55.413 3378 DEBUG keystoneclient.middleware.auth_token [-] Storing token in cache _cache_put /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1234
2014-11-28 11:38:55.413 3378 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: ecb59e3524644f0db90e64175cb20d76 with project_id : 36f745b5144842bca10af053071c6cfd and roles: admin _build_user_headers /usr/lib/python2.7/site-packages/keystoneclient/middleware/auth_token.py:1021
2014-11-28 11:38:55.413 3378 DEBUG routes.middleware [-] No route matched for GET /ports.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:97
2014-11-28 11:38:55.414 3378 DEBUG routes.middleware [-] Matched GET /ports.json __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:100
2014-11-28 11:38:55.414 3378 DEBUG routes.middleware [-] Route path: '/ports{.format}', defaults: {'action': u'index', 'controller': <wsgify at 65957776 wrapping <function resource at 0x3ee2488>>} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:102
2014-11-28 11:38:55.414 3378 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 65957776 wrapping <function resource at 0x3ee2488>>, 'format': u'json'} __call__ /usr/lib/python2.7/site-packages/routes/middleware.py:103
2014-11-28 11:38:55.424 3378 INFO neutron.wsgi [req-746b6b05-8fef-4aa5-a8e3-25a9cbe8f0d0 None] 10.10.11.3 - - [28/Nov/2014 11:38:55] "GET /v2.0/ports.json?network_id=04f88f1f-6fdd-484e-892c-99a09beacbdb&device_owner=network%3Adhcp HTTP/1.1" 200 920 0.011884
2014-11-28 11:38:55.934 3378 DEBUG neutron.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_context_request_id': u'req-1e650517-f268-4d18-affe-a6c5a815ce91', u'_context_read_deleted': u'no', u'_context_user_name': None, u'_context_project_name': None, u'namespace': None, u'_context_tenant_id': None, u'args': {u'agent_state': {u'agent_state': {u'topic': u'dhcp_agent', u'binary': u'neutron-dhcp-agent', u'host': u'devcontroller.localdomain', u'agent_type': u'DHCP agent', u'configurations': {u'subnets': 1, u'use_namespaces': True, u'dhcp_lease_duration': 86400, u'dhcp_driver': u'neutron.agent.linux.dhcp.Dnsmasq', u'networks': 1, u'ports': 3}}}, u'time': u'2014-11-28T10:38:55.930994'}, u'_context_tenant': None, u'_unique_id': u'89820bc8f2d44566ad2c5cdc83751bfb', u'_context_is_admin': True, u'version': u'1.0', u'_context_timestamp': u'2014-11-28 10:38:55.930931', u'_context_tenant_name': None, u'_context_user': None, u'_context_user_id': None, u'method': u'report_state', u'_context_project_id': None} _safe_log /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/common.py:280
2014-11-28 11:38:55.934 3378 DEBUG neutron.openstack.common.rpc.amqp [-] unpacked context: {'project_name': None, 'user_id': None, 'roles': [u'admin'], 'tenant_id': None, 'timestamp': u'2014-11-28 10:38:55.930931', 'is_admin': True, 'read_deleted': u'no', 'request_id': u'req-1e650517-f268-4d18-affe-a6c5a815ce91', 'tenant_name': None, 'project_id': None, 'user_name': None, 'tenant': None, 'user': None} _safe_log /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/common.py:280
2014-11-28 11:38:55.935 3378 DEBUG neutron.context [req-1e650517-f268-4d18-affe-a6c5a815ce91 None] Arguments dropped when creating context: {'project_name': None, 'tenant': None} __init__ /usr/lib/python2.7/site-packages/neutron/context.py:84
2014-11-28 11:39:00.540 3378 DEBUG neutron.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_context_request_id': u'req-7d9df759-1a4e-4baf-a6eb-f59d4785a8e3', u'_context_read_deleted': u'no', u'_context_user_name': None, u'_context_project_name': None, u'namespace': None, u'_context_tenant_id': None, u'args': {u'agent_state': {u'agent_state': {u'topic': u'N/A', u'binary': u'neutron-metadata-agent', u'host': u'devcontroller.localdomain', u'agent_type': u'Metadata agent', u'configurations': {u'nova_metadata_port': 8775, u'nova_metadata_ip': u'127.0.0.1', u'metadata_proxy_socket': u'/var/lib/neutron/metadata_proxy'}}}, u'time': u'2014-11-28T10:39:00.536402'}, u'_context_tenant': None, u'_unique_id': u'5793ff99cf0442328a2888f43bdc0dae', u'_context_is_admin': True, u'version': u'1.0', u'_context_timestamp': u'2014-11-27 17:22:10.621747', u'_context_tenant_name': None, u'_context_user': None, u'_context_user_id': None, u'method': u'report_state', u'_context_project_id': None} _safe_log /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/common.py:280
2014-11-28 11:39:00.541 3378 DEBUG neutron.openstack.common.rpc.amqp [-] unpacked context: {'project_name': None, 'user_id': None, 'roles': [u'admin'], 'tenant_id': None, 'timestamp': u'2014-11-27 17:22:10.621747', 'is_admin': True, 'read_deleted': u'no', 'request_id': u'req-7d9df759-1a4e-4baf-a6eb-f59d4785a8e3', 'tenant_name': None, 'project_id': None, 'user_name': None, 'tenant': None, 'user': None} _safe_log /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/common.py:280
2014-11-28 11:39:00.541 3378 DEBUG neutron.context [req-7d9df759-1a4e-4baf-a6eb-f59d4785a8e3 None] Arguments dropped when creating context: {'project_name': None, 'tenant': None} __init__ /usr/lib/python2.7/site-packages/neutron/context.py:84
2014-11-28 11:39:04.126 3378 DEBUG neutron.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_context_request_id': u'req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8', u'_context_read_deleted': u'no', u'_context_user_name': None, u'_context_project_name': None, u'namespace': None, u'_context_tenant_id': None, u'args': {u'agent_state': {u'agent_state': {u'topic': u'l3_agent', u'binary': u'neutron-l3-agent', u'host': u'devcontroller.localdomain', u'agent_type': u'L3 agent', u'configurations': {u'router_id': u'', u'gateway_external_network_id': u'', u'handle_internal_only_routers': True, u'use_namespaces': True, u'routers': 0, u'interfaces': 0, u'floating_ips': 0, u'interface_driver': u'neutron.agent.linux.interface.OVSInterfaceDriver', u'ex_gw_ports': 0}}}, u'time': u'2014-11-28T10:39:04.123462'}, u'_context_tenant': None, u'_unique_id': u'275b28c32431427b899d445e5e23b89c', u'_context_is_admin': True, u'version': u'1.0', u'_context_timestamp': u'2014-11-27 17:23:07.710676', u'_context_tenant_name': None, u'_context_user': None, u'_context_user_id': None, u'method': u'report_state', u'_context_project_id': None} _safe_log /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/common.py:280
2014-11-28 11:39:04.127 3378 DEBUG neutron.openstack.common.rpc.amqp [-] unpacked context: {'project_name': None, 'user_id': None, 'roles': [u'admin'], 'tenant_id': None, 'timestamp': u'2014-11-27 17:23:07.710676', 'is_admin': True, 'read_deleted': u'no', 'request_id': u'req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8', 'tenant_name': None, 'project_id': None, 'user_name': None, 'tenant': None, 'user': None} _safe_log /usr/lib/python2.7/site-packages/neutron/openstack/common/rpc/common.py:280
2014-11-28 11:39:04.128 3378 DEBUG neutron.context [req-27fc4032-3c4b-4902-9ba1-8a7c2d1979c8 None] Arguments dropped when creating context: {'project_name': None, 'tenant': None} __init__ /usr/lib/python2.7/site-packages/neutron/context.py:84
Start up ovsdb
2014-11-28 11:52:29.403 CET [Thread-16] INFO o.o.o.p.impl.ConnectionServiceImpl - Initialize inventory for org.opendaylight.ovsdb.plugin.api.Connection@fdf6de76 2014-11-28 11:52:29.406 CET [Thread-16] INFO o.o.o.p.impl.ConnectionServiceImpl - Add node to ovsdb inventory service OVS|10.10.11.2:54293 2014-11-28 11:52:29.584 CET [Thread-16] INFO o.o.o.p.impl.ConnectionServiceImpl - Notifying Inventory Listeners for Node Added: OVS|10.10.11.2:54293 2014-11-28 11:52:29.595 CET [Thread-15] INFO o.o.o.p.impl.ConnectionServiceImpl - Notifying Inventory Listeners for Node Added: OVS|10.10.11.3:57965 2014-11-28 11:52:29.724 CET [pool-9-thread-1] ERROR o.o.o.o.n.i.ProviderNetworkManagerImpl - No providers matching OpenFlow13 found 2014-11-28 11:52:29.776 CET [pool-9-thread-1] ERROR o.o.o.o.n.i.BridgeConfigurationManagerImpl - Error creating Integration Bridge on OVS|10.10.11.2:54293 java.util.NoSuchElementException: null at com.google.common.collect.AbstractIterator.next(AbstractIterator.java:154) ~[bundlefile:na] at org.opendaylight.ovsdb.openstack.netvirt.impl.ProviderNetworkManagerImpl.getProvider(ProviderNetworkManagerImpl.java:65) ~[bundlefile:na] at org.opendaylight.ovsdb.openstack.netvirt.impl.BridgeConfigurationManagerImpl.addBridge(BridgeConfigurationManagerImpl.java:655) ~[bundlefile:na] at org.opendaylight.ovsdb.openstack.netvirt.impl.BridgeConfigurationManagerImpl.createIntegrationBridge(BridgeConfigurationManagerImpl.java:381) ~[bundlefile:na] at org.opendaylight.ovsdb.openstack.netvirt.impl.BridgeConfigurationManagerImpl.prepareNode(BridgeConfigurationManagerImpl.java:186) ~[bundlefile:na] at org.opendaylight.ovsdb.openstack.netvirt.SouthboundHandler.processNodeUpdate(SouthboundHandler.java:130) [bundlefile:na] at org.opendayli
Solution
This is basically two things: a) ProviderNetworkManagerImpl throwing an exception b) MD-SAL reporting that it threw the exception
Interesting additional data.
If after reproducing you do on the host:
sudo ovs-vsctl del-br br-int
and then
sudo ovs-vsctl set-manager tcp:10.0.2.2:6640;sudo ovs-vsctl add-br br-int; sudo ovs-vsctl set bridge br-int protocols=["OpenFlow13"]; sudo ovs-vsctl set-controller br-int tcp:10.0.2.2:6633
the exception does not recur, and the flows get programmed to ovs.
This looks like a startup race condition in ovsdb.
No router namespace
vim /etc/neutron/l3-agent.ini debug = True
Create br-ex on Controller (neutron-server) node:
ovs-vsctl add-br br-ex
Stderr: '' execute /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:75 2014-11-28 14:04:27.121 20008 DEBUG neutron.agent.linux.utils [req-7fa08cd4-7169-4f98-a7c2-b2b319975fc8 None] Running command: ['sudo', 'neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qrouter-307b14ab-5104-4464-a4d3-bdd11fcacce2', 'ip', '-4', 'addr', 'add', '192.168.1.200/24', 'brd', '192.168.1.255', 'scope', 'global', 'dev', 'qr-1ad85853-c2'] create_process /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:48 2014-11-28 14:04:27.163 20008 DEBUG neutron.agent.linux.utils [req-7fa08cd4-7169-4f98-a7c2-b2b319975fc8 None] Command: ['sudo', 'neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qrouter-307b14ab-5104-4464-a4d3-bdd11fcacce2', 'ip', '-4', 'addr', 'add', '192.168.1.200/24', 'brd', '192.168.1.255', 'scope', 'global', 'dev', 'qr-1ad85853-c2'] Exit code: 0 Stdout: '' Stderr: '' execute /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:75 2014-11-28 14:04:27.163 20008 DEBUG neutron.agent.linux.utils [req-7fa08cd4-7169-4f98-a7c2-b2b319975fc8 None] Running command: ['sudo', 'neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qrouter-307b14ab-5104-4464-a4d3-bdd11fcacce2', 'ip', '-o', '-d', 'link', 'list'] create_process /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:48 2014-11-28 14:04:27.208 20008 DEBUG neutron.agent.linux.utils [req-7fa08cd4-7169-4f98-a7c2-b2b319975fc8 None] Command: ['sudo', 'neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qrouter-307b14ab-5104-4464-a4d3-bdd11fcacce2', 'ip', '-o', '-d', 'link', 'list'] Exit code: 0
