<div>Hi Oliver,</div><div> </div><div>I'd suggest to join us on IRC at #openstack-ansible channel on Freenode so we could help you more properly with the issue.</div><div>It seems to me at the moment some kind of misconfiguration, which is super hard to understand in ML (as eventually hard to read logs in proper way inside ML).</div><div> </div><div>02.12.2020, 13:55, "Oliver Wenz" <oliver.wenz@dhbw-mannheim.de>:</div><blockquote><p> </p><blockquote> Neutron sends this notification to the nova-api so You should check in nova-api<br /> logs.<br /> Whole workflow for that process of spawning vm is more or less like below:<br /> 1. nova-compute asks neutron for port,<br /> 2. neutron creates port and binds it with some mechanism driver - so it has<br /> vif_type e.g. "ovs" or "linuxbridge" or some other,<br /> 3. nova, based on that vif details plugs port to the proper bridge on host and<br /> pauses instance until neutron will not do its job,<br /> 4. neutron-l2-agent (linuxbrige or ovs) starts provisioning port and reports<br /> to neutron-server when it is done,<br /> 5. if there is no any provisioning blocks for that port in neutron db (can be<br /> also one from the dhcp agent), neutron sends notification to nova-api that port<br /> is ready,<br /> 6. nova unpauses vm.<br /> <br /> In Your case it seems that on step 5 nova reports some error and that You<br /> should IMO check.<br /> </blockquote><p><br />Hi Slawek,<br />thanks for the information and suggestion! I checked the<br />nova-api-os-compute logs and it seems like there are network problems<br />and an issue with wrong token scope:<br /><br />Dec 02 11:15:49 infra1-nova-api-container-83af52a6 nova-api-wsgi[84]:<br />2020-12-02 11:15:49.074 84 INFO nova.api.openstack.requestlog<br />[req-1d56ad1c-03ea-4dcc-b9da-e4f6e73ccc52<br />920e739127a14018a55fb4422b0885e7 0f14905dab5546e0adec2b56c0f6be88 -<br />default default] 192.168.110.201 "GET<br />/v2.1/servers/2a1f6fbf-48f8-4e7f-bc36-7162bdaf7e20" status: 200 len:<br />1358 microversion: 2.1 time: 0.500669<br />Dec 02 11:15:49 infra1-nova-api-container-83af52a6 nova-api-wsgi[86]:<br />2020-12-02 11:15:49.256 86 INFO oslo.messaging._drivers.impl_rabbit [-]<br />A recoverable connection/channel error occurred, trying to reconnect:<br />[Errno 104] Connection reset by peer<br />Dec 02 11:15:49 infra1-nova-api-container-83af52a6 uwsgi[48]: Wed Dec 2<br />11:15:49 2020 - SIGPIPE: writing to a closed pipe/socket/fd (probably<br />the client disconnected) on request<br />/v2.1/flavors/7c20746e-f6db-4344-9aa1-be926696ecf4 (ip 192.168.110.201) !!!<br />Dec 02 11:15:49 infra1-nova-api-container-83af52a6 nova-api-wsgi[86]:<br />2020-12-02 11:15:49.318 86 INFO nova.api.openstack.requestlog<br />[req-832f794d-db9b-4690-bb0c-8320e7beed47<br />920e739127a14018a55fb4422b0885e7 0f14905dab5546e0adec2b56c0f6be88 -<br />default default] 192.168.110.201 "GET<br />/v2.1/flavors/7c20746e-f6db-4344-9aa1-be926696ecf4" status: 200 len: 473<br />microversion: 2.1 time: 0.095833<br />Dec 02 11:15:57 infra1-nova-api-container-83af52a6 nova-api-wsgi[79]:<br />2020-12-02 11:15:57.000 79 INFO nova.api.openstack.requestlog<br />[req-2c061260-88f4-4183-a74a-ea59d1ff1ae0<br />b044fe42a4644837a3bd40beec378876 226e9c9f1fb94c8ab271490ad79c6873 -<br />default default] 192.168.110.201 "HEAD /" status: 200 len: 417<br />microversion: - time: 0.001837<br />Dec 02 11:15:57 infra1-nova-api-container-83af52a6 nova-api-wsgi[88]:<br />2020-12-02 11:15:57.214 88 INFO oslo.messaging._drivers.impl_rabbit [-]<br />A recoverable connection/channel error occurred, trying to reconnect:<br />[Errno 104] Connection reset by peer<br />Dec 02 11:15:57 infra1-nova-api-container-83af52a6 uwsgi[48]: Wed Dec 2<br />11:15:57 2020 - SIGPIPE: writing to a closed pipe/socket/fd (probably<br />the client disconnected) on request /v2.1/os-server-external-events (ip<br />192.168.110.201) !!!<br />Dec 02 11:15:57 infra1-nova-api-container-83af52a6 uwsgi[48]:<br />/openstack/venvs/nova-21.1.0/lib/python3.6/site-packages/oslo_policy/policy.py:1007:<br />UserWarning: Policy os_compute_api:os-server-external-events:create<br />failed scope check. The token used to make the request was project<br />scoped but the policy requires ['system'] scope. This behavior may<br />change in the future where using the intended scope is required<br />Dec 02 11:15:57 infra1-nova-api-container-83af52a6 uwsgi[48]:<br />warnings.warn(msg)<br />Dec 02 11:15:57 infra1-nova-api-container-83af52a6 nova-api-wsgi[88]:<br />2020-12-02 11:15:57.715 88 INFO<br />nova.api.openstack.compute.server_external_events<br />[req-759c5752-c80b-46f2-b3df-0fa126605895<br />d9a2e96567ec4670bc60dbcc8f66305f 474b7aa9b7894d6782402135c6ef4c2a -<br />default default] Creating event<br />network-changed:ed4a9455-a33c-454c-b74f-b314751cce3d for instance<br />2a1f6fbf-48f8-4e7f-bc36-7162bdaf7e20 on bc1blade15<br />Dec 02 11:15:57 infra1-nova-api-container-83af52a6 nova-api-wsgi[88]:<br />2020-12-02 11:15:57.734 88 INFO nova.api.openstack.requestlog<br />[req-759c5752-c80b-46f2-b3df-0fa126605895<br />d9a2e96567ec4670bc60dbcc8f66305f 474b7aa9b7894d6782402135c6ef4c2a -<br />default default] 192.168.110.201 "POST /v2.1/os-server-external-events"<br />status: 200 len: 179 microversion: 2.1 time: 0.533910<br />Dec 02 11:16:09 infra1-nova-api-container-83af52a6 nova-api-wsgi[82]:<br />2020-12-02 11:16:09.007 82 INFO nova.api.openstack.requestlog<br />[req-064600c9-196e-4388-978c-00b0f5560b2e<br />745ecbee83d041c6ba92f9e07ba744d5 a2fd11a3bfdd47c8893e18a6f3b7dfa3 -<br />default default] 192.168.110.201 "HEAD /" status: 200 len: 417<br />microversion: - time: 0.001638<br />Dec 02 11:16:16 infra1-nova-api-container-83af52a6 nova-api-wsgi[77]:<br />2020-12-02 11:16:16.432 77 INFO oslo.messaging._drivers.impl_rabbit [-]<br />A recoverable connection/channel error occurred, trying to reconnect:<br />[Errno 104] Connection reset by peer<br />Dec 02 11:16:16 infra1-nova-api-container-83af52a6 uwsgi[48]: Wed Dec 2<br />11:16:16 2020 - SIGPIPE: writing to a closed pipe/socket/fd (probably<br />the client disconnected) on request /v2.1/os-server-external-events (ip<br />192.168.110.201) !!!<br />Dec 02 11:16:16 infra1-nova-api-container-83af52a6 uwsgi[48]:<br />/openstack/venvs/nova-21.1.0/lib/python3.6/site-packages/oslo_policy/policy.py:1007:<br />UserWarning: Policy os_compute_api:os-server-external-events:create<br />failed scope check. The token used to make the request was project<br />scoped but the policy requires ['system'] scope. This behavior may<br />change in the future where using the intended scope is required<br />Dec 02 11:16:16 infra1-nova-api-container-83af52a6 uwsgi[48]:<br />warnings.warn(msg)<br />Dec 02 11:16:16 infra1-nova-api-container-83af52a6 nova-api-wsgi[77]:<br />2020-12-02 11:16:16.939 77 INFO<br />nova.api.openstack.compute.server_external_events<br />[req-71a40ea1-cf64-46d5-9675-d00d539f1922<br />d9a2e96567ec4670bc60dbcc8f66305f 474b7aa9b7894d6782402135c6ef4c2a -<br />default default] Creating event<br />network-vif-plugged:5cbc8608-8545-4eb3-a745-23ca912347ec for instance<br />ea72988b-83eb-4640-adaa-e24e0c3d018d on bc1blade15<br />Dec 02 11:16:16 infra1-nova-api-container-83af52a6 nova-api-wsgi[77]:<br />2020-12-02 11:16:16.958 77 INFO nova.api.openstack.requestlog<br />[req-71a40ea1-cf64-46d5-9675-d00d539f1922<br />d9a2e96567ec4670bc60dbcc8f66305f 474b7aa9b7894d6782402135c6ef4c2a -<br />default default] 192.168.110.201 "POST /v2.1/os-server-external-events"<br />status: 200 len: 183 microversion: 2.1 time: 0.526920<br />Dec 02 11:16:17 infra1-nova-api-container-83af52a6 nova-api-wsgi[71]:<br />2020-12-02 11:16:17.422 71 INFO oslo.messaging._drivers.impl_rabbit [-]<br />A recoverable connection/channel error occurred, trying to reconnect:<br />[Errno 104] Connection reset by peer<br /><br /><br /><br />Kind regards,<br />Oliver<br /> </p></blockquote><div> </div><div> </div><div>-- <br />Kind Regards,</div><div>Dmitriy Rabotyagov</div><div> </div>