(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
c154f0501c