Compare commits

...
1 Commits
Author SHA1 Message Date
james.maesandClaude Fable 5.2 a366e8b96e fix: a reveal and the access-log writer no longer wait for each other
maven / build (push) Successful in 2m34s
build / maven (push) Successful in 2m34s
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>
2026-11-14 03:39:54 -06:00
5 changed files with 318 additions and 13 deletions

No files matched your search

+4
View File
@@ -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.
@@ -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
@@ -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())));
}
}
@@ -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);
}
}
@@ -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);
}
}