Skip to content
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
29 commits
Select commit Hold shift + click to select a range
d2df7c6
add paired log assertion verb and pass env overrides through restart …
AlexKehayov Mar 28, 2026
023032d
refactor LogContainmentPairTimeframeOp
AlexKehayov Mar 28, 2026
1854bde
revert restartAtNextConfigVersion changes
AlexKehayov Mar 29, 2026
e7eccca
removed leaky and changed props in build gradle
AlexKehayov Mar 29, 2026
478de53
run quiescence in a separate task
AlexKehayov Mar 29, 2026
41dcd9f
Merge branch 'main' into 24398-quiescence-follow-up
AlexKehayov Mar 29, 2026
2864f7b
added missing prop overrides to hapiTestQuiescence
AlexKehayov Mar 29, 2026
df8c913
Merge remote-tracking branch 'origin/24398-quiescence-follow-up' into…
AlexKehayov Mar 29, 2026
6335853
enable quiescence in CI
AlexKehayov Mar 29, 2026
c31cb8a
move quiescence to time consuming
AlexKehayov Mar 29, 2026
71c19ac
move quiescence to a separate task
AlexKehayov Mar 29, 2026
1179dff
disable tss.forceHandoffs
AlexKehayov Mar 30, 2026
170aca3
removed tss overrides
AlexKehayov Mar 30, 2026
56a492e
added rerun flags
AlexKehayov Mar 30, 2026
f9f8eca
Merge branch 'main' into 24398-quiescence-follow-up
AlexKehayov Mar 30, 2026
6d7b67f
made heartbeat tick after block closes and signs
AlexKehayov Mar 30, 2026
28fc9c2
fix quiescence bug
AlexKehayov Mar 30, 2026
80348b2
resolved hanging
AlexKehayov Mar 30, 2026
874dade
revert ticks
AlexKehayov Mar 31, 2026
3a00302
skip epoch TCT in quiescence status check to prevent false DONT_QUIESCE
AlexKehayov Mar 31, 2026
bc652dc
Merge branch 'main' into 24398-quiescence-follow-up
AlexKehayov Mar 31, 2026
a342162
spotless
AlexKehayov Mar 31, 2026
9f64026
moved hapiTestQuiescence to Time consuming
AlexKehayov Mar 31, 2026
6e05047
Merge branch 'main' into 24398-quiescence-follow-up
AlexKehayov Apr 1, 2026
bd54e9a
Merge branch 'main' into 24398-quiescence-follow-up
AlexKehayov Apr 1, 2026
286da9c
isolate quiescence test into dedicated CI task without modifying core…
AlexKehayov Apr 1, 2026
c500d26
Merge branch 'main' into 24398-quiescence-follow-up
AlexKehayov Apr 2, 2026
b2c5753
Merge branch 'main' into 24398-quiescence-follow-up
AlexKehayov Apr 2, 2026
583cd04
Merge branch 'main' into 24398-quiescence-follow-up
AlexKehayov Apr 2, 2026
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion .github/workflows/zxc-execute-hapi-tests.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -621,7 +621,7 @@ jobs:
env:
LC_ALL: en.UTF-8
LANG: en_US.UTF-8
run: ${GRADLE_EXEC} hapiTestTimeConsuming && ${GRADLE_EXEC} hapiTestTimeConsumingSerial
run: ${GRADLE_EXEC} hapiTestTimeConsuming && ${GRADLE_EXEC} hapiTestTimeConsumingSerial && ${GRADLE_EXEC} hapiTestQuiescence

- name: Publish HAPI Test (Time Consuming) Report
uses: step-security/publish-unit-test-result-action@7dff603bf17ef13dee847147bef8d7cd1728b566 # v2.22.0
Expand Down
8 changes: 7 additions & 1 deletion hedera-node/test-clients/build.gradle.kts
Original file line number Diff line number Diff line change
Expand Up @@ -63,7 +63,7 @@ tasks.test {
}

val miscTags =
"!(INTEGRATION|CRYPTO|TOKEN|RESTART|UPGRADE|SMART_CONTRACT|ND_RECONNECT|LONG_RUNNING|STATE_THROTTLING|ISS|BLOCK_NODE|SIMPLE_FEES|ATOMIC_BATCH|WRAPS_DOWNLOAD)"
"!(INTEGRATION|CRYPTO|TOKEN|RESTART|UPGRADE|SMART_CONTRACT|ND_RECONNECT|LONG_RUNNING|STATE_THROTTLING|ISS|BLOCK_NODE|SIMPLE_FEES|ATOMIC_BATCH|WRAPS_DOWNLOAD|QUIESCENCE)"
val miscTagsSerial = "$miscTags&SERIAL"

