From cbd084c0e8c047a6edab8a98595d1af4b71a5bdf Mon Sep 17 00:00:00 2001
From: "James E. Blair" <jim@acmegating.com>
Date: Thu, 16 Mar 2023 11:40:47 -0700
Subject: [PATCH] DNM: extra cache debugging

This is to debug test races which appear in gate checks.

Change-Id: I7d841cf4ed660029a32e1a182ecd3d838208d4ce
---
 nodepool/zk/zookeeper.py | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/nodepool/zk/zookeeper.py b/nodepool/zk/zookeeper.py
index 53bc3a36e..42681d392 100644
--- a/nodepool/zk/zookeeper.py
+++ b/nodepool/zk/zookeeper.py
@@ -894,6 +894,7 @@ class NodeCache(NodepoolTreeCache):
         return self.zk._parseNodePath(path)
 
     def preCacheHook(self, event):
+        self.log.debug("NodeCache preCacheHook event %s", event)
         key = self.zk._parseNodeLockPath(event.event_data.path)
         if key is None:
             return
@@ -902,6 +903,8 @@ class NodeCache(NodepoolTreeCache):
         # Construct a key for the node object
         obj_key = (node_id,)
         node = self._cached_objects.get(obj_key)
+        self.log.debug("NodeCache preCacheHook contender %s %s",
+                       node, contender)
         if not node:
             return
         if event.event_type in (TreeEvent.NODE_ADDED,
@@ -2229,6 +2232,7 @@ class ZooKeeper(ZooKeeperBase):
             raise npe.ZKLockException("Did not get lock on %s" % path)
 
         node.lock = lock
+        self.log.debug("Locked: %s", node)
 
         # Do an in-place update of the node so we have the latest data.
         self.updateNode(node)
@@ -2246,6 +2250,7 @@ class ZooKeeper(ZooKeeperBase):
         if node.lock is None:
             raise npe.ZKLockException("Node %s does not hold a lock" % node)
         node.lock.release()
+        self.log.debug("Unlocked: %s", node)
         node.lock = None
 
     def forceUnlockNode(self, node):
@@ -2259,6 +2264,7 @@ class ZooKeeper(ZooKeeperBase):
             self.kazoo_client.delete(path, recursive=True)
         except kze.NoNodeError:
             pass
+        self.log.debug("Force unlocked: %s", node)
 
     def getNodeLockContenders(self, node):
         '''