Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improvement of CLI logging and error messages related to reflection. #1602

Closed
wants to merge 10 commits into from
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
import java.nio.file.Paths;
import java.util.Arrays;

import com.devonfw.cobigen.cli.constants.MessagesConstants;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

Expand Down Expand Up @@ -34,11 +35,21 @@ public static void main(String... args) {
LOG.debug("Current working directory: {}", System.getProperty("user.dir"));
CommandLine commandLine = new CommandLine(new CobiGenCommand());
commandLine.registerConverter(Path.class, s -> Paths.get(s));
CommandLine.IExecutionExceptionHandler exceptionHandler = new CommandLine.IExecutionExceptionHandler() {
@Override
public int handleExecutionException(Exception e, CommandLine commandLine, CommandLine.ParseResult parseResult) throws Exception {
if (LOG.isDebugEnabled()) {
LOG.debug("Cobigen exited with exception: ", e);
} else {
LOG.error("An error occurred while executing CobiGen: {}", e.getMessage());
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That's a strange pattern. Normally you would expect that enabling debug log level, just logs come in addition. In this case, you would end up in a situation, that logs, which you have seen on INFO log will vanish. That's an unexpected behavior, which would result in confusion during log debugging.

I would propose to do something like this:

LOG.error("An error occurred while executing CobiGen: {}", e.getMessage(), (LOG.isDebugEnabled() ? e : null));

This would log the exception just in case you have debug log enabled, but it would keep the actual log message, so you will find the same log in both cases (INFO log as well as DEBUG log level).

Nontheless, there is one critical question here. Do we expect proper messages here? Do we throw proper exceptions with proper message, which give enough value at this point to guide / help the user? Or is this exception case here more about exceptions, we would not expect? If it's the latter, then I think it does not make any sense to distinguish debug log. If it's about exceptions only, which we would not expect, then we should always log the exception. But if we expect a lot of proper exceptions, which we throw on our own with proper messages, then the compressed solution as proposed is totally fine.

return 1;
}
};
commandLine.setExecutionExceptionHandler(exceptionHandler);
int exitCode = commandLine.execute(args);
if (exitCode == 0) {
LOG.info("Success");
} else {
LOG.info("Failed");
if (exitCode != 0) {
LOG.error("Cobigen terminated in an unexpected manner. {}", (LOG.isDebugEnabled() ? "" : MessagesConstants.VERBOSE_HINT));
}
System.exit(exitCode);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,8 @@ public Integer call() throws Exception {

if (this.verbose) {
CLILogger.setLevel(Level.DEBUG);
} else {
CLILogger.setLevel(Level.INFO);
jan-vcapgemini marked this conversation as resolved.
Show resolved Hide resolved
}

return doAction();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -104,7 +104,6 @@ public Integer doAction() throws Exception {
CobiGen cg = CobiGenUtils.initializeCobiGen(this.templatesProject);

resolveTemplateDependencies();

if (this.increments == null && this.templates != null) {
Tuple<List<Object>, List<TemplateTo>> inputsAndArtifacts = preprocess(cg, TemplateTo.class);
for (int i = 0; i < inputsAndArtifacts.getA().size(); i++) {
Expand Down Expand Up @@ -331,16 +330,20 @@ public <T extends GenerableArtifact> void generate(Path inputFile, Object input,
inputFile);
report = cg.generate(input, generableArtifacts, this.outputRootPath.toAbsolutePath(), false, (task, progress) -> {
});
ValidationUtils.checkGenerationReport(report);
Set<Path> generatedJavaFiles = report.getGeneratedFiles().stream().filter(e -> e.getFileName().endsWith(".java"))
.collect(Collectors.toSet());
if (!generatedJavaFiles.isEmpty()) {
try {
ParsingUtils.formatJavaSources(generatedJavaFiles);
} catch (FormatterException e) {
LOG.warn(
"Generation was successful but we were not able to format your code. Maybe you will see strange formatting.");
boolean generationSuccess = ValidationUtils.checkGenerationReport(report);
if (generationSuccess) {
Set<Path> generatedJavaFiles = report.getGeneratedFiles().stream().filter(e -> e.getFileName().endsWith(".java"))
.collect(Collectors.toSet());
if (!generatedJavaFiles.isEmpty()) {
try {
ParsingUtils.formatJavaSources(generatedJavaFiles);
} catch (FormatterException e) {
LOG.warn(
"Generation was successful but we were not able to format your code. Maybe you will see strange formatting.");
}
}
} else {
LOG.error("Generation not successful! {}", (LOG.isDebugEnabled() ? "" : MessagesConstants.VERBOSE_HINT));
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -76,4 +76,9 @@ public class MessagesConstants {
* Message constant: description of the custom-location option
*/
public static final String CUSTOM_LOCATION_OPTION_DESCRIPTION = "Custom location where the unpacked templates will be stored.";

/**
* Message constant: hint for verbose mode.
*/
public static final String VERBOSE_HINT = "For more info execute in verbose mode (-v).";
}
Original file line number Diff line number Diff line change
Expand Up @@ -76,28 +76,30 @@ public static boolean isOutputRootPathValid(Path outputRootPath) {
* Checks the generation report in order to find possible errors and warnings
*
* @param report the generation report returned by the CobiGen.generate method
* @return true if generation succeeded, false otherwise
*/
public static void checkGenerationReport(GenerationReportTo report) {
public static boolean checkGenerationReport(GenerationReportTo report) {

for (String warning : report.getWarnings()) {
LOG.debug("Warning: {}", warning);
}

// Successful generation
if (report.getErrors() == null || report.getErrors().isEmpty()) {
LOG.info("Successful generation.");
} else {
if (LOG.isDebugEnabled() && report.getErrors().size() > 1) {
for (int i = 1; i < report.getErrors().size(); i++) {
LOG.error("Further reported error:", report.getErrors().get(i));
}
}
if (report.getErrors().get(0) instanceof CobiGenRuntimeException) {
throw report.getErrors().get(0);
return true;
}
// Unsuccesful generation, log error messages to user
// Log exceptions for devs in DEBUG
for (int i = 0; i < report.getErrors().size(); i++) {
RuntimeException e = report.getErrors().get(i);
if (LOG.isDebugEnabled()) {
LOG.debug("Encountered an exception: ", e);
} else {
throw new CobiGenRuntimeException("Generation failed. Enable debug mode to see the exceptions occurred.",
report.getErrors().get(0));
LOG.error("Error: {}", e.getMessage());
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same as above, that's actually an antipattern do provide different logs in different levels.

}
}
return false;
}

/**
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -73,8 +73,21 @@ public void process(TextTemplate template, Map<String, Object> model, Writer out
env.setLogTemplateExceptions(false); // no duplicate logging
env.process();
} catch (TemplateException e) {
// Get root cause
Throwable rootCause = e;
while (rootCause.getCause() != null && rootCause.getCause() != rootCause) {
rootCause = rootCause.getCause();
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

exception causes are recursively defined, meaning, you will not be able to get the root cause here. There is an Exception Util, which could be used to properly give you some better information.

String detailedCause = "";

if (rootCause.getClass().getCanonicalName().contains("java.lang")) {
detailedCause = ". A problem with Reflection has likely occurred: " + "Exception of type: "
+ rootCause.getClass().getCanonicalName() + " with message: " + rootCause.getMessage()
+ ", please consider rebuilding your project as a possible fix.";
}
throw new CobiGenRuntimeException("An error occurred while generating the template: "
+ template.getAbsoluteTemplatePath() + " (FreeMarker v" + FreemarkerMetadata.VERSION + ")", e);
+ template.getAbsoluteTemplatePath() + " (FreeMarker v" + FreemarkerMetadata.VERSION + ")" + detailedCause,
e);
} catch (Throwable e) {
throw new CobiGenRuntimeException("An unkonwn error occurred while generating the template: "
+ template.getAbsoluteTemplatePath() + " (FreeMarker v" + FreemarkerMetadata.VERSION + ")", e);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -104,8 +104,15 @@ private Object readInput(Path path, Charset inputCharset, Map<TriggerInterpreter
"Was not able to read input {} with inputreader '{}' although it was reported to be most likely readable. Trying next input reader...",
path, triggerInterpreter, e);
} catch (Throwable e) {
LOG.debug("While reading the input {} with the inputreader {}, an exception occured. Trying next input reader...",
path, triggerInterpreter, e);
if (LOG.isDebugEnabled()) {
// Logs full exception for DEBUG
LOG.debug("While reading the input {} with the inputreader {}, an exception occured. Trying next input reader...",
path, triggerInterpreter, e);
} else {
// Only logs message as possible hint for user
LOG.warn("While reading the input {} with the inputreader {}, an exception occured: {} Trying next input reader...",
path, triggerInterpreter, e.getMessage());
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

again anti-pattern, see above

}
return null;
}
Expand Down