Comment 1 for bug 1649548

Revision history for this message
Yuli (stremovsky) wrote :

As it turned out it happens when trying to aquire lock (dragonflow code).

Take a look at the example:

stack@ubuntu200:/opt/stack/logs$ grep req-39b7765e-8606-4259-9ca9-b31e3be89691 q-svc.log | grep "Try to get lock for object"
2016-12-13 11:25:28.774 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 3512258685.
2016-12-13 11:25:30.793 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 3156869888.
2016-12-13 11:25:34.797 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 7173602260.
2016-12-13 11:25:42.807 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 4270305405.
2016-12-13 11:25:52.816 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 2411185474.
2016-12-13 11:26:02.825 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 1907166269.
2016-12-13 11:26:12.867 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 4109395117.
2016-12-13 11:26:22.895 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 3077718418.
2016-12-13 11:26:32.903 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 1294497020.
2016-12-13 11:26:43.090 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 1200496550.
2016-12-13 11:26:53.242 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 1358217871.
2016-12-13 11:27:03.265 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 9795887159.
2016-12-13 11:27:13.269 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 6886244371.
2016-12-13 11:27:23.348 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 4907705753.
2016-12-13 11:27:33.435 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 7705261829.
2016-12-13 11:27:43.469 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 6146326246.
2016-12-13 11:27:53.731 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 5215417422.
2016-12-13 11:28:03.736 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 9806711341.
2016-12-13 11:28:13.739 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 5370613910.
2016-12-13 11:28:13.751 26433 INFO dragonflow.db.neutron.lockedobjects_db [req-39b7765e-8606-4259-9ca9-b31e3be89691 c_rally_6dff3601_cgAPsIVX -] Try to get lock for object 360e7d0657df4519a53a2a5be32c1aba in session 5370613910.

grep req-39b7765e-8606-4259-9ca9-b31e3be89691 q-svc.log | grep "Try to get lock for object" | gawk '{print $1" "$2}'
2016-12-13 11:25:28.774
2016-12-13 11:25:30.793
2016-12-13 11:25:34.797
2016-12-13 11:25:42.807
2016-12-13 11:25:52.816
2016-12-13 11:26:02.825
2016-12-13 11:26:12.867
2016-12-13 11:26:22.895
2016-12-13 11:26:32.903
2016-12-13 11:26:43.090
2016-12-13 11:26:53.242
2016-12-13 11:27:03.265
2016-12-13 11:27:13.269
2016-12-13 11:27:23.348
2016-12-13 11:27:33.435
2016-12-13 11:27:43.469
2016-12-13 11:27:53.731
2016-12-13 11:28:03.736
2016-12-13 11:28:13.739
2016-12-13 11:28:13.751

The span between attempts is 10 seconds and as a result a failure.