Fix a bug when the same method could be run concurrently by 2 threads

(Cherry-pick from Release-0.5)

The problem was caused by the fact that the eventlet switching occurs
not immediately when the event.send() is executed, but in some time
afterwards (when some blocking operation is run). This time may be
sufficient for the lock to be re-aquired by the same thread.
For example, imagine there are two green threads A and B attempting to
simultaneously run a method M of the same object. Consider the following
scenario:
1) A is executed first and acquires the lock, then executes M
2) B detects that the lock is taken and awaits on the event.wait()
3) A is finished with M, releases the lock and calls event.send() to
   allow B to proceed
4) Switching does not happen immediately and A proceeds till some
   blocking operation
5) Switching occurs, B is activated and acquires the lock on M
The problem happens because on the step (5) B assumes that the lock was
indeed released by A on step (3). However, as some actions may take
place during (4), they may include requiring the lock again. B does not
recheck this, which causes the twin ownership of the lock.
To resolve this B needs to always recheck the lock after re-activating
from wait, and, if the lock is still taken, wait again.

Closes-Bug: #1316551

Debugging and fixing of this issue required to add some logging, which
may be useful for other debugging scenarios: the output contain the
information about green-thread id, the method and the object it is run
for.
So, this partially targets blueprint improve-engine-logging

Change-Id: I06ed15a2b3642da2f85a254526638ac05be060ce

muranoapi/dsl/executor.py

@@ -30,6 +30,10 @@ import muranoapi.dsl.murano_object as murano_object
 import muranoapi.dsl.object_store as object_store
 import muranoapi.dsl.yaql_functions as yaql_functions
 
+from muranoapi.openstack.common import log as logging
+
+LOG = logging.getLogger(__name__)
+
 
 class MuranoDslExecutor(object):
     def __init__(self, class_loader, environment=None):
@@ -111,20 +115,30 @@ class MuranoDslExecutor(object):
         method_id = id(body)
         this_id = this.object_id
 
-        event, marker = self._locks.get((method_id, this_id), (None, None))
-        if event:
-            if marker == thread_marker:
-                return self._invoke_method_implementation_gt(
-                    body, this, params, murano_class, context)
-            event.wait()
+        while True:
+            event, marker = self._locks.get((method_id, this_id), (None, None))
+            if event:
+                if marker == thread_marker:
+                    return self._invoke_method_implementation_gt(
+                        body, this, params, murano_class, context)
+                event.wait()
+            else:
+                break
 
         event = eventlet.event.Event()
         self._locks[(method_id, this_id)] = (event, thread_marker)
+        # noinspection PyProtectedMember
+        method_info = "{0}.{1} ({2})".format(murano_class.name, method._name,
+                                             hash((method_id, this_id)))
+        LOG.debug(
+            "{0}: Begin execution: {1}".format(thread_marker, method_info))
         gt = eventlet.spawn(self._invoke_method_implementation_gt, body,
                             this, params, murano_class, context,
                             thread_marker)
         result = gt.wait()
         del self._locks[(method_id, this_id)]
+        LOG.debug(
+            "{0}: End execution: {1}".format(thread_marker, method_info))
         event.send()
         return result