I quickly checked at the logs and see that the VIF plugging failed because nova-compute timed out waiting:
2016-06-08 15:34:17.571 5121 WARNING nova.virt.libvirt.driver [req-9d7bb106-12f5-4bf4-a203-1aa0ce7e64b1 5f5e223276ef4df7ac1c1519c80ff263 bcd5faf949c249868335474c88dd42b3 - - -] [instance: bac44ad7-eaf8-4d9c-b62e-d8537f107193] Timeout waiting for vif plugging callback for instance bac44ad7-eaf8-4d9c-b62e-d8537f107193
at the same time I see that neutron successfully delivered the notification to nova-api:
2016-06-08 15:29:22.745 977 DEBUG nova.api.openstack.wsgi [req-163dcfa5-129d-44fc-9187-3ac4d7207814 2c5b7c93a21443ab8a6bc4824cb03443 3c1747ea62 c5410faffdb6bb1b29068f - - -] Action: 'create', calling method: <bound method ServerExternalEventsController.create of <nova.api.openstack.comp ute.server_external_events.ServerExternalEventsController object at 0x7fd1808e82d0>>, body: {"events": [{"status": "completed", "tag": "27d10f0 6-73e4-4aa0-98a2-2f4c29a658af", "name": "network-vif-plugged", "server_uuid": "bac44ad7-eaf8-4d9c-b62e-d8537f107193"}]} _process_stack /usr/lib /python2.7/dist-packages/nova/api/openstack/wsgi.py:696 2016-06-08 15:29:22.791 977 INFO nova.api.openstack.compute.server_external_events [req-163dcfa5-129d-44fc-9187-3ac4d7207814 2c5b7c93a21443ab8a 6bc4824cb03443 3c1747ea62c5410faffdb6bb1b29068f - - -] Creating event network-vif-plugged:27d10f06-73e4-4aa0-98a2-2f4c29a658af for instance bac 44ad7-eaf8-4d9c-b62e-d8537f107193 2016-06-08 15:29:22.794 977 DEBUG oslo_messaging._drivers.amqpdriver [req-163dcfa5-129d-44fc-9187-3ac4d7207814 2c5b7c93a21443ab8a6bc4824cb03443 3c1747ea62c5410faffdb6bb1b29068f - - -] CAST unique_id: 9bd64ed934db48b885d8a2f62ae9cb61 size: 5320 exchange: nova topic: compute _send /usr/l ib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:496 2016-06-08 15:29:22.801 977 INFO nova.osapi_compute.wsgi.server [req-163dcfa5-129d-44fc-9187-3ac4d7207814 2c5b7c93a21443ab8a6bc4824cb03443 3c17 47ea62c5410faffdb6bb1b29068f - - -] 10.109.7.8 "POST /v2.1/os-server-external-events HTTP/1.1" status: 200 len: 446 time: 0.0606301
It's not clear why the message was not delivered to the compute side. We'll take a closer look tomorrow.
I quickly checked at the logs and see that the VIF plugging failed because nova-compute timed out waiting:
2016-06-08 15:34:17.571 5121 WARNING nova.virt. libvirt. driver [req-9d7bb106- 12f5-4bf4- a203-1aa0ce7e64 b1 5f5e223276ef4df 7ac1c1519c80ff2 63 bcd5faf949c2498 68335474c88dd42 b3 - - -] [instance: bac44ad7- eaf8-4d9c- b62e-d8537f1071 93] Timeout waiting for vif plugging callback for instance bac44ad7- eaf8-4d9c- b62e-d8537f1071 93
at the same time I see that neutron successfully delivered the notification to nova-api:
2016-06-08 15:29:22.745 977 DEBUG nova.api. openstack. wsgi [req-163dcfa5- 129d-44fc- 9187-3ac4d72078 14 2c5b7c93a21443a b8a6bc4824cb034 43 3c1747ea62 b29068f - - -] Action: 'create', calling method: <bound method ServerExternalE ventsController .create of <nova.api. openstack. comp external_ events. ServerExternalE ventsController object at 0x7fd1808e82d0>>, body: {"events": [{"status": "completed", "tag": "27d10f0 4aa0-98a2- 2f4c29a658af" , "name": "network- vif-plugged" , "server_uuid": "bac44ad7- eaf8-4d9c- b62e-d8537f1071 93"}]} _process_stack /usr/lib 7/dist- packages/ nova/api/ openstack/ wsgi.py: 696 openstack. compute. server_ external_ events [req-163dcfa5- 129d-44fc- 9187-3ac4d72078 14 2c5b7c93a21443ab8a faffdb6bb1b2906 8f - - -] Creating event network- vif-plugged: 27d10f06- 73e4-4aa0- 98a2-2f4c29a658 af for instance bac 4d9c-b62e- d8537f107193 _drivers. amqpdriver [req-163dcfa5- 129d-44fc- 9187-3ac4d72078 14 2c5b7c93a21443a b8a6bc4824cb034 43 0faffdb6bb1b290 68f - - -] CAST unique_id: 9bd64ed934db48b 885d8a2f62ae9cb 61 size: 5320 exchange: nova topic: compute _send /usr/l 7/dist- packages/ oslo_messaging/ _drivers/ amqpdriver. py:496 compute. wsgi.server [req-163dcfa5- 129d-44fc- 9187-3ac4d72078 14 2c5b7c93a21443a b8a6bc4824cb034 43 3c17 db6bb1b29068f - - -] 10.109.7.8 "POST /v2.1/os- server- external- events HTTP/1.1" status: 200 len: 446 time: 0.0606301
c5410faffdb6bb1
ute.server_
6-73e4-
/python2.
2016-06-08 15:29:22.791 977 INFO nova.api.
6bc4824cb03443 3c1747ea62c5410
44ad7-eaf8-
2016-06-08 15:29:22.794 977 DEBUG oslo_messaging.
3c1747ea62c541
ib/python2.
2016-06-08 15:29:22.801 977 INFO nova.osapi_
47ea62c5410faff
It's not clear why the message was not delivered to the compute side. We'll take a closer look tomorrow.