fix: a reveal and the access-log writer no longer wait for each other

A reveal, and the start, end and expiry of a break-glass session, hold the
runtime's monitor from their first check to their last write. Asking for a
classification (SecuredDataRuntime.classificationRows, and
activeRetentionRules) took the same monitor, and every thread asks: core
asks for every field it decides on and for every filter criterion of every
query, including the queries made inside this QBit's own writes.

So a thread that asked while holding another lock of this QBit could not be
answered during a reveal, and if the reveal needed that lock next, both
waited for ever. The access-log writer is such a thread. It holds the
anomaly counters while it inserts a row; the insert counts earlier rows and
writes an audit, both queries with criteria. A reveal inserts its own
access-log row.

    reveal:  runtime's monitor, then the anomaly counters
    writer:  the anomaly counters, then the runtime's monitor

Seen in a host on PostgreSQL: a person read a record with a masked field and
revealed it at once; the writer's tick drained the read's log rows at the
same moment. The request and the writer deadlocked (thread dump: the request
in SystemWrites.insertOne under RevealService.reveal, the writer in
SecuredDataRuntime.classificationRows under AuditAction.fetchIdFromName
under its own insert), and every later request blocked in
classificationRows. The same order existed between a reveal and the
resolver's monitor, and the key source's.

- The rule rows have a lock of their own (ruleLock), held only while they
  are answered or read. A read is a query made as the system and takes none
  of the QBit's other locks, so nothing that holds ruleLock waits for one.
- The runtime's monitor is left to what it was for: one reveal or
  break-glass change at a time.

Tests (SecuredDataLockOrderTest, on H2 in PostgreSQL mode with the audit
tables): a thread is parked inside a reveal, and inside the start of a
break-glass session, holding the runtime's monitor; the access-log writer
must drain its queue and another thread must be told a classification and
the active retention rules meanwhile, and then the parked operation must
finish. Both tests fail without the fix (neither thread finishes).

Co-Authored-By: Claude Fable 5.2 <noreply@anthropic.com>

CHANGELOG.md

@@ -4,6 +4,10 @@ All notable changes are documented here, following [Keep a Changelog](https://ke
 
 ## [Unreleased]
 
+### Fixed: a reveal and the access-log writer waiting for each other
+- A reveal, or the start, end or expiry of a break-glass session, no longer deadlocks with a thread that asks for a classification while it holds another lock of this QBit. The access-log writer is such a thread: it holds the anomaly counters while it inserts a row, and that insert asks for classifications (it counts earlier rows and writes an audit, both queries with criteria). A reveal holds the runtime's monitor and then inserts its own access-log row. When both happened at once, neither finished, and neither did any later request, because every request asks for a classification. A person who opens a record with a masked field and reveals it straight away does both at once.
+- The rule rows a node keeps (classifications, active retention rules) have a lock of their own, held only while they are answered or read. Asking for a classification no longer takes the monitor that reveal and break-glass hold for their whole operation.
+
 ### Fixed: rule reads that ask for their own rows
 - Reading the rule rows a node keeps (classifications, active retention rules, policies) no longer recurses when code that runs inside that read asks for the same rows. Another QBit's virtual field value provider, or a post-query customizer, on a secured-data table that ran a query with filter criteria did exactly that: with one classification row present, every request that needed a classification ended in a `StackOverflowError`.
 - The QBit's system reads of its own tables (`SystemWrites.query`, the audit key lookup) name the stored fields of the table, so core runs no virtual field value provider inside them.

pom.xml

@@ -25,7 +25,7 @@
       <qqq.version>4.1.0-RC.26</qqq.version> <!-- feeds qbit-build-parent's qqq-bom-pom import -->
       <!-- QQQ 4.1.0-RC.15 ships UI API 1.6.0, field access and audit value protection -->
       <qqq.snapshot.version>4.1.0-RC.26</qqq.snapshot.version>
-      <revision>0.1.0-SNAPSHOT</revision>
+      <revision>0.1.0-RC.7</revision>
       <maven.compiler.source>21</maven.compiler.source>
       <maven.compiler.target>21</maven.compiler.target>
       <jacoco.version>0.8.15</jacoco.version>

src/main/java/com/kingsrook/qbits/secureddata/RuleRows.java

@@ -32,11 +32,12 @@ import com.kingsrook.qqq.backend.core.model.data.QRecord;
  ** SecuredDataRuntime.MAX_RULE_AGE, and safe against a read that asks for the
  ** same rows again.
  **
- ** Not synchronized: every call must be made holding the owner's monitor (the
- ** runtime for classifications and retention rules, the resolver for policies).
- ** That monitor is what makes the re-entry answer below private to one thread:
- ** while a read is running, only the thread running it can get in here; every
- ** other thread waits for the monitor and is given the rows that read returns.
+ ** Not synchronized: every call must be made holding the owner's lock (the
+ ** runtime's rule lock for classifications and retention rules, the resolver's
+ ** monitor for policies). That lock is what makes the re-entry answer below
+ ** private to one thread: while a read is running, only the thread running it
+ ** can get in here; every other thread waits for the lock and is given the rows
+ ** that read returns.
  **
  ** Re-entry: reading rule rows is itself a query, and anything that runs inside
  ** it (a table customizer, a record-security lookup, a value provider) may ask a