val prCheckTags =
Expand All @@ -74,6 +74,7 @@ val prCheckTags =
"hapiTestToken" to "TOKEN",
"hapiTestTokenSerial" to "(TOKEN&SERIAL)",
"hapiTestRestart" to "RESTART|UPGRADE",
"hapiTestQuiescence" to "QUIESCENCE",
"hapiTestSmartContract" to "SMART_CONTRACT",
"hapiTestSmartContractSerial" to "(SMART_CONTRACT&SERIAL)",
"hapiTestNDReconnect" to "ND_RECONNECT",
Expand Down Expand Up @@ -102,6 +103,7 @@ val remoteCheckTags =
listOf(
"hapiTestIss",
"hapiTestRestart",
"hapiTestQuiescence",
"hapiTestWrapsDownload",
"hapiTestToken",
"hapiTestTokenSerial",
Expand Down Expand Up @@ -135,6 +137,7 @@ val prCheckStartPorts =
"hapiTestSimpleFeesSerial" to "29000",
"hapiTestAtomicBatchSerial" to "29200",
"hapiTestSmartContractSerial" to "29400",
"hapiTestQuiescence" to "29600",
)
val prCheckPropOverrides =
mapOf(
Expand Down Expand Up @@ -170,6 +173,8 @@ val prCheckPropOverrides =
"hapiTestCutover" to
"tss.hintsEnabled=false,tss.historyEnabled=false,tss.wrapsEnabled=false,tss.initialCrsParties=8,staking.periodMins=16",
"hapiTestTimeConsumingSerial" to "nodes.nodeRewardsEnabled=false,quiescence.enabled=true",
"hapiTestQuiescence" to
"tss.forceMockSignatures=true,blockStream.quiescedHeartbeatInterval=PT3S,quiescence.enabled=true,staking.periodMins=1440,nodes.nodeRewardsEnabled=false",
"hapiTestStateThrottling" to "nodes.nodeRewardsEnabled=false,quiescence.enabled=true",
"hapiTestMiscRecords" to
"blockStream.streamMode=RECORDS,nodes.nodeRewardsEnabled=false,quiescence.enabled=true,blockStream.enableStateProofs=true,block.stateproof.verification.enabled=true,hedera.transaction.maximumPermissibleUnhealthySeconds=5",
Expand Down Expand Up @@ -203,6 +208,7 @@ val prCheckNetSizeOverrides =
"hapiTestSmartContractSerial" to "3",
"hapiTestAtomicBatch" to "3",
"hapiTestAtomicBatchSerial" to "3",
"hapiTestQuiescence" to "3",
)

