lock wait timeout in create_dhcp_port

[Salvatore Orlando]

Traceback: http://logs.openstack.org/63/60863/3/check/check-tempest-dsvm-neutron-full/3c1893a/logs/screen-q-svc.txt.gz#_2014-04-22_06_34_40_383

logstash:
http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiKE9wZXJhdGlvbmFsRXJyb3IpICgxMjA1LCAnTG9jayB3YWl0IHRpbWVvdXQgZXhjZWVkZWQ7IHRyeSByZXN0YXJ0aW5nIHRyYW5zYWN0aW9uJylcIiBBTkQgTk9UIG1lc3NhZ2U6XCJUcmFjZWJhY2sgKG1vc3QgcmVjZW50IGNhbGwgbGFzdFwiIEFORCB0YWdzOlwic2NyZWVuLXEtc3ZjLnR4dFwiIEFORCBtZXNzYWdlOlwiSU5TRVJUIElOVE8gaXBhbGxvY2F0aW9uc1wiIiwiZmllbGRzIjpbXSwib2Zmc2V0IjowLCJ0aW1lZnJhbWUiOiI2MDQ4MDAiLCJncmFwaG1vZGUiOiJjb3VudCIsInRpbWUiOnsidXNlcl9pbnRlcnZhbCI6MH0sInN0YW1wIjoxMzk4NzAzNTUyMzAwfQ==

Apparent root cause: concurrent dhcp port operations with "offending" yield during create port.

Occurences: 8 in 7 days (failure rate: 50%)

[Ihar Hrachyshka (ihar-hrachyshka)]

The lock scenario could go as follows: we see in the log that sync_routers() is called. It opens txn, then calls to _ensure_host_set_on_ports(), which lower in the stack calls to plugin.update_port(), which notifies and yields. Then we switch to a thread that updates port state, lock on that, and finally timeout.

[Rossella Sblendido (rossella-o)]

Ihar thanks for looking into it.

The operation that times out is the creation of the dhcp port, not the update port.
The update port you mentioned locks the table Port. After that I see a release_dhcp_port that is followed by a delete_ports_by_device_id and delete_port . This operation requires the lock on the port table so I think the previous update port finished.
Then there's a dhcp port creation. This operation is able to acquire the locks on the following tables: IPAllocationPool, IPAvailabilityRange and Port but fails when it tries to update the table IPAllocation . I still don't know why.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/104936

[Joe Gordon (jogo)]

No hits for this one looks like it was resolved

[Carl Baldwin (carl-baldwin)]

How can we set this to fix committed? What was the fix? The only fix linked was abandoned.

[Carl Baldwin (carl-baldwin)]

Under create_dhcp_port (an RPC call) is a create_port called on the plugin. I believe this is a manifestation of a larger problem. One that I'm seeing currently with a little bit larger scale. The lock wait timeout is the same and it is always in the context of create_port. It is not always in the context of create_dhcp_port.

[OpenStack Infra (hudson-openstack)]

Change abandoned by Kyle Mestery (<email address hidden>) on branch: master
Review: https://review.openstack.org/100963
Reason: This review is > 4 weeks without comment, and failed Jenkins the last time it was checked. We are abandoning this for now. Feel free to reactivate the review by pressing the restore button and leaving a 'recheck' comment to get fresh test results.