src/main/java/com/kingsrook/qbits/secureddata/SecuredDataRuntime.java

@@ -79,10 +79,24 @@ public class SecuredDataRuntime implements QSupplementalInstanceMetaData, AutoCl
    private final transient SecuredDataAccessLogger logger;
    private final transient SecuredDataAnomalies anomalies;
    /////////////////////////////////////////////////////////////////////////////////
-   // both are used only inside methods synchronized on this runtime: one monitor //
-   // for the two, because reading either may ask for the other                   //
+   // both are used only while holding ruleLock: one lock for the two, because    //
+   // reading either may ask for the other.                                       //
+   //                                                                             //
+   // It is a lock of its own, never this runtime's monitor. A reveal and the     //
+   // start, end and expiry of a break-glass session hold the runtime's monitor   //
+   // for their whole operation, and every thread asks for a classification all   //
+   // the time (core asks for every field it decides on and for every criterion   //
+   // of every query), including threads that hold another lock of this QBit: the //
+   // access-log writer inside the anomaly counters, the resolver, the key        //
+   // source. When the question needed the runtime's monitor, such a thread and   //
+   // a reveal that needed its lock next waited for each other for ever.          //
+   //                                                                             //
+   // ruleLock is held only while rule rows are answered or read. A read is a     //
+   // query made as the system: it takes none of the QBit's other locks, so no    //
+   // thread holding ruleLock ever waits for one of them.                         //
    /////////////////////////////////////////////////////////////////////////////////
-   private final transient RuleRows classificationRows = new RuleRows();
+   private final transient Object   ruleLock             = new Object();
+   private final transient RuleRows classificationRows   = new RuleRows();
    private final transient RuleRows activeRetentionRules = new RuleRows();
 
 
@@ -232,10 +246,13 @@ public class SecuredDataRuntime implements QSupplementalInstanceMetaData, AutoCl
     ** next call reads again. A question asked from inside the read itself (see
     ** RuleRows) is answered with the rules held when the read began.
     *******************************************************************************/
-   public synchronized List<QRecord> activeRetentionRules()
+   public List<QRecord> activeRetentionRules()
    {
-      return (activeRetentionRules.get(retentionVersion(), () -> SystemWrites.query(SecuredDataTables.RETENTION_RULE, new QQueryFilter()
-         .withCriteria(new QFilterCriteria("is_active", QCriteriaOperator.EQUALS, true)))));
+      synchronized(ruleLock)
+      {
+         return (activeRetentionRules.get(retentionVersion(), () -> SystemWrites.query(SecuredDataTables.RETENTION_RULE, new QQueryFilter()
+            .withCriteria(new QFilterCriteria("is_active", QCriteriaOperator.EQUALS, true)))));
+      }
    }
 
 
@@ -289,9 +306,12 @@ public class SecuredDataRuntime implements QSupplementalInstanceMetaData, AutoCl
     ** inside the read itself (see RuleRows) is answered with the rows held when
     ** the read began, and never starts another read.
     *******************************************************************************/