tasks {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ private TestTags() {
public static final String STATE_THROTTLING = "STATE_THROTTLING";
public static final String TOKEN = "TOKEN";
public static final String RESTART = "RESTART";
public static final String QUIESCENCE = "QUIESCENCE";
public static final String ND_RECONNECT = "ND_RECONNECT";
public static final String UPGRADE = "UPGRADE";
public static final String ISS = "ISS";
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -163,6 +163,7 @@
import com.hedera.services.bdd.spec.utilops.pauses.HapiSpecWaitUntil;
import com.hedera.services.bdd.spec.utilops.pauses.HapiSpecWaitUntilNextBlock;
import com.hedera.services.bdd.spec.utilops.streams.LogContainmentOp;
import com.hedera.services.bdd.spec.utilops.streams.LogContainmentPairTimeframeOp;
import com.hedera.services.bdd.spec.utilops.streams.LogContainmentTimeframeOp;
import com.hedera.services.bdd.spec.utilops.streams.LogValidationOp;
import com.hedera.services.bdd.spec.utilops.streams.StreamValidationOp;
Expand Down Expand Up @@ -3512,6 +3513,42 @@ public static LogContainmentTimeframeOp assertHgcaaLogContainsTimeframe(
selector, APPLICATION_LOG, Arrays.asList(patterns), startTimeSupplier, timeframe, waitTimeout);
}

/**
* Asserts that two log patterns appear in order in the specified node's HGCAA log within a timeframe,
* with a time gap between them that falls within {@code [minGap, maxGap]}. This is useful for
* distinguishing real state transitions (e.g. sustained quiescence) from transient flickers.
*
* @param selector the node selector
* @param startTimeSupplier supplier for the start time of the timeframe
* @param timeframe the duration of the timeframe window to search
* @param waitTimeout the duration to wait (polling) for the pair to appear
* @param firstPattern the first pattern to match
* @param secondPattern the second pattern to match (must appear after the first)
* @param minGap minimum required time gap between the two pattern matches
* @param maxGap maximum allowed time gap between the two pattern matches
* @return a new LogContainmentPairTimeframeOp
*/
public static LogContainmentPairTimeframeOp assertHgcaaLogContainsPairTimeframe(
@NonNull final NodeSelector selector,
@NonNull final Supplier<Instant> startTimeSupplier,
@NonNull final Duration timeframe,
@NonNull final Duration waitTimeout,
@NonNull final String firstPattern,
@NonNull final String secondPattern,
@NonNull final Duration minGap,
@NonNull final Duration maxGap) {
return new LogContainmentPairTimeframeOp(
selector,
APPLICATION_LOG,
startTimeSupplier,
timeframe,
waitTimeout,
firstPattern,
secondPattern,
minGap,
maxGap);
}

public static CustomSpecAssert valueIsInRange(
final double value, final double lowerBoundInclusive, final double upperBoundExclusive) {
return assertionsHold((spec, opLog) -> {
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,200 @@
// SPDX-License-Identifier: Apache-2.0
package com.hedera.services.bdd.spec.utilops.streams;

import static com.hedera.services.bdd.spec.transactions.TxnUtils.doIfNotInterrupted;
import static java.util.Objects.requireNonNull;
import static java.util.concurrent.TimeUnit.MILLISECONDS;

import com.hedera.services.bdd.junit.hedera.ExternalPath;
import com.hedera.services.bdd.junit.hedera.NodeSelector;
import com.hedera.services.bdd.spec.HapiSpec;
import com.hedera.services.bdd.spec.utilops.UtilOp;
import edu.umd.cs.findbugs.annotations.NonNull;
import edu.umd.cs.findbugs.annotations.Nullable;
import java.io.BufferedReader;
import java.nio.file.Files;
import java.nio.file.NoSuchFileException;
import java.time.Duration;
import java.time.Instant;
import java.time.LocalDateTime;
import java.time.ZoneId;
import java.time.format.DateTimeFormatter;
import java.util.concurrent.atomic.AtomicLong;
import java.util.function.Supplier;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.junit.jupiter.api.Assertions;

/**
* A {@link UtilOp} that validates that the selected nodes' application or platform log contains
* two patterns appearing in order within a specified timeframe, with a time gap between them
* that falls within {@code [minGap, maxGap]}, reading the log incrementally.
*
* <p>This is useful for asserting that a state transition (e.g. quiescence) lasted a meaningful
* duration, distinguishing real transitions from transient flickers that resolve in milliseconds.
*/
public class LogContainmentPairTimeframeOp extends UtilOp {
private static final Logger log = LogManager.getLogger(LogContainmentPairTimeframeOp.class);
private static final DateTimeFormatter LOG_TIMESTAMP_FORMAT =
DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss.SSS");

private final NodeSelector selector;
private final ExternalPath path;
private final String firstPattern;
private final String secondPattern;
private final Supplier<Instant> startTimeSupplier;
private final Duration timeframe;
private final Duration waitTimeout;
private final Duration minGap;
private final Duration maxGap;

// State for incremental reading
private final AtomicLong linesProcessed = new AtomicLong(0L);
// Persists across polls so a firstPattern match on one poll can pair with a secondPattern on the next
@Nullable
private Instant candidateFirstTime;

public LogContainmentPairTimeframeOp(
@NonNull final NodeSelector selector,
@NonNull final ExternalPath path,
@NonNull final Supplier<Instant> startTimeSupplier,
@NonNull final Duration timeframe,
@NonNull final Duration waitTimeout,
@NonNull final String firstPattern,
@NonNull final String secondPattern,
@NonNull final Duration minGap,
@NonNull final Duration maxGap) {
if (path != ExternalPath.APPLICATION_LOG
&& path != ExternalPath.BLOCK_NODE_COMMS_LOG
&& path != ExternalPath.SWIRLDS_LOG) {
throw new IllegalArgumentException(path + " is not a log");
}
this.path = requireNonNull(path);
this.selector = requireNonNull(selector);
this.startTimeSupplier = requireNonNull(startTimeSupplier);
this.timeframe = requireNonNull(timeframe);
this.waitTimeout = requireNonNull(waitTimeout);
this.firstPattern = requireNonNull(firstPattern);
this.secondPattern = requireNonNull(secondPattern);
this.minGap = requireNonNull(minGap);
this.maxGap = requireNonNull(maxGap);
if (minGap.compareTo(maxGap) > 0) {
throw new IllegalArgumentException("minGap (" + minGap + ") must be <= maxGap (" + maxGap + ")");
}
}

@Override
protected boolean submitOp(@NonNull final HapiSpec spec) throws Throwable {
final Instant startTime = startTimeSupplier.get();
if (startTime == null) {
throw new IllegalStateException("Start time supplier returned null");
}
final Instant endTime = startTime.plus(timeframe);
final Instant timeoutDeadline = Instant.now().plus(waitTimeout);

log.info(
"Starting paired log check: StartTime={}, Timeframe={}, Timeout={}, "
+ "FirstPattern='{}', SecondPattern='{}', MinGap={}, MaxGap={}",
startTime,
timeframe,
waitTimeout,
firstPattern,
secondPattern,
minGap,
maxGap);

while (Instant.now().isBefore(timeoutDeadline)) {
// Process new log lines for all selected nodes
final boolean[] matched = {false};
final Instant[] matchedTimes = new Instant[2];
spec.targetNetworkOrThrow().nodesFor(selector).forEach(node -> {
if (!matched[0]) {
findMatchingPairInNodeLog(node.getExternalPath(path), startTime, endTime, matched, matchedTimes);
}
});

if (matched[0]) {
log.info(
"Found matching pair: '{}' at {} and '{}' at {} (gap={})",
firstPattern,
matchedTimes[0],
secondPattern,
matchedTimes[1],
Duration.between(matchedTimes[0], matchedTimes[1]));
return false; // Success
}

if (Instant.now().isBefore(timeoutDeadline)) {
doIfNotInterrupted(() -> MILLISECONDS.sleep(1000));
}
}

Assertions.fail(String.format(
"Did not find a matching pair of log patterns within the timeframe. "
+ "StartTime=%s, Timeframe=%s, Timeout=%s, FirstPattern='%s', SecondPattern='%s', "
+ "MinGap=%s, MaxGap=%s",
startTime, timeframe, waitTimeout, firstPattern, secondPattern, minGap, maxGap));

return false; // Should not be reached due to Assertions.fail
}

private void findMatchingPairInNodeLog(
@NonNull final java.nio.file.Path logPath,
@NonNull final Instant startTime,
@NonNull final Instant endTime,
@NonNull final boolean[] matched,
@NonNull final Instant[] matchedTimes) {
long newLinesRead = 0;
try (BufferedReader reader = Files.newBufferedReader(logPath)) {
// Skip lines already processed and process the rest
try (var linesStream = reader.lines().skip(linesProcessed.get())) {
final var iterator = linesStream.iterator();
while (iterator.hasNext()) {
final String line = iterator.next();
newLinesRead++;

LocalDateTime logTime;
Instant logInstant;
try {
// Basic check for timestamp format length
if (line.length() < 23) continue;
final String timestamp = line.substring(0, 23);
logTime = LocalDateTime.parse(timestamp, LOG_TIMESTAMP_FORMAT);
logInstant = logTime.atZone(ZoneId.systemDefault()).toInstant();
} catch (Exception e) {
continue;
}

// Check if the log entry is within the timeframe
if (logInstant.isAfter(startTime) && logInstant.isBefore(endTime)) {
// Check for firstPattern — always update candidate to the latest match
if (line.contains(firstPattern)) {
candidateFirstTime = logInstant;
}
// Check for secondPattern only if we have a candidate firstPattern
if (candidateFirstTime != null && line.contains(secondPattern)) {
final Duration gap = Duration.between(candidateFirstTime, logInstant);
if (gap.compareTo(minGap) >= 0 && gap.compareTo(maxGap) <= 0) {
matched[0] = true;
matchedTimes[0] = candidateFirstTime;
matchedTimes[1] = logInstant;
break;
}
// Gap didn't qualify — reset candidate so we look for the next pair
candidateFirstTime = null;
}
}
}
}
} catch (NoSuchFileException nsfe) {
log.warn("Log file not found: {}. Will retry.", logPath);
// File might appear later, do nothing and let the loop retry
} catch (Exception e) {
log.error("Error reading log file {}. Candidate so far: {}", logPath, candidateFirstTime, e);
// Rethrow or handle as appropriate for the test framework
throw new RuntimeException("Error during log processing for " + logPath, e);
}
// Update the total lines processed for this file
linesProcessed.addAndGet(newLinesRead);
}
}
Loading
Loading