From be9b97e2cdcbdbb832eec6d8178e5b412cd1e966 Mon Sep 17 00:00:00 2001 From: kijanowski Date: Fri, 5 May 2023 13:34:25 +0200 Subject: [PATCH 01/10] Verify expected result with MVEL --- .../Cqld4PreparedStmtDispenser.java | 3 ++- .../opdispensers/Cqld4RawStmtDispenser.java | 3 ++- .../Cqld4SimpleCqlStmtDispenser.java | 3 ++- .../adapter/cqld4/optypes/Cqld4CqlOp.java | 21 +++++++++++++++- .../optypes/Cqld4CqlPreparedStatement.java | 6 +++-- .../optypes/Cqld4CqlSimpleStatement.java | 6 +++-- .../api/activityimpl/BaseOpDispenser.java | 14 +++++++++++ .../engine/api/activityimpl/OpDispenser.java | 2 ++ .../activityimpl/uniform/flowtypes/Op.java | 3 +++ .../uniform/actions/StandardAction.java | 24 +++++++++++++++++-- 10 files changed, 75 insertions(+), 10 deletions(-) diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4PreparedStmtDispenser.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4PreparedStmtDispenser.java index 398ce1e6e..4e72dad5c 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4PreparedStmtDispenser.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4PreparedStmtDispenser.java @@ -90,7 +90,8 @@ public class Cqld4PreparedStmtDispenser extends Cqld4BaseOpDispenser { getMaxPages(), isRetryReplace(), getMaxLwtRetries(), - processors + processors, + getExpectedResultExpression() ); } catch (Exception exception) { return CQLD4PreparedStmtDiagnostics.rebindWithDiagnostics( diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4RawStmtDispenser.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4RawStmtDispenser.java index 16b999e60..4fcf44b13 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4RawStmtDispenser.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4RawStmtDispenser.java @@ -50,7 +50,8 @@ public class Cqld4RawStmtDispenser extends Cqld4BaseOpDispenser { (SimpleStatement) stmtFunc.apply(value), getMaxPages(), isRetryReplace(), - getMaxLwtRetries() + getMaxLwtRetries(), + getExpectedResultExpression() ); } diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4SimpleCqlStmtDispenser.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4SimpleCqlStmtDispenser.java index f58ce6dc3..ecb23b312 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4SimpleCqlStmtDispenser.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4SimpleCqlStmtDispenser.java @@ -47,7 +47,8 @@ public class Cqld4SimpleCqlStmtDispenser extends Cqld4BaseOpDispenser { (SimpleStatement) stmtFunc.apply(value), getMaxPages(), isRetryReplace(), - getMaxLwtRetries() + getMaxLwtRetries(), + getExpectedResultExpression() ); } diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java index 67931b83a..4d46e5685 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java @@ -27,8 +27,12 @@ import io.nosqlbench.adapter.cqld4.exceptions.ExceededRetryReplaceException; import io.nosqlbench.adapter.cqld4.exceptions.UndefinedResultSetException; import io.nosqlbench.adapter.cqld4.exceptions.UnexpectedPagingException; import io.nosqlbench.engine.api.activityimpl.uniform.flowtypes.*; +import org.mvel2.MVEL; +import java.io.Serializable; +import java.util.ArrayList; import java.util.Iterator; +import java.util.List; import java.util.Map; @@ -54,12 +58,20 @@ public abstract class Cqld4CqlOp implements CycleOp, VariableCapture, private Cqld4CqlOp nextOp; private final RSProcessors processors; + private final ThreadLocal> results = new ThreadLocal<>(); + private Serializable expectedResultExpression; + public Cqld4CqlOp(CqlSession session, int maxPages, boolean retryReplace, int maxLwtRetries, RSProcessors processors) { + this(session, maxPages, retryReplace, maxLwtRetries, processors, null); + } + + public Cqld4CqlOp(CqlSession session, int maxPages, boolean retryReplace, int maxLwtRetries, RSProcessors processors, Serializable expectedResultExpressions) { this.session = session; this.maxPages = maxPages; this.retryReplace = retryReplace; this.maxLwtRetries =maxLwtRetries; this.processors = processors; + this.expectedResultExpression = expectedResultExpressions; } protected Cqld4CqlOp(CqlSession session, int maxPages, boolean retryReplace, int maxLwtRetries, int retryRplaceCount, RSProcessors processors) { @@ -97,19 +109,22 @@ public abstract class Cqld4CqlOp implements CycleOp, VariableCapture, Iterator reader = rs.iterator(); int pages = 0; + var resultRows = new ArrayList(); while (true) { int pageRows = rs.getAvailableWithoutFetching(); for (int i = 0; i < pageRows; i++) { Row row = reader.next(); + resultRows.add(row); processors.buffer(row); } if (pages++ > maxPages) { throw new UnexpectedPagingException(rs, getQueryString(), pages, maxPages, stmt.getPageSize()); } if (rs.isFullyFetched()) { + results.set(resultRows); break; } - totalRows += pageRows; + totalRows += pageRows; // TODO JK what is this for? } processors.flush(); return rs; @@ -139,4 +154,8 @@ public abstract class Cqld4CqlOp implements CycleOp, VariableCapture, return new Cqld4CqlReboundStatement(session, maxPages, retryReplace, maxLwtRetries, retryReplaceCount, rebound, processors); } + @Override + public boolean verified() { // TODO JK can this be made CQL agnostic? And moved to BaseOpDispenser? + return MVEL.executeExpression(expectedResultExpression, results.get(), boolean.class); + } } diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlPreparedStatement.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlPreparedStatement.java index 9e6dfcad9..cb1d29b67 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlPreparedStatement.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlPreparedStatement.java @@ -20,12 +20,14 @@ import com.datastax.oss.driver.api.core.CqlSession; import com.datastax.oss.driver.api.core.cql.BoundStatement; import io.nosqlbench.adapter.cqld4.RSProcessors; +import java.io.Serializable; + public class Cqld4CqlPreparedStatement extends Cqld4CqlOp { private final BoundStatement stmt; - public Cqld4CqlPreparedStatement(CqlSession session, BoundStatement stmt, int maxPages, boolean retryReplace, int maxLwtRetries, RSProcessors processors) { - super(session,maxPages,retryReplace,maxLwtRetries,processors); + public Cqld4CqlPreparedStatement(CqlSession session, BoundStatement stmt, int maxPages, boolean retryReplace, int maxLwtRetries, RSProcessors processors, Serializable expectedResultExpression) { + super(session, maxPages, retryReplace, maxLwtRetries, processors, expectedResultExpression); this.stmt = stmt; } diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlSimpleStatement.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlSimpleStatement.java index 0f119c91d..39141c8df 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlSimpleStatement.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlSimpleStatement.java @@ -20,11 +20,13 @@ import com.datastax.oss.driver.api.core.CqlSession; import com.datastax.oss.driver.api.core.cql.SimpleStatement; import io.nosqlbench.adapter.cqld4.RSProcessors; +import java.io.Serializable; + public class Cqld4CqlSimpleStatement extends Cqld4CqlOp { private final SimpleStatement stmt; - public Cqld4CqlSimpleStatement(CqlSession session, SimpleStatement stmt, int maxPages, boolean retryReplace, int maxLwtRetries) { - super(session, maxPages,retryReplace, maxLwtRetries, new RSProcessors()); + public Cqld4CqlSimpleStatement(CqlSession session, SimpleStatement stmt, int maxPages, boolean retryReplace, int maxLwtRetries, Serializable expectedResultExpression) { + super(session, maxPages,retryReplace, maxLwtRetries, new RSProcessors(), expectedResultExpression); this.stmt = stmt; } diff --git a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/BaseOpDispenser.java b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/BaseOpDispenser.java index 83c7b796d..79212b554 100644 --- a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/BaseOpDispenser.java +++ b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/BaseOpDispenser.java @@ -23,7 +23,9 @@ import io.nosqlbench.engine.api.activityimpl.uniform.DriverAdapter; import io.nosqlbench.engine.api.activityimpl.uniform.flowtypes.Op; import io.nosqlbench.engine.api.metrics.ThreadLocalNamedTimers; import io.nosqlbench.engine.api.templating.ParsedOp; +import org.mvel2.MVEL; +import java.io.Serializable; import java.util.concurrent.TimeUnit; /** @@ -38,6 +40,7 @@ import java.util.concurrent.TimeUnit; public abstract class BaseOpDispenser implements OpDispenser { private final String opName; + private Serializable expectedResultExpression; protected final DriverAdapter adapter; private boolean instrument; private Histogram resultSizeHistogram; @@ -63,6 +66,17 @@ public abstract class BaseOpDispenser implements OpDispenser } } configureInstrumentation(op); + configureExpectations(op); + } + + private void configureExpectations(ParsedOp op) { + op.getOptionalStaticValue("expected-result", String.class) + .map(MVEL::compileExpression) + .ifPresent(result -> this.expectedResultExpression = result); + } + + public Serializable getExpectedResultExpression() { + return expectedResultExpression; } String getOpName() { diff --git a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/OpDispenser.java b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/OpDispenser.java index 162621902..c8d584f18 100644 --- a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/OpDispenser.java +++ b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/OpDispenser.java @@ -16,6 +16,7 @@ package io.nosqlbench.engine.api.activityimpl; +import java.io.Serializable; import java.util.function.LongFunction; /** @@ -81,5 +82,6 @@ public interface OpDispenser extends LongFunction, OpResultTracker { */ T apply(long value); + Serializable getExpectedResultExpression(); } diff --git a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/flowtypes/Op.java b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/flowtypes/Op.java index e5ecdf6a2..d70014c8f 100644 --- a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/flowtypes/Op.java +++ b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/flowtypes/Op.java @@ -33,4 +33,7 @@ package io.nosqlbench.engine.api.activityimpl.uniform.flowtypes; */ // TODO: optimize the runtime around the specific op type public interface Op extends OpResultSize { + default boolean verified() { + return false; + } } diff --git a/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java b/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java index d1f5010e8..0f3d236a0 100644 --- a/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java +++ b/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java @@ -87,7 +87,7 @@ public class StandardAction, R extends Op> impl while (op != null) { int tries = 0; - while (tries++ <= maxTries) { + while (tries++ < maxTries) { Throwable error = null; long startedAt = System.nanoTime(); @@ -112,7 +112,27 @@ public class StandardAction, R extends Op> impl if (error == null) { resultSuccessTimer.update(nanos, TimeUnit.NANOSECONDS); dispenser.onSuccess(cycle, nanos, op.getResultSize()); - break; + + if (dispenser.getExpectedResultExpression() != null) { // TODO JK refactor the whole if/else break/continue tree + if (op.verified()) { // TODO JK Could this be moved to BaseOpDispenser? + logger.info(() -> "Verification of result passed"); + break; + } else { + // retry + var triesLeft = maxTries - tries; + logger.info("Verification of result did not pass - {} retries left", triesLeft); + if (triesLeft == 0) { + var retriesExhausted = new RuntimeException("Max retries for verification step exhausted."); // TODO JK do we need a dedicated exception here? VerificationRetriesExhaustedException? + var errorDetail = errorHandler.handleError(retriesExhausted, cycle, nanos); + dispenser.onError(cycle, nanos, retriesExhausted); + code = ErrorDetail.ERROR_RETRYABLE.resultCode; // TODO JK use code from errorDetail.resultCode? + break; + } + continue; + } + } else { + break; + } } else { ErrorDetail detail = errorHandler.handleError(error, cycle, nanos); dispenser.onError(cycle, nanos, error); From a8ce71f9e78de403b79ffcedaa9f0d361c39b83d Mon Sep 17 00:00:00 2001 From: Jonathan Shook Date: Mon, 8 May 2023 12:31:01 -0500 Subject: [PATCH 02/10] Comments on branch. You can truncate this commit after reading. --- .../opdispensers/Cqld4PreparedStmtDispenser.java | 3 ++- .../nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java | 12 +++++++++++- .../engine/api/activityimpl/BaseOpDispenser.java | 4 +++- .../api/activityimpl/uniform/flowtypes/Op.java | 4 +++- .../activityimpl/uniform/actions/StandardAction.java | 8 ++++++-- 5 files changed, 25 insertions(+), 6 deletions(-) diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4PreparedStmtDispenser.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4PreparedStmtDispenser.java index 4e72dad5c..2acfe1573 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4PreparedStmtDispenser.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4PreparedStmtDispenser.java @@ -91,7 +91,8 @@ public class Cqld4PreparedStmtDispenser extends Cqld4BaseOpDispenser { isRetryReplace(), getMaxLwtRetries(), processors, - getExpectedResultExpression() + getExpectedResultExpression() // TODO/MVEL: When this is moved to BaseOpDispenser + StandardAction + // there will be no need to add it to the value type for the op, since the dispenser can hold it ); } catch (Exception exception) { return CQLD4PreparedStmtDiagnostics.rebindWithDiagnostics( diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java index 4d46e5685..1d687bfb1 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022 nosqlbench + * Copyright (c) 2022-2023 nosqlbench * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -109,6 +109,10 @@ public abstract class Cqld4CqlOp implements CycleOp, VariableCapture, Iterator reader = rs.iterator(); int pages = 0; + // TODO/MVEL: An optimization to this would be to collect the results in a result set processor, + // but allow/require this processor to be added to an op _only_ in the event that it would + // be needed by a downstream consumer like the MVEL expected result evaluator + var resultRows = new ArrayList(); while (true) { int pageRows = rs.getAvailableWithoutFetching(); @@ -125,6 +129,7 @@ public abstract class Cqld4CqlOp implements CycleOp, VariableCapture, break; } totalRows += pageRows; // TODO JK what is this for? + // TODO/MVEL: JK: this is meant to go to a total-rows metric, although it is not wired correctly yet } processors.flush(); return rs; @@ -156,6 +161,11 @@ public abstract class Cqld4CqlOp implements CycleOp, VariableCapture, @Override public boolean verified() { // TODO JK can this be made CQL agnostic? And moved to BaseOpDispenser? + // TODO/MVEL: Yes, it can. The initial implementation should, and it should actually be inside + // the main StandardAction, _after_ CycleOp or ChainingOp result is computed return MVEL.executeExpression(expectedResultExpression, results.get(), boolean.class); + // TODO/MVEL: Wherever this logic lives, we might want to have a symbolic description which + // is emitted for logging our metrics purposes indicating the success or failure outcomes. + // perhaps something like expected-name: .... and metrics could be then -success and -error } } diff --git a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/BaseOpDispenser.java b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/BaseOpDispenser.java index 79212b554..341186df5 100644 --- a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/BaseOpDispenser.java +++ b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/BaseOpDispenser.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022 nosqlbench + * Copyright (c) 2022-2023 nosqlbench * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -69,6 +69,8 @@ public abstract class BaseOpDispenser implements OpDispenser configureExpectations(op); } + // TODO/MVEL: Please add some error handling around that explains to the user + // what happened in the event of a compilation failure. private void configureExpectations(ParsedOp op) { op.getOptionalStaticValue("expected-result", String.class) .map(MVEL::compileExpression) diff --git a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/flowtypes/Op.java b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/flowtypes/Op.java index d70014c8f..7a78ab7a4 100644 --- a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/flowtypes/Op.java +++ b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/flowtypes/Op.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022 nosqlbench + * Copyright (c) 2022-2023 nosqlbench * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -33,6 +33,8 @@ package io.nosqlbench.engine.api.activityimpl.uniform.flowtypes; */ // TODO: optimize the runtime around the specific op type public interface Op extends OpResultSize { + // TODO/MVEL: Let's take this out of here to keep Op as a tagging interface + // I think it will sit fine on the BaseOpDispenser, and lifecycles align for this nicely default boolean verified() { return false; } diff --git a/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java b/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java index 0f3d236a0..ce91d2bfc 100644 --- a/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java +++ b/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022 nosqlbench + * Copyright (c) 2022-2023 nosqlbench * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -115,12 +115,13 @@ public class StandardAction, R extends Op> impl if (dispenser.getExpectedResultExpression() != null) { // TODO JK refactor the whole if/else break/continue tree if (op.verified()) { // TODO JK Could this be moved to BaseOpDispenser? - logger.info(() -> "Verification of result passed"); + logger.info(() -> "Verification of result passed"); // TODO/MVEL: this is too verbose per cycle break; } else { // retry var triesLeft = maxTries - tries; logger.info("Verification of result did not pass - {} retries left", triesLeft); + // TODO/MVEL: I think we should designate a separate logging channel for verification logic if (triesLeft == 0) { var retriesExhausted = new RuntimeException("Max retries for verification step exhausted."); // TODO JK do we need a dedicated exception here? VerificationRetriesExhaustedException? var errorDetail = errorHandler.handleError(retriesExhausted, cycle, nanos); @@ -129,6 +130,9 @@ public class StandardAction, R extends Op> impl break; } continue; + // TODO/MVEL: I think we should collapse all this if possible to throwing a UnverifiedError and let error handlers do their thing. + // TODO/MVEL: This would work nicely with existing mechanisms and allow users to route errors and status codes as they like. + // TODO/MVEL: A future refinement would be to allow customized error handlers (+-) per dispenser } } else { break; From 2e47715ce797f893980e5cb3e412b115a1309f9f Mon Sep 17 00:00:00 2001 From: kijanowski Date: Fri, 12 May 2023 16:51:38 +0200 Subject: [PATCH 03/10] Code review adjustments --- .../nosqlbench/adapter/cqld4/Cqld4Space.java | 1 + .../Cqld4PreparedStmtDispenser.java | 4 +- .../opdispensers/Cqld4RawStmtDispenser.java | 5 +- .../Cqld4SimpleCqlStmtDispenser.java | 5 +- .../adapter/cqld4/optypes/Cqld4CqlOp.java | 26 ++------ .../optypes/Cqld4CqlPreparedStatement.java | 8 +-- .../optypes/Cqld4CqlSimpleStatement.java | 8 +-- .../api/activityimpl/BaseOpDispenser.java | 27 ++++++--- .../activityimpl/uniform/flowtypes/Op.java | 5 -- .../errorhandling/ErrorMetrics.java | 11 +++- ...xpectedResultVerificationErrorHandler.java | 60 +++++++++++++++++++ .../uniform/actions/StandardAction.java | 42 ++++++------- ...tionExpectedResultVerificationMetrics.java | 51 ++++++++++++++++ .../modular/NBErrorHandlerTest.java | 57 +++++++++++++++++- .../java/io/nosqlbench/engine/cli/NBCLI.java | 2 +- .../engine/core/logging/LoggerConfig.java | 23 ++++++- .../ExpectedResultVerificationError.java | 29 +++++++++ .../api/errors/MVELCompilationError.java | 26 ++++++++ 18 files changed, 306 insertions(+), 84 deletions(-) create mode 100644 engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/handlers/ExpectedResultVerificationErrorHandler.java create mode 100644 engine-api/src/main/java/io/nosqlbench/engine/api/metrics/ExceptionExpectedResultVerificationMetrics.java create mode 100644 nb-api/src/main/java/io/nosqlbench/api/errors/ExpectedResultVerificationError.java create mode 100644 nb-api/src/main/java/io/nosqlbench/api/errors/MVELCompilationError.java diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/Cqld4Space.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/Cqld4Space.java index eebb23c14..89bd66961 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/Cqld4Space.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/Cqld4Space.java @@ -293,6 +293,7 @@ public class Cqld4Space implements AutoCloseable { .add(Param.optional("whitelist", String.class, "list of whitelist hosts addresses")) .add(Param.optional("showstmt", Boolean.class, "show the contents of the statement in the log")) .add(Param.optional("cloud_proxy_address", String.class, "Cloud Proxy Address")) + .add(Param.optional("maxtries", Integer.class)) .add(SSLKsFactory.get().getConfigModel()) .add(getDriverOptionsModel()) .add(new OptionHelpers(new OptionsMap()).getConfigModel()) diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4PreparedStmtDispenser.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4PreparedStmtDispenser.java index 2acfe1573..398ce1e6e 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4PreparedStmtDispenser.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4PreparedStmtDispenser.java @@ -90,9 +90,7 @@ public class Cqld4PreparedStmtDispenser extends Cqld4BaseOpDispenser { getMaxPages(), isRetryReplace(), getMaxLwtRetries(), - processors, - getExpectedResultExpression() // TODO/MVEL: When this is moved to BaseOpDispenser + StandardAction - // there will be no need to add it to the value type for the op, since the dispenser can hold it + processors ); } catch (Exception exception) { return CQLD4PreparedStmtDiagnostics.rebindWithDiagnostics( diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4RawStmtDispenser.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4RawStmtDispenser.java index 4fcf44b13..7043b6715 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4RawStmtDispenser.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4RawStmtDispenser.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022 nosqlbench + * Copyright (c) 2022-2023 nosqlbench * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -50,8 +50,7 @@ public class Cqld4RawStmtDispenser extends Cqld4BaseOpDispenser { (SimpleStatement) stmtFunc.apply(value), getMaxPages(), isRetryReplace(), - getMaxLwtRetries(), - getExpectedResultExpression() + getMaxLwtRetries() ); } diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4SimpleCqlStmtDispenser.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4SimpleCqlStmtDispenser.java index ecb23b312..0f71fb262 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4SimpleCqlStmtDispenser.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/opdispensers/Cqld4SimpleCqlStmtDispenser.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022 nosqlbench + * Copyright (c) 2022-2023 nosqlbench * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -47,8 +47,7 @@ public class Cqld4SimpleCqlStmtDispenser extends Cqld4BaseOpDispenser { (SimpleStatement) stmtFunc.apply(value), getMaxPages(), isRetryReplace(), - getMaxLwtRetries(), - getExpectedResultExpression() + getMaxLwtRetries() ); } diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java index 1d687bfb1..8e675b36d 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlOp.java @@ -27,9 +27,7 @@ import io.nosqlbench.adapter.cqld4.exceptions.ExceededRetryReplaceException; import io.nosqlbench.adapter.cqld4.exceptions.UndefinedResultSetException; import io.nosqlbench.adapter.cqld4.exceptions.UnexpectedPagingException; import io.nosqlbench.engine.api.activityimpl.uniform.flowtypes.*; -import org.mvel2.MVEL; -import java.io.Serializable; import java.util.ArrayList; import java.util.Iterator; import java.util.List; @@ -46,7 +44,7 @@ import java.util.Map; // TODO: add rows histogram resultSetSizeHisto -public abstract class Cqld4CqlOp implements CycleOp, VariableCapture, OpGenerator, OpResultSize { +public abstract class Cqld4CqlOp implements CycleOp>, VariableCapture, OpGenerator, OpResultSize { private final CqlSession session; private final int maxPages; @@ -59,19 +57,13 @@ public abstract class Cqld4CqlOp implements CycleOp, VariableCapture, private final RSProcessors processors; private final ThreadLocal> results = new ThreadLocal<>(); - private Serializable expectedResultExpression; public Cqld4CqlOp(CqlSession session, int maxPages, boolean retryReplace, int maxLwtRetries, RSProcessors processors) { - this(session, maxPages, retryReplace, maxLwtRetries, processors, null); - } - - public Cqld4CqlOp(CqlSession session, int maxPages, boolean retryReplace, int maxLwtRetries, RSProcessors processors, Serializable expectedResultExpressions) { this.session = session; this.maxPages = maxPages; this.retryReplace = retryReplace; this.maxLwtRetries =maxLwtRetries; this.processors = processors; - this.expectedResultExpression = expectedResultExpressions; } protected Cqld4CqlOp(CqlSession session, int maxPages, boolean retryReplace, int maxLwtRetries, int retryRplaceCount, RSProcessors processors) { @@ -83,7 +75,7 @@ public abstract class Cqld4CqlOp implements CycleOp, VariableCapture, this.processors = processors; } - public final ResultSet apply(long cycle) { + public final List apply(long cycle) { Statement stmt = getStmt(); rs = session.execute(stmt); @@ -128,11 +120,10 @@ public abstract class Cqld4CqlOp implements CycleOp, VariableCapture, results.set(resultRows); break; } - totalRows += pageRows; // TODO JK what is this for? - // TODO/MVEL: JK: this is meant to go to a total-rows metric, although it is not wired correctly yet + totalRows += pageRows; } processors.flush(); - return rs; + return results.get(); } @Override @@ -159,13 +150,4 @@ public abstract class Cqld4CqlOp implements CycleOp, VariableCapture, return new Cqld4CqlReboundStatement(session, maxPages, retryReplace, maxLwtRetries, retryReplaceCount, rebound, processors); } - @Override - public boolean verified() { // TODO JK can this be made CQL agnostic? And moved to BaseOpDispenser? - // TODO/MVEL: Yes, it can. The initial implementation should, and it should actually be inside - // the main StandardAction, _after_ CycleOp or ChainingOp result is computed - return MVEL.executeExpression(expectedResultExpression, results.get(), boolean.class); - // TODO/MVEL: Wherever this logic lives, we might want to have a symbolic description which - // is emitted for logging our metrics purposes indicating the success or failure outcomes. - // perhaps something like expected-name: .... and metrics could be then -success and -error - } } diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlPreparedStatement.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlPreparedStatement.java index cb1d29b67..44a4b85b1 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlPreparedStatement.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlPreparedStatement.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022 nosqlbench + * Copyright (c) 2022-2023 nosqlbench * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -20,14 +20,12 @@ import com.datastax.oss.driver.api.core.CqlSession; import com.datastax.oss.driver.api.core.cql.BoundStatement; import io.nosqlbench.adapter.cqld4.RSProcessors; -import java.io.Serializable; - public class Cqld4CqlPreparedStatement extends Cqld4CqlOp { private final BoundStatement stmt; - public Cqld4CqlPreparedStatement(CqlSession session, BoundStatement stmt, int maxPages, boolean retryReplace, int maxLwtRetries, RSProcessors processors, Serializable expectedResultExpression) { - super(session, maxPages, retryReplace, maxLwtRetries, processors, expectedResultExpression); + public Cqld4CqlPreparedStatement(CqlSession session, BoundStatement stmt, int maxPages, boolean retryReplace, int maxLwtRetries, RSProcessors processors) { + super(session, maxPages, retryReplace, maxLwtRetries, processors); this.stmt = stmt; } diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlSimpleStatement.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlSimpleStatement.java index 39141c8df..959a3ea89 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlSimpleStatement.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/optypes/Cqld4CqlSimpleStatement.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022 nosqlbench + * Copyright (c) 2022-2023 nosqlbench * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -20,13 +20,11 @@ import com.datastax.oss.driver.api.core.CqlSession; import com.datastax.oss.driver.api.core.cql.SimpleStatement; import io.nosqlbench.adapter.cqld4.RSProcessors; -import java.io.Serializable; - public class Cqld4CqlSimpleStatement extends Cqld4CqlOp { private final SimpleStatement stmt; - public Cqld4CqlSimpleStatement(CqlSession session, SimpleStatement stmt, int maxPages, boolean retryReplace, int maxLwtRetries, Serializable expectedResultExpression) { - super(session, maxPages,retryReplace, maxLwtRetries, new RSProcessors(), expectedResultExpression); + public Cqld4CqlSimpleStatement(CqlSession session, SimpleStatement stmt, int maxPages, boolean retryReplace, int maxLwtRetries) { + super(session, maxPages,retryReplace, maxLwtRetries, new RSProcessors()); this.stmt = stmt; } diff --git a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/BaseOpDispenser.java b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/BaseOpDispenser.java index 341186df5..c5363080b 100644 --- a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/BaseOpDispenser.java +++ b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/BaseOpDispenser.java @@ -19,6 +19,7 @@ package io.nosqlbench.engine.api.activityimpl; import com.codahale.metrics.Histogram; import com.codahale.metrics.Timer; import io.nosqlbench.api.engine.metrics.ActivityMetrics; +import io.nosqlbench.api.errors.MVELCompilationError; import io.nosqlbench.engine.api.activityimpl.uniform.DriverAdapter; import io.nosqlbench.engine.api.activityimpl.uniform.flowtypes.Op; import io.nosqlbench.engine.api.metrics.ThreadLocalNamedTimers; @@ -66,21 +67,29 @@ public abstract class BaseOpDispenser implements OpDispenser } } configureInstrumentation(op); - configureExpectations(op); - } - - // TODO/MVEL: Please add some error handling around that explains to the user - // what happened in the event of a compilation failure. - private void configureExpectations(ParsedOp op) { - op.getOptionalStaticValue("expected-result", String.class) - .map(MVEL::compileExpression) - .ifPresent(result -> this.expectedResultExpression = result); + configureResultExpectations(op); } public Serializable getExpectedResultExpression() { return expectedResultExpression; } + private void configureResultExpectations(ParsedOp op) { + op.getOptionalStaticValue("expected-result", String.class) + .map(this::compileExpectedResultExpression) + .ifPresent(result -> this.expectedResultExpression = result); + } + + private Serializable compileExpectedResultExpression(String expectedResultExpression) { + try { + return MVEL.compileExpression(expectedResultExpression); + } catch (Exception e) { + throw new MVELCompilationError( + String.format("Failed to compile expected-result expression: \"%s\"", expectedResultExpression), e + ); + } + } + String getOpName() { return opName; } diff --git a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/flowtypes/Op.java b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/flowtypes/Op.java index 7a78ab7a4..a05e2fe63 100644 --- a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/flowtypes/Op.java +++ b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/flowtypes/Op.java @@ -33,9 +33,4 @@ package io.nosqlbench.engine.api.activityimpl.uniform.flowtypes; */ // TODO: optimize the runtime around the specific op type public interface Op extends OpResultSize { - // TODO/MVEL: Let's take this out of here to keep Op as a tagging interface - // I think it will sit fine on the BaseOpDispenser, and lifecycles align for this nicely - default boolean verified() { - return false; - } } diff --git a/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/ErrorMetrics.java b/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/ErrorMetrics.java index 40a0e354b..e53a12936 100644 --- a/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/ErrorMetrics.java +++ b/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/ErrorMetrics.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022 nosqlbench + * Copyright (c) 2022-2023 nosqlbench * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -18,6 +18,7 @@ package io.nosqlbench.engine.api.activityapi.errorhandling; import io.nosqlbench.api.engine.activityimpl.ActivityDef; import io.nosqlbench.engine.api.metrics.ExceptionCountMetrics; +import io.nosqlbench.engine.api.metrics.ExceptionExpectedResultVerificationMetrics; import io.nosqlbench.engine.api.metrics.ExceptionHistoMetrics; import io.nosqlbench.engine.api.metrics.ExceptionMeterMetrics; import io.nosqlbench.engine.api.metrics.ExceptionTimerMetrics; @@ -31,6 +32,7 @@ public class ErrorMetrics { private ExceptionHistoMetrics exceptionHistoMetrics; private ExceptionMeterMetrics exceptionMeterMetrics; private ExceptionTimerMetrics exceptionTimerMetrics; + private ExceptionExpectedResultVerificationMetrics exceptionExpectedResultVerificationMetrics; public ErrorMetrics(ActivityDef activityDef) { this.activityDef = activityDef; @@ -64,6 +66,13 @@ public class ErrorMetrics { return exceptionTimerMetrics; } + public synchronized ExceptionExpectedResultVerificationMetrics getExceptionExpectedResultVerificationMetrics() { + if (exceptionExpectedResultVerificationMetrics == null) { + exceptionExpectedResultVerificationMetrics = new ExceptionExpectedResultVerificationMetrics(activityDef); + } + return exceptionExpectedResultVerificationMetrics; + } + public interface Aware { void setErrorMetricsSupplier(Supplier supplier); } diff --git a/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/handlers/ExpectedResultVerificationErrorHandler.java b/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/handlers/ExpectedResultVerificationErrorHandler.java new file mode 100644 index 000000000..bdc727526 --- /dev/null +++ b/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/handlers/ExpectedResultVerificationErrorHandler.java @@ -0,0 +1,60 @@ +/* + * Copyright (c) 2022-2023 nosqlbench + * + * 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 + * + * http://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 io.nosqlbench.engine.api.activityapi.errorhandling.modular.handlers; + +import io.nosqlbench.api.errors.ExpectedResultVerificationError; +import io.nosqlbench.engine.api.activityapi.errorhandling.ErrorMetrics; +import io.nosqlbench.engine.api.activityapi.errorhandling.modular.ErrorDetail; +import io.nosqlbench.engine.api.activityapi.errorhandling.modular.ErrorHandler; +import io.nosqlbench.engine.api.metrics.ExceptionExpectedResultVerificationMetrics; +import io.nosqlbench.nb.annotations.Service; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; + +import java.util.function.Supplier; + +/** + * The expected result verification error handler will create, if needed, two metric + * objects for error and retry counts. + */ +@Service(value = ErrorHandler.class, selector = "verifyexpected") +public class ExpectedResultVerificationErrorHandler implements ErrorHandler, ErrorMetrics.Aware { + private static final Logger logger = LogManager.getLogger(ExpectedResultVerificationErrorHandler.class); + private ExceptionExpectedResultVerificationMetrics exceptionExpectedResultVerificationMetrics; + + @Override + public ErrorDetail handleError(String name, Throwable t, long cycle, long durationInNanos, ErrorDetail detail) { + if (t instanceof ExpectedResultVerificationError erve) { + if (erve.getTriesLeft() == 0) { + logger.warn("Verification of result did not pass. All retries exhausted."); + exceptionExpectedResultVerificationMetrics.countVerificationErrors(); + } else { + logger.info("Cycle: {} Verification of result did not pass. {} retries left.", cycle, erve.getTriesLeft()); + // TODO/MVEL: I think we should designate a separate logging channel for verification logic + // TODO JK: Should this be done via a dedicated logger in the LoggerConfig class? log4j2.xml files seem to be overridden? + exceptionExpectedResultVerificationMetrics.countVerificationRetries(); + } + } + return detail; + } + + @Override + public void setErrorMetricsSupplier(Supplier supplier) { + this.exceptionExpectedResultVerificationMetrics = supplier.get().getExceptionExpectedResultVerificationMetrics(); + } + +} diff --git a/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java b/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java index ce91d2bfc..18273bf8e 100644 --- a/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java +++ b/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java @@ -18,6 +18,7 @@ package io.nosqlbench.engine.api.activityimpl.uniform.actions; import com.codahale.metrics.Histogram; import com.codahale.metrics.Timer; +import io.nosqlbench.api.errors.ExpectedResultVerificationError; import io.nosqlbench.engine.api.activityapi.core.ActivityDefObserver; import io.nosqlbench.engine.api.activityapi.core.SyncAction; import io.nosqlbench.engine.api.activityapi.errorhandling.modular.ErrorDetail; @@ -29,7 +30,9 @@ import io.nosqlbench.engine.api.activityimpl.uniform.StandardActivity; import io.nosqlbench.engine.api.activityimpl.uniform.flowtypes.*; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; +import org.mvel2.MVEL; +import java.io.Serializable; import java.util.concurrent.TimeUnit; /** @@ -104,6 +107,16 @@ public class StandardAction, R extends Op> impl throw new RuntimeException("The op implementation did not implement any active logic. Implement " + "one of [RunnableOp, CycleOp, or ChainingOp]"); } + var expectedResultExpression = dispenser.getExpectedResultExpression(); + if (shouldVerifyExpectedResultFor(op, expectedResultExpression)) { + var verified = MVEL.executeExpression(expectedResultExpression, result, boolean.class); + // TODO/MVEL: Wherever this logic lives, we might want to have a symbolic description which + // is emitted for logging our metrics purposes indicating the success or failure outcomes. + // perhaps something like expected-name: .... and metrics could be then -success and -error + if (!verified) { + throw new ExpectedResultVerificationError(maxTries - tries); + } + } } catch (Exception e) { error = e; } finally { @@ -112,31 +125,6 @@ public class StandardAction, R extends Op> impl if (error == null) { resultSuccessTimer.update(nanos, TimeUnit.NANOSECONDS); dispenser.onSuccess(cycle, nanos, op.getResultSize()); - - if (dispenser.getExpectedResultExpression() != null) { // TODO JK refactor the whole if/else break/continue tree - if (op.verified()) { // TODO JK Could this be moved to BaseOpDispenser? - logger.info(() -> "Verification of result passed"); // TODO/MVEL: this is too verbose per cycle - break; - } else { - // retry - var triesLeft = maxTries - tries; - logger.info("Verification of result did not pass - {} retries left", triesLeft); - // TODO/MVEL: I think we should designate a separate logging channel for verification logic - if (triesLeft == 0) { - var retriesExhausted = new RuntimeException("Max retries for verification step exhausted."); // TODO JK do we need a dedicated exception here? VerificationRetriesExhaustedException? - var errorDetail = errorHandler.handleError(retriesExhausted, cycle, nanos); - dispenser.onError(cycle, nanos, retriesExhausted); - code = ErrorDetail.ERROR_RETRYABLE.resultCode; // TODO JK use code from errorDetail.resultCode? - break; - } - continue; - // TODO/MVEL: I think we should collapse all this if possible to throwing a UnverifiedError and let error handlers do their thing. - // TODO/MVEL: This would work nicely with existing mechanisms and allow users to route errors and status codes as they like. - // TODO/MVEL: A future refinement would be to allow customized error handlers (+-) per dispenser - } - } else { - break; - } } else { ErrorDetail detail = errorHandler.handleError(error, cycle, nanos); dispenser.onError(cycle, nanos, error); @@ -163,4 +151,8 @@ public class StandardAction, R extends Op> impl @Override public void onActivityDefUpdate(ActivityDef activityDef) { } + + private boolean shouldVerifyExpectedResultFor(Op op, Serializable expectedResultExpression) { + return !(op instanceof RunnableOp) && expectedResultExpression != null; + } } diff --git a/engine-api/src/main/java/io/nosqlbench/engine/api/metrics/ExceptionExpectedResultVerificationMetrics.java b/engine-api/src/main/java/io/nosqlbench/engine/api/metrics/ExceptionExpectedResultVerificationMetrics.java new file mode 100644 index 000000000..45657f64b --- /dev/null +++ b/engine-api/src/main/java/io/nosqlbench/engine/api/metrics/ExceptionExpectedResultVerificationMetrics.java @@ -0,0 +1,51 @@ +/* + * Copyright (c) 2022-2023 nosqlbench + * + * 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 + * + * http://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 io.nosqlbench.engine.api.metrics; + +import com.codahale.metrics.Counter; +import io.nosqlbench.api.engine.activityimpl.ActivityDef; +import io.nosqlbench.api.engine.metrics.ActivityMetrics; + + +/** + * Use this to provide exception metering during expected result verification. + */ +public class ExceptionExpectedResultVerificationMetrics { + private final Counter verificationErrors; + private final Counter verificationRetries; + + public ExceptionExpectedResultVerificationMetrics(ActivityDef activityDef) { + verificationRetries = ActivityMetrics.counter(activityDef, "verificationcounts.RETRIES"); + verificationErrors = ActivityMetrics.counter(activityDef, "verificationcounts.ERRORS"); + } + + public void countVerificationRetries() { + verificationRetries.inc(); + } + + public void countVerificationErrors() { + verificationErrors.inc(); + } + + public Counter getVerificationErrors() { + return verificationErrors; + } + + public Counter getVerificationRetries() { + return verificationRetries; + } +} diff --git a/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java b/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java index 94bcb9883..d7a4706e3 100644 --- a/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java +++ b/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022 nosqlbench + * Copyright (c) 2022-2023 nosqlbench * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -21,16 +21,22 @@ import com.codahale.metrics.Histogram; import com.codahale.metrics.Meter; import com.codahale.metrics.Timer; import io.nosqlbench.api.engine.activityimpl.ActivityDef; +import io.nosqlbench.api.errors.ExpectedResultVerificationError; import io.nosqlbench.engine.api.activityapi.errorhandling.ErrorMetrics; import io.nosqlbench.engine.api.activityapi.errorhandling.modular.handlers.CountErrorHandler; import io.nosqlbench.engine.api.activityapi.errorhandling.modular.handlers.CounterErrorHandler; +import io.nosqlbench.engine.api.activityapi.errorhandling.modular.handlers.ExpectedResultVerificationErrorHandler; import io.nosqlbench.util.NBMock; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.core.Logger; import org.junit.jupiter.api.Test; +import org.junit.jupiter.params.ParameterizedTest; +import org.junit.jupiter.params.provider.Arguments; +import org.junit.jupiter.params.provider.MethodSource; import java.util.List; +import java.util.stream.Stream; import static org.assertj.core.api.Assertions.assertThat; import static org.assertj.core.api.Assertions.assertThatExceptionOfType; @@ -172,5 +178,54 @@ class NBErrorHandlerTest { appender.cleanup(logger); } + @ParameterizedTest(name = "Error with {0}") + @MethodSource + void testExpectedResultVerificationErrorHandler(String name, Exception error, String log, long retriesCount, long errorsCount, Logger logger) { + // given + NBMock.LogAppender appender = NBMock.registerTestLogger(ERROR_HANDLER_APPENDER_NAME, logger, Level.INFO); + + var errorMetrics = new ErrorMetrics(ActivityDef.parseActivityDef("alias=testalias_result_verification_" + name)); + var eh = new NBErrorHandler(() -> "verifyexpected", () -> errorMetrics); + var retries = errorMetrics.getExceptionExpectedResultVerificationMetrics().getVerificationRetries(); + var errors = errorMetrics.getExceptionExpectedResultVerificationMetrics().getVerificationErrors(); + + assertThat(retries.getCount()).isEqualTo(0); + assertThat(errors.getCount()).isEqualTo(0); + + // when + eh.handleError(error, 1, 2); + + // then + assertThat(retries.getCount()).isEqualTo(retriesCount); + assertThat(errors.getCount()).isEqualTo(errorsCount); + + logger.getContext().stop(); // force any async appenders to flush + logger.getContext().start(); // resume processing + + assertThat(appender.getFirstEntry()).contains(log); + appender.cleanup(logger); + } + + private static Stream testExpectedResultVerificationErrorHandler() { + Logger logger = (Logger) LogManager.getLogger(ExpectedResultVerificationErrorHandler.class); + return Stream.of( + Arguments.of( + "retries left", + new ExpectedResultVerificationError(5), + "Cycle: 1 Verification of result did not pass. 5 retries left.", + 1, + 0, + logger + ), + Arguments.of( + "no retries left", + new ExpectedResultVerificationError(0), + "Verification of result did not pass. All retries exhausted.", + 0, + 1, + logger + ) + ); + } } diff --git a/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLI.java b/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLI.java index b64ccd212..f6291c9ba 100644 --- a/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLI.java +++ b/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLI.java @@ -246,7 +246,7 @@ public class NBCLI implements Function { } NBCLIOptions options = new NBCLIOptions(args); - logger = LogManager.getLogger("NBCLI"); + logger = LogManager.getLogger("NBCLI"); // TODO JK - already present in L166 NBIO.addGlobalIncludes(options.wantsIncludes()); diff --git a/engine-core/src/main/java/io/nosqlbench/engine/core/logging/LoggerConfig.java b/engine-core/src/main/java/io/nosqlbench/engine/core/logging/LoggerConfig.java index e97f20ebf..3c5c8b560 100644 --- a/engine-core/src/main/java/io/nosqlbench/engine/core/logging/LoggerConfig.java +++ b/engine-core/src/main/java/io/nosqlbench/engine/core/logging/LoggerConfig.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022 nosqlbench + * Copyright (c) 2022-2023 nosqlbench * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -17,11 +17,13 @@ package io.nosqlbench.engine.core.logging; import io.nosqlbench.api.logging.NBLogLevel; +import io.nosqlbench.engine.api.activityapi.errorhandling.modular.handlers.ExpectedResultVerificationErrorHandler; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.core.Filter; import org.apache.logging.log4j.core.LoggerContext; import org.apache.logging.log4j.core.appender.ConsoleAppender; +import org.apache.logging.log4j.core.appender.FileAppender; import org.apache.logging.log4j.core.appender.RollingFileAppender; import org.apache.logging.log4j.core.config.Configuration; import org.apache.logging.log4j.core.config.ConfigurationFactory; @@ -209,6 +211,25 @@ public class LoggerConfig extends ConfigurationFactory { .addComponent(triggeringPolicy); builder.add(logsAppenderBuilder); + // RESULTVERIFYLOG appender + AppenderComponentBuilder resultVerificationAppenderBuilder = + builder + .newAppender("RESULTVERIFYLOG", FileAppender.PLUGIN_NAME) + .addAttribute("append", false) + .addAttribute("fileName", loggerDir.resolve("expected-result-verification.log").toString()) + .add(builder + .newLayout("PatternLayout") + .addAttribute("pattern", "%d %p %C{1.} [%t] %m%n") + ); + builder.add(resultVerificationAppenderBuilder); + + // Result Verification logging + builder.add(builder + .newLogger(ExpectedResultVerificationErrorHandler.class.getName(), Level.INFO) + .add(builder.newAppenderRef("RESULTVERIFYLOG")) + .addAttribute("additivity", false) + ); + rootBuilder.add( builder.newAppenderRef("SCENARIO_APPENDER") .addAttribute("level", fileLevel) diff --git a/nb-api/src/main/java/io/nosqlbench/api/errors/ExpectedResultVerificationError.java b/nb-api/src/main/java/io/nosqlbench/api/errors/ExpectedResultVerificationError.java new file mode 100644 index 000000000..5b55fffa9 --- /dev/null +++ b/nb-api/src/main/java/io/nosqlbench/api/errors/ExpectedResultVerificationError.java @@ -0,0 +1,29 @@ +/* + * Copyright (c) 2022-2023 nosqlbench + * + * 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 + * + * http://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 io.nosqlbench.api.errors; + +public class ExpectedResultVerificationError extends RuntimeException { + private final int triesLeft; + + public ExpectedResultVerificationError(int triesLeft) { + this.triesLeft = triesLeft; + } + + public int getTriesLeft() { + return triesLeft; + } +} diff --git a/nb-api/src/main/java/io/nosqlbench/api/errors/MVELCompilationError.java b/nb-api/src/main/java/io/nosqlbench/api/errors/MVELCompilationError.java new file mode 100644 index 000000000..07ec6573d --- /dev/null +++ b/nb-api/src/main/java/io/nosqlbench/api/errors/MVELCompilationError.java @@ -0,0 +1,26 @@ +/* + * Copyright (c) 2022-2023 nosqlbench + * + * 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 + * + * http://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 io.nosqlbench.api.errors; + +/** + * MVELCompilationErrors are those known to occur during the compilation of expected results expressions. + */ +public class MVELCompilationError extends RuntimeException { + public MVELCompilationError(String message, Throwable cause) { + super(message, cause); + } +} From bda0790bd4ba246bbe4df4d80cfcc4e2035ae10e Mon Sep 17 00:00:00 2001 From: kijanowski Date: Wed, 17 May 2023 09:47:07 +0200 Subject: [PATCH 04/10] Code review adjustments --- .../uniform/BaseDriverAdapter.java | 1 + ...xpectedResultVerificationErrorHandler.java | 6 +-- .../uniform/actions/StandardAction.java | 6 +-- .../modular/NBErrorHandlerTest.java | 9 ++-- .../java/io/nosqlbench/engine/cli/NBCLI.java | 3 +- .../nosqlbench/engine/cli/NBCLIOptions.java | 14 ++++++ .../engine/core/logging/LoggerConfig.java | 47 ++++++++++++------- .../ExpectedResultVerificationError.java | 16 ++++++- 8 files changed, 70 insertions(+), 32 deletions(-) diff --git a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/BaseDriverAdapter.java b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/BaseDriverAdapter.java index 074413728..1e3bb9711 100644 --- a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/BaseDriverAdapter.java +++ b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/BaseDriverAdapter.java @@ -170,6 +170,7 @@ public abstract class BaseDriverAdapter implements DriverAdapte .add(Param.optional(List.of("workload", "yaml"), String.class, "location of workload yaml file")) .add(Param.optional("driver", String.class)) .add(Param.defaultTo("dryrun", "none").setRegex("(op|jsonnet|none)")) + .add(Param.optional("maxtries", Integer.class)) .asReadOnly(); } diff --git a/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/handlers/ExpectedResultVerificationErrorHandler.java b/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/handlers/ExpectedResultVerificationErrorHandler.java index bdc727526..19368d639 100644 --- a/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/handlers/ExpectedResultVerificationErrorHandler.java +++ b/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/handlers/ExpectedResultVerificationErrorHandler.java @@ -33,19 +33,17 @@ import java.util.function.Supplier; */ @Service(value = ErrorHandler.class, selector = "verifyexpected") public class ExpectedResultVerificationErrorHandler implements ErrorHandler, ErrorMetrics.Aware { - private static final Logger logger = LogManager.getLogger(ExpectedResultVerificationErrorHandler.class); + private static final Logger logger = LogManager.getLogger("VERIFY"); private ExceptionExpectedResultVerificationMetrics exceptionExpectedResultVerificationMetrics; @Override public ErrorDetail handleError(String name, Throwable t, long cycle, long durationInNanos, ErrorDetail detail) { if (t instanceof ExpectedResultVerificationError erve) { if (erve.getTriesLeft() == 0) { - logger.warn("Verification of result did not pass. All retries exhausted."); + logger.warn("Cycle: {} Verification of result {} did not pass following expression: {}", cycle, erve.getResultAsString(), erve.getExpectedResultExpression()); exceptionExpectedResultVerificationMetrics.countVerificationErrors(); } else { logger.info("Cycle: {} Verification of result did not pass. {} retries left.", cycle, erve.getTriesLeft()); - // TODO/MVEL: I think we should designate a separate logging channel for verification logic - // TODO JK: Should this be done via a dedicated logger in the LoggerConfig class? log4j2.xml files seem to be overridden? exceptionExpectedResultVerificationMetrics.countVerificationRetries(); } } diff --git a/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java b/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java index 18273bf8e..e204ac247 100644 --- a/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java +++ b/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java @@ -110,11 +110,8 @@ public class StandardAction, R extends Op> impl var expectedResultExpression = dispenser.getExpectedResultExpression(); if (shouldVerifyExpectedResultFor(op, expectedResultExpression)) { var verified = MVEL.executeExpression(expectedResultExpression, result, boolean.class); - // TODO/MVEL: Wherever this logic lives, we might want to have a symbolic description which - // is emitted for logging our metrics purposes indicating the success or failure outcomes. - // perhaps something like expected-name: .... and metrics could be then -success and -error if (!verified) { - throw new ExpectedResultVerificationError(maxTries - tries); + throw new ExpectedResultVerificationError(maxTries - tries, expectedResultExpression, result); } } } catch (Exception e) { @@ -125,6 +122,7 @@ public class StandardAction, R extends Op> impl if (error == null) { resultSuccessTimer.update(nanos, TimeUnit.NANOSECONDS); dispenser.onSuccess(cycle, nanos, op.getResultSize()); + break; } else { ErrorDetail detail = errorHandler.handleError(error, cycle, nanos); dispenser.onError(cycle, nanos, error); diff --git a/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java b/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java index d7a4706e3..146cc9ca5 100644 --- a/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java +++ b/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java @@ -207,11 +207,12 @@ class NBErrorHandlerTest { } private static Stream testExpectedResultVerificationErrorHandler() { - Logger logger = (Logger) LogManager.getLogger(ExpectedResultVerificationErrorHandler.class); + Logger logger = (Logger) LogManager.getLogger("VERIFY"); + var obj = new Object(); return Stream.of( Arguments.of( "retries left", - new ExpectedResultVerificationError(5), + new ExpectedResultVerificationError(5, "expected", obj), "Cycle: 1 Verification of result did not pass. 5 retries left.", 1, 0, @@ -219,8 +220,8 @@ class NBErrorHandlerTest { ), Arguments.of( "no retries left", - new ExpectedResultVerificationError(0), - "Verification of result did not pass. All retries exhausted.", + new ExpectedResultVerificationError(0, "expected", obj), + String.format("Cycle: 1 Verification of result %s did not pass following expression: %s", obj.toString(), "expected"), 0, 1, logger diff --git a/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLI.java b/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLI.java index f6291c9ba..c75a48674 100644 --- a/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLI.java +++ b/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLI.java @@ -160,6 +160,7 @@ public class NBCLI implements Function { .setMaxLogs(globalOptions.getLogsMax()) .setLogsDirectory(globalOptions.getLogsDirectory()) .setAnsiEnabled(globalOptions.isEnableAnsi()) + .setDedicatedVerificationLogger(globalOptions.isDedicatedVerificationLogger()) .activate(); ConfigurationFactory.setConfigurationFactory(loggerConfig); @@ -246,7 +247,7 @@ public class NBCLI implements Function { } NBCLIOptions options = new NBCLIOptions(args); - logger = LogManager.getLogger("NBCLI"); // TODO JK - already present in L166 + logger = LogManager.getLogger("NBCLI"); NBIO.addGlobalIncludes(options.wantsIncludes()); diff --git a/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java b/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java index 50abcebb0..5a685d384 100644 --- a/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java +++ b/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java @@ -124,6 +124,7 @@ public class NBCLIOptions { private static final String DEFAULT_CONSOLE_PATTERN = "TERSE"; private static final String DEFAULT_LOGFILE_PATTERN = "VERBOSE"; + private final static String ENABLE_DEDICATED_VERIFICATION_LOGGER = "--enable-dedicated-verification-logging"; // private static final String DEFAULT_CONSOLE_LOGGING_PATTERN = "%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n"; @@ -186,6 +187,7 @@ public class NBCLIOptions { private String graphitelogLevel="info"; private boolean wantsListCommands = false; private boolean wantsListApps = false; + private boolean dedicatedVerificationLogger = false; public boolean isWantsListApps() { return wantsListApps; @@ -227,6 +229,14 @@ public class NBCLIOptions { return this.graphitelogLevel; } + public boolean isDedicatedVerificationLogger() { + return this.dedicatedVerificationLogger; + } + + public void enableDedicatedVerificationLogger() { + this.dedicatedVerificationLogger = true; + } + public enum Mode { ParseGlobalsOnly, ParseAllOptions @@ -340,6 +350,10 @@ public class NBCLIOptions { setWantsStackTraces(true); arglist.removeFirst(); break; + case ENABLE_DEDICATED_VERIFICATION_LOGGER: + enableDedicatedVerificationLogger(); + arglist.removeFirst(); + break; case ANNOTATE_EVENTS: arglist.removeFirst(); String toAnnotate = readWordOrThrow(arglist, "annotated events"); diff --git a/engine-core/src/main/java/io/nosqlbench/engine/core/logging/LoggerConfig.java b/engine-core/src/main/java/io/nosqlbench/engine/core/logging/LoggerConfig.java index 3c5c8b560..fddd932fd 100644 --- a/engine-core/src/main/java/io/nosqlbench/engine/core/logging/LoggerConfig.java +++ b/engine-core/src/main/java/io/nosqlbench/engine/core/logging/LoggerConfig.java @@ -89,6 +89,7 @@ public class LoggerConfig extends ConfigurationFactory { private int maxLogfiles = 100; private String logfileLocation; private boolean ansiEnabled; + private boolean isDedicatedVerificationLoggerEnabled = false; public LoggerConfig() { @@ -109,6 +110,11 @@ public class LoggerConfig extends ConfigurationFactory { return this; } + public LoggerConfig setDedicatedVerificationLogger(boolean enabled) { + this.isDedicatedVerificationLoggerEnabled = enabled; + return this; + } + /** * Ensure that what is shown in the logfile includes at a minimum, * everything that is shown on console, but allow it to show more @@ -211,24 +217,10 @@ public class LoggerConfig extends ConfigurationFactory { .addComponent(triggeringPolicy); builder.add(logsAppenderBuilder); - // RESULTVERIFYLOG appender - AppenderComponentBuilder resultVerificationAppenderBuilder = - builder - .newAppender("RESULTVERIFYLOG", FileAppender.PLUGIN_NAME) - .addAttribute("append", false) - .addAttribute("fileName", loggerDir.resolve("expected-result-verification.log").toString()) - .add(builder - .newLayout("PatternLayout") - .addAttribute("pattern", "%d %p %C{1.} [%t] %m%n") - ); - builder.add(resultVerificationAppenderBuilder); - - // Result Verification logging - builder.add(builder - .newLogger(ExpectedResultVerificationErrorHandler.class.getName(), Level.INFO) - .add(builder.newAppenderRef("RESULTVERIFYLOG")) - .addAttribute("additivity", false) - ); + if (isDedicatedVerificationLoggerEnabled) { + var verificationLogfilePath = loggerDir.resolve(filebase + "_verification.log").toString(); + addResultVerificationLoggingChannel(builder, verificationLogfilePath); + } rootBuilder.add( builder.newAppenderRef("SCENARIO_APPENDER") @@ -388,4 +380,23 @@ public class LoggerConfig extends ConfigurationFactory { this.loggerDir = logsDirectory; return this; } + + private void addResultVerificationLoggingChannel(ConfigurationBuilder builder, String verificationLogfilePath) { + var appenderName = "RESULTVERIFYLOG"; + var appender = builder + .newAppender(appenderName, FileAppender.PLUGIN_NAME) + .addAttribute("append", false) + .addAttribute("fileName", verificationLogfilePath) + .add(builder + .newLayout("PatternLayout") + .addAttribute("pattern", "%d %p %C{1.} [%t] %m%n") + ); + var logger = builder + .newLogger("VERIFY", Level.INFO) + .add(builder.newAppenderRef(appenderName)) + .addAttribute("additivity", false); + + builder.add(appender); + builder.add(logger); + } } diff --git a/nb-api/src/main/java/io/nosqlbench/api/errors/ExpectedResultVerificationError.java b/nb-api/src/main/java/io/nosqlbench/api/errors/ExpectedResultVerificationError.java index 5b55fffa9..88df81890 100644 --- a/nb-api/src/main/java/io/nosqlbench/api/errors/ExpectedResultVerificationError.java +++ b/nb-api/src/main/java/io/nosqlbench/api/errors/ExpectedResultVerificationError.java @@ -16,14 +16,28 @@ package io.nosqlbench.api.errors; +import java.io.Serializable; + public class ExpectedResultVerificationError extends RuntimeException { private final int triesLeft; + private final Serializable expectedResultExpression; + private final Object result; - public ExpectedResultVerificationError(int triesLeft) { + public ExpectedResultVerificationError(int triesLeft, Serializable expectedResultExpression, Object result) { this.triesLeft = triesLeft; + this.expectedResultExpression = expectedResultExpression; + this.result = result; } public int getTriesLeft() { return triesLeft; } + + public Serializable getExpectedResultExpression() { + return expectedResultExpression; + } + + public String getResultAsString() { + return result.toString(); // TODO JK how to traverse the first x characters of the result? parse to json? via reflection? + } } From 2268dc9c0646576971fedbc20a0e4235c985f050 Mon Sep 17 00:00:00 2001 From: kijanowski Date: Wed, 17 May 2023 11:24:53 +0200 Subject: [PATCH 05/10] Resolve merge conflicts --- .../src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java | 5 ----- 1 file changed, 5 deletions(-) diff --git a/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java b/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java index dc6e9fce4..94e7611ab 100644 --- a/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java +++ b/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java @@ -350,11 +350,6 @@ public class NBCLIOptions { showStackTraces = true; arglist.removeFirst(); break; - case NBCLIOptions.DASH_VVV_TRACE: - this.consoleLevel = NBLogLevel.TRACE; - showStackTraces = true; - arglist.removeFirst(); - break; case NBCLIOptions.ENABLE_DEDICATED_VERIFICATION_LOGGER: enableDedicatedVerificationLogger(); break; From 1101df95c4e3fb323819d3c005f26b753dba21e2 Mon Sep 17 00:00:00 2001 From: kijanowski Date: Wed, 17 May 2023 11:29:04 +0200 Subject: [PATCH 06/10] Resolve merge conflicts --- .../src/main/java/io/nosqlbench/adapter/cqld4/Cqld4Space.java | 1 - 1 file changed, 1 deletion(-) diff --git a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/Cqld4Space.java b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/Cqld4Space.java index 89bd66961..eebb23c14 100644 --- a/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/Cqld4Space.java +++ b/adapter-cqld4/src/main/java/io/nosqlbench/adapter/cqld4/Cqld4Space.java @@ -293,7 +293,6 @@ public class Cqld4Space implements AutoCloseable { .add(Param.optional("whitelist", String.class, "list of whitelist hosts addresses")) .add(Param.optional("showstmt", Boolean.class, "show the contents of the statement in the log")) .add(Param.optional("cloud_proxy_address", String.class, "Cloud Proxy Address")) - .add(Param.optional("maxtries", Integer.class)) .add(SSLKsFactory.get().getConfigModel()) .add(getDriverOptionsModel()) .add(new OptionHelpers(new OptionsMap()).getConfigModel()) From fb8f70bf9af3608cd702ae5a1b47be111c41c0e2 Mon Sep 17 00:00:00 2001 From: kijanowski Date: Wed, 17 May 2023 11:51:18 +0200 Subject: [PATCH 07/10] Resolve merge conflicts --- .../engine/api/activityimpl/OpDispenser.java | 2 +- .../api/activityapi/errorhandling/ErrorMetrics.java | 7 +++---- .../ExceptionExpectedResultVerificationMetrics.java | 10 ++++++---- .../nosqlbench/engine/core/logging/LoggerConfig.java | 1 - 4 files changed, 10 insertions(+), 10 deletions(-) diff --git a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/OpDispenser.java b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/OpDispenser.java index c8d584f18..097744a5f 100644 --- a/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/OpDispenser.java +++ b/adapters-api/src/main/java/io/nosqlbench/engine/api/activityimpl/OpDispenser.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022 nosqlbench + * Copyright (c) 2022-2023 nosqlbench * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. diff --git a/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/ErrorMetrics.java b/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/ErrorMetrics.java index b1e63f1da..acc3e5433 100644 --- a/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/ErrorMetrics.java +++ b/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/ErrorMetrics.java @@ -62,10 +62,9 @@ public class ErrorMetrics { } public synchronized ExceptionExpectedResultVerificationMetrics getExceptionExpectedResultVerificationMetrics() { - if (exceptionExpectedResultVerificationMetrics == null) { - exceptionExpectedResultVerificationMetrics = new ExceptionExpectedResultVerificationMetrics(activityDef); - } - return exceptionExpectedResultVerificationMetrics; + if (null == exceptionExpectedResultVerificationMetrics) + this.exceptionExpectedResultVerificationMetrics = new ExceptionExpectedResultVerificationMetrics(this.parentLabels); + return this.exceptionExpectedResultVerificationMetrics; } public interface Aware { diff --git a/engine-api/src/main/java/io/nosqlbench/engine/api/metrics/ExceptionExpectedResultVerificationMetrics.java b/engine-api/src/main/java/io/nosqlbench/engine/api/metrics/ExceptionExpectedResultVerificationMetrics.java index 45657f64b..e54726dfc 100644 --- a/engine-api/src/main/java/io/nosqlbench/engine/api/metrics/ExceptionExpectedResultVerificationMetrics.java +++ b/engine-api/src/main/java/io/nosqlbench/engine/api/metrics/ExceptionExpectedResultVerificationMetrics.java @@ -17,7 +17,7 @@ package io.nosqlbench.engine.api.metrics; import com.codahale.metrics.Counter; -import io.nosqlbench.api.engine.activityimpl.ActivityDef; +import io.nosqlbench.api.config.NBLabeledElement; import io.nosqlbench.api.engine.metrics.ActivityMetrics; @@ -25,12 +25,14 @@ import io.nosqlbench.api.engine.metrics.ActivityMetrics; * Use this to provide exception metering during expected result verification. */ public class ExceptionExpectedResultVerificationMetrics { + private final NBLabeledElement parentLabels; private final Counter verificationErrors; private final Counter verificationRetries; - public ExceptionExpectedResultVerificationMetrics(ActivityDef activityDef) { - verificationRetries = ActivityMetrics.counter(activityDef, "verificationcounts.RETRIES"); - verificationErrors = ActivityMetrics.counter(activityDef, "verificationcounts.ERRORS"); + public ExceptionExpectedResultVerificationMetrics(final NBLabeledElement parentLabels) { + this.parentLabels = parentLabels; + verificationRetries = ActivityMetrics.counter(parentLabels, "verificationcounts.RETRIES"); + verificationErrors = ActivityMetrics.counter(parentLabels, "verificationcounts.ERRORS"); } public void countVerificationRetries() { diff --git a/engine-core/src/main/java/io/nosqlbench/engine/core/logging/LoggerConfig.java b/engine-core/src/main/java/io/nosqlbench/engine/core/logging/LoggerConfig.java index fddd932fd..b3f95008a 100644 --- a/engine-core/src/main/java/io/nosqlbench/engine/core/logging/LoggerConfig.java +++ b/engine-core/src/main/java/io/nosqlbench/engine/core/logging/LoggerConfig.java @@ -17,7 +17,6 @@ package io.nosqlbench.engine.core.logging; import io.nosqlbench.api.logging.NBLogLevel; -import io.nosqlbench.engine.api.activityapi.errorhandling.modular.handlers.ExpectedResultVerificationErrorHandler; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.Logger; import org.apache.logging.log4j.core.Filter; From 63cfa5d85d72988b427e9a18d14eb440063609ff Mon Sep 17 00:00:00 2001 From: kijanowski Date: Wed, 17 May 2023 12:22:58 +0200 Subject: [PATCH 08/10] Resolve merge conflicts --- .../errorhandling/modular/NBErrorHandlerTest.java | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-) diff --git a/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java b/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java index 3e8b9f193..6c9b7295f 100644 --- a/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java +++ b/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java @@ -21,12 +21,10 @@ import com.codahale.metrics.Histogram; import com.codahale.metrics.Meter; import com.codahale.metrics.Timer; import io.nosqlbench.api.config.NBLabeledElement; -import io.nosqlbench.api.engine.activityimpl.ActivityDef; import io.nosqlbench.api.errors.ExpectedResultVerificationError; import io.nosqlbench.engine.api.activityapi.errorhandling.ErrorMetrics; import io.nosqlbench.engine.api.activityapi.errorhandling.modular.handlers.CountErrorHandler; import io.nosqlbench.engine.api.activityapi.errorhandling.modular.handlers.CounterErrorHandler; -import io.nosqlbench.engine.api.activityapi.errorhandling.modular.handlers.ExpectedResultVerificationErrorHandler; import io.nosqlbench.util.NBMock; import io.nosqlbench.util.NBMock.LogAppender; import org.apache.logging.log4j.Level; @@ -185,8 +183,7 @@ class NBErrorHandlerTest { void testExpectedResultVerificationErrorHandler(String name, Exception error, String log, long retriesCount, long errorsCount, Logger logger) { // given NBMock.LogAppender appender = NBMock.registerTestLogger(ERROR_HANDLER_APPENDER_NAME, logger, Level.INFO); - - var errorMetrics = new ErrorMetrics(ActivityDef.parseActivityDef("alias=testalias_result_verification_" + name)); + var errorMetrics = new ErrorMetrics(NBLabeledElement.forKV("activity","testalias_result_verification_" + name)); var eh = new NBErrorHandler(() -> "verifyexpected", () -> errorMetrics); var retries = errorMetrics.getExceptionExpectedResultVerificationMetrics().getVerificationRetries(); var errors = errorMetrics.getExceptionExpectedResultVerificationMetrics().getVerificationErrors(); From c48dcb1848dffd98522206fb08d656c431cee887 Mon Sep 17 00:00:00 2001 From: kijanowski Date: Wed, 17 May 2023 14:37:55 +0200 Subject: [PATCH 09/10] Do not pretty-print the result object in case of a verification error --- .../ExpectedResultVerificationErrorHandler.java | 2 +- .../activityimpl/uniform/actions/StandardAction.java | 2 +- .../errorhandling/modular/NBErrorHandlerTest.java | 10 +++++----- .../api/errors/ExpectedResultVerificationError.java | 7 +------ 4 files changed, 8 insertions(+), 13 deletions(-) diff --git a/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/handlers/ExpectedResultVerificationErrorHandler.java b/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/handlers/ExpectedResultVerificationErrorHandler.java index 19368d639..c2ca0cde9 100644 --- a/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/handlers/ExpectedResultVerificationErrorHandler.java +++ b/engine-api/src/main/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/handlers/ExpectedResultVerificationErrorHandler.java @@ -40,7 +40,7 @@ public class ExpectedResultVerificationErrorHandler implements ErrorHandler, Err public ErrorDetail handleError(String name, Throwable t, long cycle, long durationInNanos, ErrorDetail detail) { if (t instanceof ExpectedResultVerificationError erve) { if (erve.getTriesLeft() == 0) { - logger.warn("Cycle: {} Verification of result {} did not pass following expression: {}", cycle, erve.getResultAsString(), erve.getExpectedResultExpression()); + logger.warn("Cycle: {} Verification of result did not pass following expression: {}", cycle, erve.getExpectedResultExpression()); exceptionExpectedResultVerificationMetrics.countVerificationErrors(); } else { logger.info("Cycle: {} Verification of result did not pass. {} retries left.", cycle, erve.getTriesLeft()); diff --git a/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java b/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java index e204ac247..b0ab2aa8d 100644 --- a/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java +++ b/engine-api/src/main/java/io/nosqlbench/engine/api/activityimpl/uniform/actions/StandardAction.java @@ -111,7 +111,7 @@ public class StandardAction, R extends Op> impl if (shouldVerifyExpectedResultFor(op, expectedResultExpression)) { var verified = MVEL.executeExpression(expectedResultExpression, result, boolean.class); if (!verified) { - throw new ExpectedResultVerificationError(maxTries - tries, expectedResultExpression, result); + throw new ExpectedResultVerificationError(maxTries - tries, expectedResultExpression); } } } catch (Exception e) { diff --git a/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java b/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java index 6c9b7295f..7534f9966 100644 --- a/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java +++ b/engine-api/src/test/java/io/nosqlbench/engine/api/activityapi/errorhandling/modular/NBErrorHandlerTest.java @@ -205,13 +205,13 @@ class NBErrorHandlerTest { appender.cleanup(logger); } + @SuppressWarnings("unused") private static Stream testExpectedResultVerificationErrorHandler() { Logger logger = (Logger) LogManager.getLogger("VERIFY"); - var obj = new Object(); return Stream.of( Arguments.of( "retries left", - new ExpectedResultVerificationError(5, "expected", obj), + new ExpectedResultVerificationError(5, "expected"), "Cycle: 1 Verification of result did not pass. 5 retries left.", 1, 0, @@ -219,13 +219,13 @@ class NBErrorHandlerTest { ), Arguments.of( "no retries left", - new ExpectedResultVerificationError(0, "expected", obj), - String.format("Cycle: 1 Verification of result %s did not pass following expression: %s", obj.toString(), "expected"), + new ExpectedResultVerificationError(0, "expected"), + "Cycle: 1 Verification of result did not pass following expression: expected", 0, 1, logger ) - ); + ); } } diff --git a/nb-api/src/main/java/io/nosqlbench/api/errors/ExpectedResultVerificationError.java b/nb-api/src/main/java/io/nosqlbench/api/errors/ExpectedResultVerificationError.java index 88df81890..44d70c594 100644 --- a/nb-api/src/main/java/io/nosqlbench/api/errors/ExpectedResultVerificationError.java +++ b/nb-api/src/main/java/io/nosqlbench/api/errors/ExpectedResultVerificationError.java @@ -21,12 +21,10 @@ import java.io.Serializable; public class ExpectedResultVerificationError extends RuntimeException { private final int triesLeft; private final Serializable expectedResultExpression; - private final Object result; - public ExpectedResultVerificationError(int triesLeft, Serializable expectedResultExpression, Object result) { + public ExpectedResultVerificationError(int triesLeft, Serializable expectedResultExpression) { this.triesLeft = triesLeft; this.expectedResultExpression = expectedResultExpression; - this.result = result; } public int getTriesLeft() { @@ -37,7 +35,4 @@ public class ExpectedResultVerificationError extends RuntimeException { return expectedResultExpression; } - public String getResultAsString() { - return result.toString(); // TODO JK how to traverse the first x characters of the result? parse to json? via reflection? - } } From 863172d7cbede7d0020e9df9ae4a659c1774d941 Mon Sep 17 00:00:00 2001 From: kijanowski Date: Thu, 18 May 2023 15:28:21 +0200 Subject: [PATCH 10/10] Code review fixes --- .../src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java | 1 + 1 file changed, 1 insertion(+) diff --git a/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java b/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java index 94e7611ab..1687a225e 100644 --- a/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java +++ b/engine-cli/src/main/java/io/nosqlbench/engine/cli/NBCLIOptions.java @@ -352,6 +352,7 @@ public class NBCLIOptions { break; case NBCLIOptions.ENABLE_DEDICATED_VERIFICATION_LOGGER: enableDedicatedVerificationLogger(); + arglist.removeFirst(); break; case NBCLIOptions.ANNOTATE_EVENTS: arglist.removeFirst();