use of com.datastax.fallout.util.Duration in project fallout by datastax.
the class DurationChecker method checkHistory.
@Override
public boolean checkHistory(Ensemble ensemble, Collection<Operation> history) {
long duration = 0;
Duration maxDuration = maxDurationSpec.value(this);
Duration minDuration = minDurationSpec.value(this);
List<String> phaseNames = phaseListSpec.value(this);
phaseNames = (phaseNames == null) ? new ArrayList<>() : phaseNames;
String description = "test";
if (phaseNames.isEmpty()) {
long start = 0;
long end = 0;
for (Operation op : history) {
if (start == 0) {
start = op.getTime();
}
end = op.getTime();
}
duration = end - start;
} else {
phaseNames.replaceAll(n -> n.trim());
description = "phase(s) " + phaseNames.toString();
// With multiple phases of interest, we have to keep track of context to avoid double-counting
int contextCounter = 0;
long start = 0;
for (Operation op : history) {
if (op.getType() == Operation.Type.start && phaseNames.contains(op.getProcess())) {
contextCounter++;
if (contextCounter == 1) {
start = op.getTime();
}
} else if (op.getType() == Operation.Type.end && phaseNames.contains(op.getProcess())) {
contextCounter--;
if (contextCounter == 0) {
duration += op.getTime() - start;
}
}
}
if (contextCounter > 0) {
logger().warn("DurationChecker didn't find the end of a phase. Calculated duration will not include any time for such phases.");
}
if (duration == 0) {
logger().warn("Total duration of {} is 0 - verify that the phase name(s) match the workload section of the test yaml.", description);
}
}
boolean durationOk = true;
if (maxDuration != null && duration > maxDuration.toNanos()) {
durationOk = false;
String convertedDuration = maxDuration.unit.convert(duration, TimeUnit.NANOSECONDS) + " " + maxDuration.unit.toString().toLowerCase();
logger().warn("Duration of {} was {} ({} nanos), exceeding the max specified in checker: {}", description, convertedDuration, duration, maxDuration.toString());
} else if (minDuration != null && duration < minDuration.toNanos()) {
durationOk = false;
String convertedDuration = minDuration.unit.convert(duration, TimeUnit.NANOSECONDS) + " " + minDuration.unit.toString().toLowerCase();
logger().warn("Duration of {} was {} ({} nanos), & was shorter than the min specified in checker: {}", description, convertedDuration, duration, minDuration.toString());
}
return durationOk;
}
use of com.datastax.fallout.util.Duration in project fallout by datastax.
the class KubernetesDeploymentManifestSpec method getManifestWaitOptions.
public ManifestWaitOptions getManifestWaitOptions(PropertyGroup properties) {
if (waitOptions != null) {
return waitOptions;
}
String condition = waitConditionSpec.value(properties);
Duration timeout = waitTimeoutSpec.value(properties);
switch(waitStrategySpec.value(properties)) {
case FIXED_DURATION:
return ManifestWaitOptions.fixedDuration(timeout);
case WAIT_ON_MANIFEST:
return ManifestWaitOptions.manifest(timeout, condition);
case WAIT_ON_PODS:
return ManifestWaitOptions.pods(timeout, condition, podLabelSpec.value(properties));
case WAIT_ON_CONTAINERS:
return ManifestWaitOptions.containers(timeout, containerNameSpec.value(properties), ignored -> expectedContainersSpec.value(properties));
case WAIT_ON_IMAGE:
return ManifestWaitOptions.image(timeout, condition, ignored -> imageNameSpec.value(properties));
default:
throw new InvalidConfigurationException("Invalid choice of Manifest Wait Strategy");
}
}
use of com.datastax.fallout.util.Duration in project fallout by datastax.
the class StableMetricsThresholdArtifactCheckerTest method shouldCatchOutOfRangeMetricWhenUsingWarmupOffset.
@Test
public void shouldCatchOutOfRangeMetricWhenUsingWarmupOffset() {
StableMetricsThresholdArtifactChecker stableMetricsThresholdArtifactChecker = new StableMetricsThresholdArtifactChecker();
Duration warmupOffset = Duration.seconds(60);
Instant now = Instant.now();
List<Result> metricResults = List.of(new Result(new Metric("metric_a", "123.123.123.134:8080", "some_job"), List.of(new Value(now, 100L), new Value(now.plusSeconds(60), 33L))), new Result(new Metric("metric_a", "123.123.123.135:8084", "some_job"), List.of(new Value(now, 100L))));
RangeQueryResult rangeQueryResult = new RangeQueryResult(new Data(metricResults));
boolean result = stableMetricsThresholdArtifactChecker.validateIfMetricValuesAreWithinRange(rangeQueryResult, warmupOffset, 0L, 15L);
assertThat(result).isFalse();
}
use of com.datastax.fallout.util.Duration in project fallout by datastax.
the class StableMetricsThresholdArtifactCheckerTest method shouldIgnoreOutOfRangeMetricIfItIsBeforeWarmupOffset.
@Test
public void shouldIgnoreOutOfRangeMetricIfItIsBeforeWarmupOffset() {
StableMetricsThresholdArtifactChecker stableMetricsThresholdArtifactChecker = new StableMetricsThresholdArtifactChecker();
Duration warmupOffset = Duration.seconds(60);
Instant now = Instant.now();
List<Result> metricResults = List.of(new Result(new Metric("metric_a", "123.123.123.134:8080", "some_job"), List.of(new Value(now, 100L), new Value(now.plusSeconds(60), 5L))), new Result(new Metric("metric_a", "123.123.123.135:8084", "some_job"), List.of(new Value(now, 15L))));
RangeQueryResult rangeQueryResult = new RangeQueryResult(new Data(metricResults));
boolean result = stableMetricsThresholdArtifactChecker.validateIfMetricValuesAreWithinRange(rangeQueryResult, warmupOffset, 0L, 15L);
assertThat(result).isTrue();
}
use of com.datastax.fallout.util.Duration in project fallout by datastax.
the class NodeResponse method awaitAsync.
/**
* An asynchronous wait.
*
* The future will complete when isCompleted() returns true
*
* Many processes can be waited on via one shared worker thread
*
* @see Utils#awaitConditionAsync
*/
public CompletableFuture<Boolean> awaitAsync(WaitOptionsAdjuster adjuster) {
WaitOptions waitOptions = createWaitOptions();
adjuster.adjust(waitOptions);
final Logger logger = waitOptions.logger(this);
final Pair<Duration, Optional<Duration>> timeouts = waitOptions.effectiveTimeouts();
final Duration timeout = timeouts.getLeft();
final Optional<Duration> noOutputTimeout = timeouts.getRight();
String additionalInfo = noOutputTimeout.map(t -> "no-output-timeout: " + t.toHM() + ", ").orElse("");
logger.info("Waiting for command ({}hard-timeout: {}): {}", additionalInfo, timeout.toHM(), command);
if (asyncWaitStarted) {
String logMsg = "awaitAsync on already awaited NodeResponse: " + command;
logger.warn(logMsg);
}
asyncWaitStarted = true;
class Context {
static final int MAX_LAST_LINES = 20;
final BufferedReader stream;
final String type;
final Consumer<String> consumer;
final EvictingQueue<String> lastLines = EvictingQueue.create(MAX_LAST_LINES);
CompletableFuture<Boolean> lineSupplier;
Context(BufferedReader stream, Consumer<String> consumer, String type) {
this.stream = stream;
this.consumer = consumer;
this.type = type;
}
void handleLine(String line) {
lastLines.add(line);
consumer.accept(line);
}
public String appendLastLines(String logMsg) {
String res = logMsg;
if (!lastLines.isEmpty()) {
res += "\n" + type + " (last " + lastLines.size() + " lines):\n";
for (String line : lastLines) {
res += line + "\n";
}
}
return res;
}
}
final Context[] streams;
try {
streams = new Context[] { new Context(new BufferedReader(new InputStreamReader(getOutputStream(), StandardCharsets.UTF_8)), waitOptions.stdoutConsumer, "STDOUT"), new Context(new BufferedReader(new InputStreamReader(getErrorStream(), StandardCharsets.UTF_8)), waitOptions.stderrConsumer, "STDERR") };
} catch (IOException e) {
logger.error("Error waiting for node response", e);
return CompletableFuture.completedFuture(false);
}
AtomicLong lastOutputLineTime = new AtomicLong(0);
for (Context ctx : streams) {
ctx.lineSupplier = CompletableFuture.supplyAsync(() -> {
try {
String line;
while ((line = ctx.stream.readLine()) != null) {
String trimmedLine = line.trim();
if (!trimmedLine.isEmpty() && !trimmedLine.equals("\n")) {
Optional<Logger> outputLineLogger = waitOptions.outputLineLogger(this);
if (outputLineLogger.isPresent()) {
outputLineLogger.get().info("{}: {}", ctx.type, line);
}
ctx.handleLine(line);
}
lastOutputLineTime.set(System.nanoTime());
}
return true;
} catch (Exception e) {
logger.error("Error waiting for node response output", e);
return false;
}
}, lineSupplierExecutor);
}
AtomicBoolean wasNoOutputTimeout = new AtomicBoolean(false);
List<Utils.TimeoutCheck> timeoutChecks = List.of();
if (noOutputTimeout.isPresent()) {
long outputTimeoutNano = noOutputTimeout.get().toNanos();
timeoutChecks = new ArrayList<>(1);
timeoutChecks.add(nanoTime -> {
long lastOutputNano = lastOutputLineTime.get();
if (// we only timeout processes that have had output before
lastOutputNano > 0) {
if (nanoTime >= lastOutputNano + outputTimeoutNano) {
wasNoOutputTimeout.set(true);
return true;
}
}
return false;
});
}
Utils.AwaitConditionOptions awaitOptions = new Utils.AwaitConditionOptions(logger, this::isCompleted, timeout, timer, waitOptions.checkInterval);
awaitOptions.addTimeoutChecks(timeoutChecks);
return Utils.awaitConditionAsync(awaitOptions).thenApplyAsync(completedWithoutTimeout -> {
completionListeners.forEach(completionListener -> completionListener.accept(this));
completionListeners.clear();
String nodeInfo = owner == null ? "" : " on node '" + owner.getId() + "'";
// command output after the command has been logged as completed.
if (completedWithoutTimeout && !wasKilled()) {
// Wait for stream processing to complete
for (Context ctx : streams) {
try {
Uninterruptibles.getUninterruptibly(ctx.lineSupplier, 1, TimeUnit.MINUTES);
} catch (ExecutionException e) {
throw new CompletionException(e);
} catch (TimeoutException e) {
logger.error("Command{} timed out waiting for output streams to close; this may be due to a zombie process, see FAL-1119", nodeInfo);
}
}
} else {
// Stop processing output since we will either kill this process due to timeout, or have already
// killed it. For killed processes, this is a hack to get around children of the target process
// keeping the stream open; once FAL-1119 is done, it should no longer be necessary.
logger.debug("Command{} timed out or killed: cancelling output streams listeners", nodeInfo);
for (Context ctx : streams) {
if (!ctx.lineSupplier.isDone()) {
ctx.lineSupplier.cancel(true);
}
}
}
if (!completedWithoutTimeout) {
// need to kill before potentially fetching fully buffered output from FBNR
this.kill();
}
String outputToLog = waitOptions.outputLogging ? getFormattedCommandOutput() : "";
if (completedWithoutTimeout) {
int exitCode = getExitCode();
if (exitCode == 0) {
logger.info("Command{} completed with exit code {}: {}{}", nodeInfo, exitCode, command, outputToLog);
} else {
String logMsg = "Command{} completed with non-zero exit code {}: {}{}";
if (waitOptions.exitCodeIsError.test(exitCode)) {
String errorMsg = CMD_FAIL_LOG_PREFIX + logMsg;
if (outputToLog.isEmpty()) {
String cmdOutput = getFormattedCommandOutput();
if (cmdOutput.isEmpty()) {
for (Context ctx : streams) {
outputToLog = ctx.appendLastLines(outputToLog);
}
} else {
// on error we log the full output even when outputLogging was false
outputToLog = cmdOutput;
}
}
logger.error(errorMsg, nodeInfo, exitCode, command, outputToLog);
} else {
logger.info(logMsg, nodeInfo, exitCode, command, outputToLog);
}
}
} else {
if (wasNoOutputTimeout.get()) {
String errorMsg = CMD_FAIL_LOG_PREFIX + "Command{} timed out due to no output after {}: {}{}";
logger.error(errorMsg, nodeInfo, waitOptions.noOutputTimeout.get(), command, outputToLog);
} else {
String errorMsg = CMD_FAIL_LOG_PREFIX + "Command{} timed out after {}: {}{}";
logger.error(errorMsg, nodeInfo, timeout, command, outputToLog);
}
}
return completedWithoutTimeout;
});
}
Aggregations