Hi Oliver,
 
I'd suggest to join us on IRC at #openstack-ansible channel on Freenode so we could help you more properly with the issue.
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).
 
02.12.2020, 13:55, "Oliver Wenz" <oliver.wenz@dhbw-mannheim.de>:

 

 Neutron sends this notification to the nova-api so You should check in nova-api
 logs.
 Whole workflow for that process of spawning vm is more or less like below:
 1. nova-compute asks neutron for port,
 2. neutron creates port and binds it with some mechanism driver - so it has
 vif_type e.g. "ovs" or "linuxbridge" or some other,
 3. nova, based on that vif details plugs port to the proper bridge on host and
 pauses instance until neutron will not do its job,
 4. neutron-l2-agent (linuxbrige or ovs) starts provisioning port and reports
 to neutron-server when it is done,
 5. if there is no any provisioning blocks for that port in neutron db (can be
 also one from the dhcp agent), neutron sends notification to nova-api that port
 is ready,
 6. nova unpauses vm.
 
 In Your case it seems that on step 5 nova reports some error and that You
 should IMO check.
 


Hi Slawek,
thanks for the information and suggestion! I checked the
nova-api-os-compute logs and it seems like there are network problems
and an issue with wrong token scope:

Dec 02 11:15:49 infra1-nova-api-container-83af52a6 nova-api-wsgi[84]:
2020-12-02 11:15:49.074 84 INFO nova.api.openstack.requestlog
[req-1d56ad1c-03ea-4dcc-b9da-e4f6e73ccc52
920e739127a14018a55fb4422b0885e7 0f14905dab5546e0adec2b56c0f6be88 -
default default] 192.168.110.201 "GET
/v2.1/servers/2a1f6fbf-48f8-4e7f-bc36-7162bdaf7e20" status: 200 len:
1358 microversion: 2.1 time: 0.500669
Dec 02 11:15:49 infra1-nova-api-container-83af52a6 nova-api-wsgi[86]:
2020-12-02 11:15:49.256 86 INFO oslo.messaging._drivers.impl_rabbit [-]
A recoverable connection/channel error occurred, trying to reconnect:
[Errno 104] Connection reset by peer
Dec 02 11:15:49 infra1-nova-api-container-83af52a6 uwsgi[48]: Wed Dec 2
11:15:49 2020 - SIGPIPE: writing to a closed pipe/socket/fd (probably
the client disconnected) on request
/v2.1/flavors/7c20746e-f6db-4344-9aa1-be926696ecf4 (ip 192.168.110.201) !!!
Dec 02 11:15:49 infra1-nova-api-container-83af52a6 nova-api-wsgi[86]:
2020-12-02 11:15:49.318 86 INFO nova.api.openstack.requestlog
[req-832f794d-db9b-4690-bb0c-8320e7beed47
920e739127a14018a55fb4422b0885e7 0f14905dab5546e0adec2b56c0f6be88 -
default default] 192.168.110.201 "GET
/v2.1/flavors/7c20746e-f6db-4344-9aa1-be926696ecf4" status: 200 len: 473
microversion: 2.1 time: 0.095833
Dec 02 11:15:57 infra1-nova-api-container-83af52a6 nova-api-wsgi[79]:
2020-12-02 11:15:57.000 79 INFO nova.api.openstack.requestlog
[req-2c061260-88f4-4183-a74a-ea59d1ff1ae0
b044fe42a4644837a3bd40beec378876 226e9c9f1fb94c8ab271490ad79c6873 -
default default] 192.168.110.201 "HEAD /" status: 200 len: 417
microversion: - time: 0.001837
Dec 02 11:15:57 infra1-nova-api-container-83af52a6 nova-api-wsgi[88]:
2020-12-02 11:15:57.214 88 INFO oslo.messaging._drivers.impl_rabbit [-]
A recoverable connection/channel error occurred, trying to reconnect:
[Errno 104] Connection reset by peer
Dec 02 11:15:57 infra1-nova-api-container-83af52a6 uwsgi[48]: Wed Dec 2
11:15:57 2020 - SIGPIPE: writing to a closed pipe/socket/fd (probably
the client disconnected) on request /v2.1/os-server-external-events (ip
192.168.110.201) !!!
Dec 02 11:15:57 infra1-nova-api-container-83af52a6 uwsgi[48]:
/openstack/venvs/nova-21.1.0/lib/python3.6/site-packages/oslo_policy/policy.py:1007:
UserWarning: Policy os_compute_api:os-server-external-events:create
failed scope check. The token used to make the request was project
scoped but the policy requires ['system'] scope. This behavior may
change in the future where using the intended scope is required
Dec 02 11:15:57 infra1-nova-api-container-83af52a6 uwsgi[48]:
warnings.warn(msg)
Dec 02 11:15:57 infra1-nova-api-container-83af52a6 nova-api-wsgi[88]:
2020-12-02 11:15:57.715 88 INFO
nova.api.openstack.compute.server_external_events
[req-759c5752-c80b-46f2-b3df-0fa126605895
d9a2e96567ec4670bc60dbcc8f66305f 474b7aa9b7894d6782402135c6ef4c2a -
default default] Creating event
network-changed:ed4a9455-a33c-454c-b74f-b314751cce3d for instance
2a1f6fbf-48f8-4e7f-bc36-7162bdaf7e20 on bc1blade15
Dec 02 11:15:57 infra1-nova-api-container-83af52a6 nova-api-wsgi[88]:
2020-12-02 11:15:57.734 88 INFO nova.api.openstack.requestlog
[req-759c5752-c80b-46f2-b3df-0fa126605895
d9a2e96567ec4670bc60dbcc8f66305f 474b7aa9b7894d6782402135c6ef4c2a -
default default] 192.168.110.201 "POST /v2.1/os-server-external-events"
status: 200 len: 179 microversion: 2.1 time: 0.533910
Dec 02 11:16:09 infra1-nova-api-container-83af52a6 nova-api-wsgi[82]:
2020-12-02 11:16:09.007 82 INFO nova.api.openstack.requestlog
[req-064600c9-196e-4388-978c-00b0f5560b2e
745ecbee83d041c6ba92f9e07ba744d5 a2fd11a3bfdd47c8893e18a6f3b7dfa3 -
default default] 192.168.110.201 "HEAD /" status: 200 len: 417
microversion: - time: 0.001638
Dec 02 11:16:16 infra1-nova-api-container-83af52a6 nova-api-wsgi[77]:
2020-12-02 11:16:16.432 77 INFO oslo.messaging._drivers.impl_rabbit [-]
A recoverable connection/channel error occurred, trying to reconnect:
[Errno 104] Connection reset by peer
Dec 02 11:16:16 infra1-nova-api-container-83af52a6 uwsgi[48]: Wed Dec 2
11:16:16 2020 - SIGPIPE: writing to a closed pipe/socket/fd (probably
the client disconnected) on request /v2.1/os-server-external-events (ip
192.168.110.201) !!!
Dec 02 11:16:16 infra1-nova-api-container-83af52a6 uwsgi[48]:
/openstack/venvs/nova-21.1.0/lib/python3.6/site-packages/oslo_policy/policy.py:1007:
UserWarning: Policy os_compute_api:os-server-external-events:create
failed scope check. The token used to make the request was project
scoped but the policy requires ['system'] scope. This behavior may
change in the future where using the intended scope is required
Dec 02 11:16:16 infra1-nova-api-container-83af52a6 uwsgi[48]:
warnings.warn(msg)
Dec 02 11:16:16 infra1-nova-api-container-83af52a6 nova-api-wsgi[77]:
2020-12-02 11:16:16.939 77 INFO
nova.api.openstack.compute.server_external_events
[req-71a40ea1-cf64-46d5-9675-d00d539f1922
d9a2e96567ec4670bc60dbcc8f66305f 474b7aa9b7894d6782402135c6ef4c2a -
default default] Creating event
network-vif-plugged:5cbc8608-8545-4eb3-a745-23ca912347ec for instance
ea72988b-83eb-4640-adaa-e24e0c3d018d on bc1blade15
Dec 02 11:16:16 infra1-nova-api-container-83af52a6 nova-api-wsgi[77]:
2020-12-02 11:16:16.958 77 INFO nova.api.openstack.requestlog
[req-71a40ea1-cf64-46d5-9675-d00d539f1922
d9a2e96567ec4670bc60dbcc8f66305f 474b7aa9b7894d6782402135c6ef4c2a -
default default] 192.168.110.201 "POST /v2.1/os-server-external-events"
status: 200 len: 183 microversion: 2.1 time: 0.526920
Dec 02 11:16:17 infra1-nova-api-container-83af52a6 nova-api-wsgi[71]:
2020-12-02 11:16:17.422 71 INFO oslo.messaging._drivers.impl_rabbit [-]
A recoverable connection/channel error occurred, trying to reconnect:
[Errno 104] Connection reset by peer



Kind regards,
Oliver
 

 
 
-- 
Kind Regards,
Dmitriy Rabotyagov