From c2ae38b9706a85760c5d3abbe527eaca01294fcc Mon Sep 17 00:00:00 2001
From: Håkon Hallingstad <hakon@verizonmedia.com>
Date: Sun, 11 Oct 2020 15:49:56 +0200
Subject: Deadlock detection

Just before Lock.acquire() is invoked, the locks within the process is queried
to see if a "deadlock" will occur: The current thread waiting to acquire lock
path P1, which is held by thread T1 waiting on acquiring a lock at path P2,
etc, until a thread is waiting for a lock held by the current thread.

Even without this PR the deadlock would resolve itself automatically because
all locks are acquired with timeouts.  However, this PR 1. resolves the
deadlock immediately, and 2. leaves a log trace (hopefully from the exception)
to allow us to refactor code to avoid such deadlocks.
---
 .../com/yahoo/vespa/curator/stats/LockTest.java    | 75 ++++++++++++++++++++--
 1 file changed, 70 insertions(+), 5 deletions(-)

(limited to 'zkfacade/src/test')

diff --git a/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LockTest.java b/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LockTest.java
index f440c2cfad8..c28691fe655 100644
--- a/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LockTest.java
+++ b/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LockTest.java
@@ -1,6 +1,7 @@
 // Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
 package com.yahoo.vespa.curator.stats;
 
+import com.google.common.util.concurrent.UncheckedTimeoutException;
 import com.yahoo.vespa.curator.Lock;
 import org.apache.curator.framework.recipes.locks.InterProcessLock;
 import org.junit.Before;
@@ -9,6 +10,9 @@ import org.junit.Test;
 import java.time.Duration;
 import java.util.List;
 import java.util.Optional;
+import java.util.concurrent.Executors;
+import java.util.concurrent.TimeUnit;
+import java.util.concurrent.locks.ReentrantLock;
 
 import static org.junit.Assert.assertEquals;
 import static org.junit.Assert.assertNotNull;
@@ -27,7 +31,7 @@ public class LockTest {
     private final InterProcessLock mutex = mock(InterProcessLock.class);
     private final String lockPath = "/lock/path";
     private final String lock2Path = "/lock2/path";
-    private final Duration acquireTimeout = Duration.ofSeconds(10);
+    private static final Duration acquireTimeout = Duration.ofMinutes(10);
     private final Lock lock = new Lock(lockPath, mutex);
     private final Lock lock2 = new Lock(lock2Path, mutex);
 
@@ -176,9 +180,6 @@ public class LockTest {
     public void nestedLocks() throws Exception {
         when(mutex.acquire(anyLong(), any())).thenReturn(true);
 
-        String lockPath2 = "/lock/path/2";
-        Lock lock2 = new Lock(lockPath2, mutex);
-
         lock.acquire(acquireTimeout);
         lock2.acquire(acquireTimeout);
 
@@ -188,10 +189,74 @@ public class LockTest {
         assertEquals(2, lockAttempts.size());
         assertEquals(lockPath, lockAttempts.get(0).getLockPath());
         assertEquals(LockAttempt.LockState.ACQUIRED, lockAttempts.get(0).getLockState());
-        assertEquals(lockPath2, lockAttempts.get(1).getLockPath());
+        assertEquals(lock2Path, lockAttempts.get(1).getLockPath());
         assertEquals(LockAttempt.LockState.ACQUIRED, lockAttempts.get(1).getLockState());
 
         lock.close();
         lock.close();
     }
+
+    @Test
+    public void deadlock() throws Exception {
+        var lockPath1 = "/lock/path/1";
+        var lockPath2 = "/lock/path/2";
+
+        var lock1 = new Lock(lockPath1, new InterProcessMutexMock());
+        var lock2 = new Lock(lockPath2, new InterProcessMutexMock());
+
+        lock2.acquire(acquireTimeout);
+
+        Thread thread = Executors.defaultThreadFactory().newThread(() -> threadMain(lock1, lock2));
+        thread.setName("LockTest-async-thread");
+        thread.start();
+
+        LockStats globalStats = LockStats.getGlobal();
+        ThreadLockStats asyncThreadStats = globalStats.getForThread(thread);
+        while (true) {
+            Optional<LockAttempt> bottomMostOngoingLockAttempt = asyncThreadStats.getBottomMostOngoingLockAttempt();
+            if (bottomMostOngoingLockAttempt.isPresent() &&
+                    bottomMostOngoingLockAttempt.get().getLockPath().equals(lockPath2)) {
+                break;
+            }
+
+            try {
+                Thread.sleep(1);
+            } catch (InterruptedException e) { }
+        }
+
+        try {
+            lock1.acquire(acquireTimeout);
+            fail();
+        } catch (UncheckedTimeoutException e) {
+            assertEquals(
+                    "Unexpected timeout exception message: " + e.getMessage(),
+                    "Deadlock detected: Thread main, " +
+                            "trying to acquire lock /lock/path/1 held by thread LockTest-async-thread, " +
+                            "trying to acquire lock /lock/path/2 held by thread main",
+                    e.getMessage());
+        }
+
+        // Unlock, which unblocks thread
+        lock2.close();
+        thread.join();
+    }
+
+    private static void threadMain(Lock lock1, Lock lock2) {
+        lock1.acquire(acquireTimeout);
+
+        // This will block
+        lock2.acquire(acquireTimeout);
+
+        lock2.close();
+
+        lock1.close();
+    }
+
+    private static class InterProcessMutexMock implements InterProcessLock {
+        private final ReentrantLock lock = new ReentrantLock();
+        @Override public void acquire() throws Exception { lock.lock(); }
+        @Override public boolean acquire(long time, TimeUnit unit) throws Exception { acquire(); return true; }
+        @Override public void release() throws Exception { lock.unlock(); }
+        @Override public boolean isAcquiredInThisProcess() { return lock.isLocked(); }
+    }
 }
-- 
cgit v1.2.3