-   synchronized List<QRecord> classificationRows()
+   List<QRecord> classificationRows()
    {
-      return (classificationRows.get(classificationVersion(), () -> SystemWrites.query(SecuredDataTables.CLASSIFICATION, new QQueryFilter())));
+      synchronized(ruleLock)
+      {
+         return (classificationRows.get(classificationVersion(), () -> SystemWrites.query(SecuredDataTables.CLASSIFICATION, new QQueryFilter())));
+      }
    }
 
 

src/test/java/com/kingsrook/qbits/secureddata/SecuredDataLockOrderTest.java

@@ -0,0 +1,271 @@
+/*
+ * QQQ - Low-code Application Framework for Engineers.
+ * Copyright (C) 2021-2025.  Kingsrook, LLC
+ * 651 N Broad St Ste 205 # 6917 | Middletown DE 19709 | United States
+ * contact@kingsrook.com
+ * https://github.com/Kingsrook/
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     https://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package com.kingsrook.qbits.secureddata;
+
+
+import java.io.Serializable;
+import java.util.List;
+import java.util.concurrent.Callable;
+import java.util.concurrent.CountDownLatch;
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
+import java.util.concurrent.Future;
+import java.util.concurrent.TimeUnit;
+import java.util.concurrent.TimeoutException;
+import java.util.concurrent.atomic.AtomicBoolean;
+import java.util.concurrent.atomic.AtomicReference;
+import com.kingsrook.qbits.secureddata.breakglass.BreakGlassService;
+import com.kingsrook.qbits.secureddata.metadata.SecuredDataTables;
+import com.kingsrook.qbits.secureddata.reveal.RevealResult;
+import com.kingsrook.qbits.secureddata.reveal.RevealService;
+import com.kingsrook.qqq.backend.core.actions.ai.DataClassification;
+import com.kingsrook.qqq.backend.core.actions.permissions.fieldaccess.FieldAccessEvent;
+import com.kingsrook.qqq.backend.core.actions.permissions.fieldaccess.FieldAccessEventType;
+import com.kingsrook.qqq.backend.core.actions.permissions.fieldaccess.FieldAccessOutcome;
+import com.kingsrook.qqq.backend.core.context.QContext;
+import com.kingsrook.qqq.backend.core.model.data.QRecord;
+import com.kingsrook.qqq.backend.core.model.metadata.QInstance;
+import com.kingsrook.qqq.backend.core.model.metadata.tables.QTableMetaData;
+import com.kingsrook.qqq.backend.core.model.session.QSession;
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.Timeout;
+import static com.kingsrook.qbits.secureddata.SecuredDataTestSupport.CLOCK;
+import static com.kingsrook.qbits.secureddata.SecuredDataTestSupport.insert;
+import static com.kingsrook.qbits.secureddata.SecuredDataTestSupport.logs;
+import static com.kingsrook.qbits.secureddata.SecuredDataTestSupport.policyRow;
+import static org.assertj.core.api.Assertions.assertThat;
+import static org.assertj.core.api.Assertions.fail;
+
+
+/*******************************************************************************
+ ** A reveal, and the start, end and expiry of a break-glass session, hold the
+ ** runtime's monitor from their first check to their last write, so that two of
+ ** them cannot both pass a check (the daily allowance, one active session).
+ ** Every other thread asks this QBit for a classification all the time: core
+ ** asks for every field it decides on and for every filter criterion of every
+ ** query, including the queries made inside this QBit's own writes.
+ **
+ ** When that question needed the same monitor, a thread that asked it while
+ ** holding another of this QBit's locks could never be answered during a
+ ** reveal that was about to need that lock: the access-log writer holds the
+ ** anomaly counters' monitor while it inserts a row (the insert counts earlier
+ ** rows and writes an audit, both queries with criteria), and a reveal inserts
+ ** its own access-log row. Reveal: runtime, then counters. Writer: counters,
+ ** then runtime. Both waited for ever, and so did every later request, since
+ ** every request asks for a classification.
+ **
+ ** The rule rows now have a lock of their own that is held only while they are
+ ** read. These tests run on a relational database (H2 in PostgreSQL mode, with
+ ** the audit tables), where an insert really writes its audit. Each parks one
+ ** thread inside the operation, holding the runtime's monitor, and requires
+ ** the access-log writer and a classification question on other threads to
+ ** finish meanwhile; then the parked operation finishes too. Without the fix
+ ** the writer does not finish and the test fails after WAIT_SECONDS.
+ *******************************************************************************/
+@Timeout(180)
+class SecuredDataLockOrderTest
+{
+   private static final long WAIT_SECONDS = 20;
+
+   private final ExecutorService threads = Executors.newCachedThreadPool(work ->
+   {
+      Thread thread = new Thread(work, "lock-order-test");
+      thread.setDaemon(true);
+      return (thread);
+   });
+
+   private QInstance          instance;
+   private SecuredDataRuntime runtime;
+   private QSession           person;
+   private QTableMetaData     reading;
+   private Serializable       pk;
+
+   private final CountDownLatch          parked  = new CountDownLatch(1);
+   private final CountDownLatch          resume  = new CountDownLatch(1);
+   private final AtomicReference<Thread> working = new AtomicReference<>();
+   private final AtomicBoolean           heldTheRuntimesMonitor = new AtomicBoolean();
+
+
+
+   /*******************************************************************************
+    ** Let a parked thread go, then close; a runtime whose threads are stuck was
+    ** already taken out of the list (see abandon).
+    *******************************************************************************/
+   @AfterEach
+   void cleanup()
+   {
+      resume.countDown();
+      threads.shutdownNow();
+      RetentionTestSupport.close();
+   }
+
+
+
+   /*******************************************************************************
+    ** A reveal in progress holds up neither the access-log writer nor a question.
+    *******************************************************************************/
+   @Test
+   void theAccessLogWriterAndAClassificationQuestionFinishWhileARevealIsInProgress() throws Exception
+   {
+      setup();
+      Future<RevealResult> reveal = parkInside(() -> new RevealService().reveal("reading", pk, "notes", null, "Synthetic reveal; lock order test."));
+
+      othersFinishMeanwhile();
+
+      resume.countDown();
+      assertThat(reveal.get(WAIT_SECONDS, TimeUnit.SECONDS).value()).isEqualTo("test-notes");
+      assertThat(logs()).extracting(row -> row.getValueString("event_type")).contains("EXACT_MATCH_FILTER", "REVEAL");
+      assertThat(runtime.resolver().isRevealActive("reading", "notes", pk)).isTrue();
+   }
+
+
+
+   /*******************************************************************************
+    ** The same for the start of a break-glass session, which holds the same monitor.
+    *******************************************************************************/
+   @Test
+   void theAccessLogWriterAndAClassificationQuestionFinishWhileBreakGlassStarts() throws Exception
+   {
+      setup();
+      person.getPermissions().add(BreakGlassService.START + ".hasAccess");
+      Future<QRecord> started = parkInside(() -> new BreakGlassService().start("Synthetic break-glass session; lock order test.", 5, "reading", DataClassification.PHI));
+
+      othersFinishMeanwhile();
+
+      resume.countDown();
+      assertThat(started.get(WAIT_SECONDS, TimeUnit.SECONDS).getValueString("status")).isEqualTo("ACTIVE");
+      assertThat(logs()).extracting(row -> row.getValueString("event_type")).contains("EXACT_MATCH_FILTER", "BREAK_GLASS_START");
+   }
+
+
+
+   /*******************************************************************************
+    ** A relational instance with audit tables; a PII field one policy makes
+    ** revealable to the person; one row; and one search of that field waiting in
+    ** the access-log queue, as it waits after a person filters a list by it.
+    *******************************************************************************/
+   private void setup() throws Exception
+   {
+      instance = RetentionTestSupport.setup();
+      runtime = SecuredDataRuntime.current();
+      person = QContext.getQSession();
+      reading = instance.getTable("reading");
+      insert(SecuredDataTables.POLICY, policyRow("secured_data.admin", "PII", "REVEALABLE"));
+      pk = RetentionTestSupport.reading(120).getValue("id");
+
+      runtime.resolver().onAccess(new FieldAccessEvent().withType(FieldAccessEventType.EXACT_MATCH_FILTER).withOutcome(FieldAccessOutcome.MATCH)
+         .withTableName("reading").withFieldNames(List.of("notes")).withActionName("query").withRecordCount(1)
+         .withSearchValueFingerprints(List.of(runtime.resolver().fingerprintSearchValue("known"))));
+      assertThat(logs()).as("the search is queued, not yet written").extracting(row -> row.getValueString("event_type")).doesNotContain("EXACT_MATCH_FILTER");
+   }
+
+
+
+   /*******************************************************************************
+    ** Run the operation as the person on another thread and return once it is
+    ** parked at its first reading of the clock, which both operations make
+    ** inside their synchronized block.
+    *******************************************************************************/
+   private <T> Future<T> parkInside(Callable<T> operation) throws Exception
+   {
+      CLOCK.beforeInstant = () ->
+      {
+         if(Thread.currentThread() == working.get() && parked.getCount() == 1)
+         {
+            heldTheRuntimesMonitor.set(Thread.holdsLock(runtime));
+            parked.countDown();
+            try
+            {
+               resume.await();
+            }
+            catch(InterruptedException e)
+            {
+               Thread.currentThread().interrupt();
+            }
+         }
+      };
+      Future<T> future = threads.submit(() ->
+      {
+         QContext.init(instance, person);
+         try
+         {
+            working.set(Thread.currentThread());
+            return (operation.call());
+         }
+         finally
+         {
+            QContext.clear();
+         }
+      });
+      assertThat(parked.await(WAIT_SECONDS, TimeUnit.SECONDS)).as("the operation read the clock").isTrue();
+      assertThat(heldTheRuntimesMonitor).as("the operation is parked holding the runtime's monitor").isTrue();
+      return (future);
+   }
+
+
+
+   /*******************************************************************************
+    ** While the operation is parked: the access-log writer drains its queue (what
+    ** its worker does on every tick), and a thread that holds no lock is told
+    ** the classification of a field and the active retention rules.
+    *******************************************************************************/
+   private void othersFinishMeanwhile() throws Exception
+   {
+      Future<?> writer = threads.submit(() -> runtime.logger().flush());
+      Future<DataClassification> question = threads.submit(() ->
+      {
+         QContext.init(instance, person);
+         try
+         {
+            runtime.activeRetentionRules();
+            return (SecuredDataClassifications.effective(reading, "notes"));
+         }
+         finally
+         {
+            QContext.clear();
+         }
+      });
+
+      try
+      {
+         writer.get(WAIT_SECONDS, TimeUnit.SECONDS);
+         assertThat(question.get(WAIT_SECONDS, TimeUnit.SECONDS)).isEqualTo(DataClassification.PII);
+      }
+      catch(TimeoutException e)
+      {
+         abandon();
+         fail("A thread waited " + WAIT_SECONDS + " seconds for the monitor the parked operation holds (writer done: " + writer.isDone() + ", question done: " + question.isDone()
+            + "): the operation needs the lock that thread holds next, so neither would ever finish");
+      }
+   }
+
+
+
+   /*******************************************************************************
+    ** Threads of this runtime are stuck holding its locks: closing it would wait
+    ** for them, so it is left to the daemon threads instead of being closed.
+    *******************************************************************************/
+   private void abandon()
+   {
+      SecuredDataTestSupport.RUNTIMES.remove(runtime);
+   }
+}

src/test/java/com/kingsrook/qbits/secureddata/SecuredDataTestSupport.java

@@ -234,6 +234,7 @@ final class SecuredDataTestSupport
     *******************************************************************************/
    static void close()
    {
+      CLOCK.beforeInstant = null;
       RUNTIMES.forEach(SecuredDataRuntime::close);
       RUNTIMES.clear();
       QContext.clear();
@@ -248,6 +249,9 @@ final class SecuredDataTestSupport
    {
       Instant now = NOW;
 
+      /** Run on the reading thread before every reading of the clock; a test parks a thread at a known point with it. */
+      volatile Runnable beforeInstant;
+
 
 
       /*******************************************************************************
@@ -275,6 +279,11 @@ final class SecuredDataTestSupport
        *******************************************************************************/
       public Instant instant()
       {
+         Runnable hook = beforeInstant;
+         if(hook != null)
+         {
+            hook.run();
+         }
          return (now);
       }
    }