Open Stack

On 19/12/18 6:49 AM, Jay Pipes wrote:
> On 12/18/2018 11:06 AM, Mike Bayer wrote:
>> On Tue, Dec 18, 2018 at 12:36 AM Ignazio Cassano
>> <ignaziocassano at gmail.com> wrote:
>>>
>>> Yes, I  tried on yesterday and this workaround solved.
>>> Thanks
>>> Ignazio
>>
>> OK, so that means this "deadlock" is not really a deadlock but it is a
>> write-conflict between two Galera masters.      I have a long term
>> goal to being relaxing this common requirement that Openstack apps
>> only refer to one Galera master at a time.    If this is a particular
>> hotspot for Heat (no pun intended) can we pursue adding a transaction
>> retry decorator for this operation?  This is the standard approach for
>> other applications that are subject to galera multi-master writeset
>> conflicts such as Neutron.

The weird thing about this issue is that we actually have a retry 
decorator on the operation that I assume is the problem. It was added in 
Queens and largely fixed this issue in the gate:

https://review.openstack.org/#/c/521170/1/heat/db/sqlalchemy/api.py

> Correct.
> 
> Heat doesn't use SELECT .. FOR UPDATE does it? That's also a big cause 
> of the aforementioned "deadlocks".

AFAIK, no. In fact we were quite careful to design stuff that is 
expected to be subject to write contention to use UPDATE ... WHERE (by 
doing query().filter_by().update() in sqlalchemy), but it turned out to 
be those very statements that were most prone to causing deadlocks in 
the gate (i.e. we added retry decorators in those two places and the 
failures went away), according to me in the commit message for that 
patch: https://review.openstack.org/521170

Are we Doing It Wrong(TM)?

thanks,
Zane.

> Best,
> -jay
> 
>>>
>>> Il giorno Lun 17 Dic 2018 20:38 Joe Topjian <joe at topjian.net> ha 
>>> scritto:
>>>>
>>>> Hi Ignazio,
>>>>
>>>> Do you currently have HAProxy configured to route requests to 
>>>> multiple MariaDB nodes? If so, as a workaround, try doing an 
>>>> active/backup configuration where all but 1 node is configured as an 
>>>> HAProxy "backup".
>>>>
>>>> Thanks,
>>>> Joe
>>>>
>>>>
>>>>
>>>> On Sun, Dec 16, 2018 at 10:46 PM Ignazio Cassano 
>>>> <ignaziocassano at gmail.com> wrote:
>>>>>
>>>>> Hello Zane, it happens also when I create a magnum cluster .
>>>>> My mariadb cluster is behind haproxy.
>>>>> Do you need any other info?
>>>>> Thanks
>>>>> Ignazio
>>>>>
>>>>>
>>>>> Il giorno Lun 17 Dic 2018 00:28 Zane Bitter <zbitter at redhat.com> ha 
>>>>> scritto:
>>>>>>
>>>>>> On 14/12/18 4:06 AM, Ignazio Cassano wrote:
>>>>>>> Hi All,
>>>>>>> I installed queens on centos 7.
>>>>>>> Heat seems to work fine with templates I wrote but when I create 
>>>>>>> magnum
>>>>>>> cluster
>>>>>>> I often face with db deadlock in heat-engine log:
>>>>>>
>>>>>> The stacktrace below is in stack delete, so do you mean that the 
>>>>>> problem
>>>>>> occurs when deleting a Magnum cluster, or can it occur any time 
>>>>>> with a
>>>>>> magnum cluster?
>>>>>>
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource 
>>>>>>> Traceback (most
>>>>>>> recent call last):
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource   File
>>>>>>> "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 
>>>>>>> 918, in
>>>>>>> _action_recorder
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource     yield
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource   File
>>>>>>> "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 
>>>>>>> 2035,
>>>>>>> in delete
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource     
>>>>>>> *action_args)
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource   File
>>>>>>> "/usr/lib/python2.7/site-packages/heat/engine/scheduler.py", line 
>>>>>>> 346,
>>>>>>> in wrapper
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource     step =
>>>>>>> next(subtask)
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource   File
>>>>>>> "/usr/lib/python2.7/site-packages/heat/engine/resource.py", line 
>>>>>>> 977, in
>>>>>>> action_handler_task
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource     done =
>>>>>>> check(handler_data)
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource   File
>>>>>>> "/usr/lib/python2.7/site-packages/heat/engine/resources/stack_resource.py", 
>>>>>>>
>>>>>>> line 587, in check_delete_complete
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource     return
>>>>>>> self._check_status_complete(self.DELETE)
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource   File
>>>>>>> "/usr/lib/python2.7/site-packages/heat/engine/resources/stack_resource.py", 
>>>>>>>
>>>>>>> line 454, in _check_status_complete
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource     
>>>>>>> action=action)
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource
>>>>>>> ResourceFailure: resources[0]: (pymysql.err.InternalError) (1213,
>>>>>>> u'Deadlock found when trying to get lock; try restarting 
>>>>>>> transaction')
>>>>>>> (Background on this error at: http://sqlalche.me/e/2j85)
>>>>>>> 2018-12-13 11:48:46.016 89597 ERROR heat.engine.resource
>>>>>>> 2018-12-13 11:48:46.030 89597 INFO heat.engine.stack
>>>>>>> [req-9a43184f-77d8-4fad-ab9e-2b9826c10b70 - admin - default default]
>>>>>>> Stack DELETE FAILED
>>>>>>> (swarm-clustergp27-ebhsalhb4bop-swarm_primary_master-tzgkh3ncmymw):
>>>>>>> Resource DELETE failed: resources[0]: (pymysql.err.InternalError) 
>>>>>>> (1213,
>>>>>>> u'Deadlock found when trying to get lock; try restarting 
>>>>>>> transaction')
>>>>>>> (Background on this error at: http://sqlalche.me/e/2j85)
>>>>>>> 2018-12-13 11:48:46.844 89595 INFO heat.engine.resource
>>>>>>> [req-9a43184f-77d8-4fad-ab9e-2b9826c10b70 - admin - default default]
>>>>>>> DELETE: ResourceGroup "swarm_primary_master"
>>>>>>> [6984db3c-3ac1-4afc-901f-21b3e7f230a7] Stack
>>>>>>> "swarm-clustergp27-ebhsalhb4bop" 
>>>>>>> [b43256fa-52e2-4613-ac15-63fd9340a8be]
>>>>>>>
>>>>>>>
>>>>>>> I read this issue was solved in heat version 10 but seems not.
>>>>>>
>>>>>> The patch for bug 1732969, which is in Queens, is probably the fix
>>>>>> you're referring to: https://review.openstack.org/#/c/521170/1
>>>>>>
>>>>>> The traceback in that bug included the SQL statement that was 
>>>>>> failing.
>>>>>> I'm not sure if that isn't included in your traceback because 
>>>>>> SQLAlchemy
>>>>>> didn't report it, or if it's because that traceback is actually 
>>>>>> from the
>>>>>> parent stack. If you have a traceback from the original failure in 
>>>>>> the
>>>>>> child stack that would be useful. If there's a way to turn on more
>>>>>> detailed reporting of errors in SQLAlchemy that would also be useful.
>>>>>>
>>>>>> Since this is a delete, it's possible that we need a 
>>>>>> retry-on-deadlock
>>>>>> on the resource_delete() function also (though resource_update() is
>>>>>> actually used more during a delete to update the status).
>>>>>>
>>>>>> - ZB
>>>>>>
>>
>