Skip to content

Commit

Permalink
#293: log warning instead of assertion in Step for robustness (#295)
Browse files Browse the repository at this point in the history
  • Loading branch information
hohwille authored Apr 19, 2024
1 parent f23348b commit 3b37c2c
Show file tree
Hide file tree
Showing 7 changed files with 272 additions and 37 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -774,8 +774,15 @@ public StepImpl newStep(boolean silent, String name, Object... parameters) {
*/
public void endStep(StepImpl step) {

assert (step == this.currentStep);
this.currentStep = this.currentStep.getParent();
if (step == this.currentStep) {
this.currentStep = this.currentStep.getParent();
} else {
String currentStepName = "null";
if (this.currentStep != null) {
currentStepName = this.currentStep.getName();
}
warning("endStep called with wrong step '{}' but expected '{}'", step.getName(), currentStepName);
}
}

/**
Expand Down
68 changes: 57 additions & 11 deletions cli/src/main/java/com/devonfw/tools/ide/step/Step.java
Original file line number Diff line number Diff line change
@@ -1,10 +1,11 @@
package com.devonfw.tools.ide.step;

import java.util.concurrent.Callable;

/**
* Interface for a {@link Step} of the process. Allows to split larger processes into smaller steps that are traced
* and measured. At the end you can get a report with the hierarchy of all steps and their success/failure status,
* duration in absolute and relative numbers to gain transparency.<br>
* The typical use should follow this pattern:
* Interface for a {@link Step} of the process. Allows to split larger processes into smaller steps that are traced and
* measured. At the end you can get a report with the hierarchy of all steps and their success/failure status, duration
* in absolute and relative numbers to gain transparency.<br> The typical use should follow this pattern:
*
* <pre>
* Step step = context.{@link com.devonfw.tools.ide.context.IdeContext#newStep(String) newStep}("My step description");
Expand All @@ -30,14 +31,14 @@ public interface Step {

/**
* @return the duration of this {@link Step} from construction to {@link #success()} or {@link #end()}. Will be
* {@code 0} if not {@link #end() ended}.
* {@code 0} if not {@link #end() ended}.
*/
long getDuration();

/**
* @return {@code Boolean#TRUE} if this {@link Step} has {@link #success() succeeded}, {@code Boolean#FALSE} if the
* {@link Step} has {@link #end() ended} without {@link #success() success} and {@code null} if the
* {@link Step} is still running.
* {@link Step} has {@link #end() ended} without {@link #success() success} and {@code null} if the {@link Step} is
* still running.
*/
Boolean getSuccess();

Expand All @@ -51,7 +52,7 @@ default boolean isSuccess() {

/**
* @return {@code true} if this step {@link #end() ended} without {@link #success() success} e.g. with an
* {@link #error(String) error}, {@code false} otherwise.
* {@link #error(String) error}, {@code false} otherwise.
*/
default boolean isFailure() {

Expand Down Expand Up @@ -134,7 +135,7 @@ default void error(Throwable error) {
*
* @param error the catched {@link Throwable}.
* @param suppress to suppress the error logging (if error will be rethrown and duplicated error messages shall be
* avoided).
* avoided).
*/
default void error(Throwable error, boolean suppress) {

Expand Down Expand Up @@ -173,7 +174,7 @@ default void error(Throwable error, String message, Object... args) {
*
* @param error the catched {@link Throwable}. May be {@code null} if only a {@code message} is provided.
* @param suppress to suppress the error logging (if error will be rethrown and duplicated error messages shall be
* avoided).
* avoided).
* @param message the explicit message to log as error.
* @param args the optional arguments to fill as placeholder into the {@code message}.
*/
Expand All @@ -186,7 +187,7 @@ default void error(Throwable error, String message, Object... args) {

/**
* @param i the index of the requested parameter. Should be in the range from {@code 0} to
* <code>{@link #getParameterCount()}-1</code>.
* <code>{@link #getParameterCount()}-1</code>.
* @return the parameter at the given index {@code i} or {@code null} if no such parameter exists.
*/
Object getParameter(int i);
Expand All @@ -196,4 +197,49 @@ default void error(Throwable error, String message, Object... args) {
*/
int getParameterCount();

/**
* @param stepCode the {@link Runnable} to {@link Runnable#run() execute} for this {@link Step}.
*/
default void run(Runnable stepCode) {

try {
stepCode.run();
if (getSuccess() == null) {
success();
}
} catch (RuntimeException | Error e) {
error(e);
throw e;
} finally {
end();
}
}

/**
* @param stepCode the {@link Callable} to {@link Callable#call() execute} for this {@link Step}.
* @param <R> type of the return value.
* @return the value returned from {@link Callable#call()}.
*/
default <R> R call(Callable<R> stepCode) {

try {
R result = stepCode.call();
if (getSuccess() == null) {
success();
}
return result;
} catch (Throwable e) {
error(e);
if (e instanceof RuntimeException re) {
throw re;
} else if (e instanceof Error error) {
throw error;
} else {
throw new IllegalStateException(e);
}
} finally {
end();
}
}

}
32 changes: 19 additions & 13 deletions cli/src/main/java/com/devonfw/tools/ide/step/StepImpl.java
Original file line number Diff line number Diff line change
@@ -1,14 +1,14 @@
package com.devonfw.tools.ide.step;

import com.devonfw.tools.ide.context.AbstractIdeContext;
import com.devonfw.tools.ide.context.IdeContext;
import com.devonfw.tools.ide.log.IdeSubLogger;

import java.time.Duration;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;

import com.devonfw.tools.ide.context.AbstractIdeContext;
import com.devonfw.tools.ide.context.IdeContext;
import com.devonfw.tools.ide.log.IdeSubLogger;

/**
* Regular implementation of {@link Step}.
*/
Expand Down Expand Up @@ -131,23 +131,27 @@ public void end() {

private void end(Boolean newSuccess, Throwable error, boolean suppress, String message, Object[] args) {

if (this.success != null) {
boolean firstCallOfEnd = (this.success == null);
if (!firstCallOfEnd) {
assert (this.duration > 0);
// success or error may only be called once per Step, while end() will be called again in finally block
assert (newSuccess == null) : "Step " + this.name + " already ended with " + this.success
+ " and cannot be ended again with " + newSuccess;
return;
if (newSuccess != null) {
this.context.warning("Step '{}' already ended with {} and now ended again with {}.", this.name, this.success,
newSuccess);
} else {
return;
}
}
assert (this.duration == 0);
long delay = System.currentTimeMillis() - this.start;
if (delay == 0) {
delay = 1;
}
this.duration = delay;
if (newSuccess == null) {
newSuccess = Boolean.FALSE;
}
this.success = newSuccess;
if (this.success != Boolean.FALSE) { // never allow a failed step to change to success
this.duration = delay;
this.success = newSuccess;
}
if (newSuccess.booleanValue()) {
assert (error == null);
if (message != null) {
Expand All @@ -174,7 +178,9 @@ private void end(Boolean newSuccess, Throwable error, boolean suppress, String m
}
logger.log("Step '{}' ended with failure.", this.name);
}
this.context.endStep(this);
if (firstCallOfEnd) {
this.context.endStep(this);
}
}

/**
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,7 @@ public abstract class LocalToolCommandlet extends ToolCommandlet {
* @param context the {@link IdeContext}.
* @param tool the {@link #getName() tool name}.
* @param tags the {@link #getTags() tags} classifying the tool. Should be created via {@link Set#of(Object) Set.of}
* method.
* method.
*/
public LocalToolCommandlet(IdeContext context, String tool, Set<Tag> tags) {

Expand All @@ -43,7 +43,7 @@ public Path getToolPath() {

/**
* @return the {@link Path} where the executables of the tool can be found. Typically a "bin" folder inside
* {@link #getToolPath() tool path}.
* {@link #getToolPath() tool path}.
*/
public Path getToolBinPath() {

Expand Down Expand Up @@ -84,13 +84,13 @@ protected boolean doInstall(boolean silent) {
fileAccess.mkdirs(toolPath.getParent());
fileAccess.symlink(installation.linkDir(), toolPath);
this.context.getPath().setPath(this.tool, installation.binDir());
postInstall();
if (installedVersion == null) {
step.success("Successfully installed {} in version {}", this.tool, resolvedVersion);
} else {
step.success("Successfully installed {} in version {} replacing previous version {}", this.tool,
resolvedVersion, installedVersion);
}
postInstall();
return true;
} catch (RuntimeException e) {
step.error(e, true);
Expand All @@ -107,7 +107,7 @@ protected boolean doInstall(boolean silent) {
* IDE installation.
*
* @param version the {@link VersionIdentifier} requested to be installed. May also be a
* {@link VersionIdentifier#isPattern() version pattern}.
* {@link VersionIdentifier#isPattern() version pattern}.
* @return the {@link ToolInstallation} in the central software repository matching the given {@code version}.
*/
public ToolInstallation installInRepo(VersionIdentifier version) {
Expand All @@ -121,7 +121,7 @@ public ToolInstallation installInRepo(VersionIdentifier version) {
* IDE installation.
*
* @param version the {@link VersionIdentifier} requested to be installed. May also be a
* {@link VersionIdentifier#isPattern() version pattern}.
* {@link VersionIdentifier#isPattern() version pattern}.
* @param edition the specific edition to install.
* @return the {@link ToolInstallation} in the central software repository matching the given {@code version}.
*/
Expand All @@ -136,7 +136,7 @@ public ToolInstallation installInRepo(VersionIdentifier version, String edition)
* IDE installation.
*
* @param version the {@link VersionIdentifier} requested to be installed. May also be a
* {@link VersionIdentifier#isPattern() version pattern}.
* {@link VersionIdentifier#isPattern() version pattern}.
* @param edition the specific edition to install.
* @param toolRepository the {@link ToolRepository} to use.
* @return the {@link ToolInstallation} in the central software repository matching the given {@code version}.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 +38,7 @@ public abstract class AbstractIdeContextTest extends Assertions {

/**
* @param testProject the (folder)name of the project test case, in this folder a 'project' folder represents the test
* project in {@link #TEST_PROJECTS}. E.g. "basic".
* project in {@link #TEST_PROJECTS}. E.g. "basic".
* @return the {@link IdeTestContext} pointing to that project.
*/
protected IdeTestContext newContext(String testProject) {
Expand All @@ -48,7 +48,7 @@ protected IdeTestContext newContext(String testProject) {

/**
* @param testProject the (folder)name of the project test case, in this folder a 'project' folder represents the test
* project in {@link #TEST_PROJECTS}. E.g. "basic".
* project in {@link #TEST_PROJECTS}. E.g. "basic".
* @param projectPath the relative path inside the test project where to create the context.
* @return the {@link IdeTestContext} pointing to that project.
*/
Expand All @@ -59,7 +59,7 @@ protected static IdeTestContext newContext(String testProject, String projectPat

/**
* @param testProject the (folder)name of the project test case, in this folder a 'project' folder represents the test
* project in {@link #TEST_PROJECTS}. E.g. "basic".
* project in {@link #TEST_PROJECTS}. E.g. "basic".
* @param projectPath the relative path inside the test project where to create the context.
* @param copyForMutation - {@code true} to create a copy of the project that can be modified by the test,
* {@code false} otherwise (only to save resources if you are 100% sure that your test never modifies anything
Expand Down Expand Up @@ -136,7 +136,7 @@ protected static void assertLogMessage(IdeTestContext context, IdeLogLevel level
* @param level the expected {@link IdeLogLevel}.
* @param message the expected {@link com.devonfw.tools.ide.log.IdeSubLogger#log(String) log message}.
* @param contains - {@code true} if the given {@code message} may only be a sub-string of the log-message to assert,
* {@code false} otherwise (the entire log message including potential parameters being filled in is asserted).
* {@code false} otherwise (the entire log message including potential parameters being filled in is asserted).
*/
protected static void assertLogMessage(IdeTestContext context, IdeLogLevel level, String message, boolean contains) {

Expand All @@ -155,6 +155,43 @@ public boolean matches(String e) {
}
}

/**
* @param context the {@link IdeContext} that was created via the {@link #newContext(String) newContext} method.
* @param level the expected {@link IdeLogLevel}.
* @param message the {@link com.devonfw.tools.ide.log.IdeSubLogger#log(String) log message} that should not have been
* logged.
*/
protected static void assertNoLogMessage(IdeTestContext context, IdeLogLevel level, String message) {

assertNoLogMessage(context, level, message, false);
}

/**
* @param context the {@link IdeContext} that was created via the {@link #newContext(String) newContext} method.
* @param level the expected {@link IdeLogLevel}.
* @param message the {@link com.devonfw.tools.ide.log.IdeSubLogger#log(String) log message} that should not have been
* logged.
* @param contains - {@code true} if the given {@code message} may only be a sub-string of the log-message to assert,
* {@code false} otherwise (the entire log message including potential parameters being filled in is asserted).
*/
protected static void assertNoLogMessage(IdeTestContext context, IdeLogLevel level, String message,
boolean contains) {

IdeTestLogger logger = context.level(level);
ListAssert<String> assertion = assertThat(logger.getMessages()).as(level.name() + "-Log messages");
if (contains) {
Condition<String> condition = new Condition<>() {
public boolean matches(String e) {

return e.contains(message);
}
};
assertion.filteredOn(condition).isEmpty();
} else {
assertion.doesNotContain(message);
}
}

/**
* Checks if a {@link com.devonfw.tools.ide.io.IdeProgressBar} was implemented correctly and reflects a default
* behavior
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -35,9 +35,15 @@ public IdeSlf4jLogger(IdeLogLevel level) {
@Override
public String log(Throwable error, String message, Object... args) {

if ((message == null) && (error != null)) {
message = error.getMessage();
if (message == null) {
message = error.toString();
}
}
String msg = message;
if ((this.level == IdeLogLevel.STEP) || (this.level == IdeLogLevel.INTERACTION)
|| (this.level == IdeLogLevel.SUCCESS)) {
|| (this.level == IdeLogLevel.SUCCESS)) {
msg = this.level.name() + ":" + message;
}
LoggingEventBuilder builder = LOG.atLevel(this.logLevel);
Expand Down
Loading

0 comments on commit 3b37c2c

Please sign in to comment.