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

Lur1an · 2022-11-15T07:53:07Z

Adresses/Fixes #1593, #1594.

Implements

ExceptionHandler for CLI
Fixes for logging-level
Clearer Exception/Error messages regarding reflection errors

@devonfw/cobigen

- Fixed log-level settings for CLI - Stacktrace for exception only printed in -v mode - Rework of ValidationUtils, execution is not interrupted by exception, instead boolean value is returned - Uncaught exceptions in CLI execution are manually handled with a ExecutionExceptionHandler to improve logging - Added detail to exception messages connected to reflection issues

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/CobiGenCLI.java

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/commands/GenerateCommand.java

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/CobiGenCLI.java

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/commands/CommandCommons.java

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/commands/GenerateCommand.java

...reemarker/src/main/java/com/devonfw/cobigen/tempeng/freemarker/FreeMarkerTemplateEngine.java

maybeec · 2022-11-18T16:09:15Z

cobigen/cobigen-core/src/main/java/com/devonfw/cobigen/impl/generator/InputInterpreterImpl.java

-          path, triggerInterpreter, e);
+      LOG.warn("While reading the input {} with the inputreader {}, an exception occured: {} Trying next input reader...",
+              path, triggerInterpreter, e.getMessage());
+      if (LOG.isDebugEnabled()) e.printStackTrace();


Don't print stacktraces on your own, pass the e on case of debug as last log parameter

maybeec · 2022-11-18T16:09:57Z

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/utils/ValidationUtils.java

+    for (int i = 0; i < report.getErrors().size(); i++) {
+      RuntimeException e = report.getErrors().get(i);
+      LOG.error("Error: {}", e.getMessage());
+      if (LOG.isDebugEnabled()) e.printStackTrace();


Don't print stacktraces on your own, pass e on debug as last parameter on log function

Addressed in next commit.

maybeec · 2022-11-18T16:10:25Z

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/utils/ValidationUtils.java

+    // Log exceptions for devs in DEBUG
+    for (int i = 0; i < report.getErrors().size(); i++) {
+      RuntimeException e = report.getErrors().get(i);
+      LOG.error("Error: {}", e.getMessage());


Don't print messages of exceptions. They will be in the stacktrace anyhow

The error message from the exception might contain useful hints for the user on how to fix it himself. My idea was to move the stacktrace of the exception into DEBUG but keep the exception message.

maybeec · 2022-11-18T16:11:17Z

...reemarker/src/main/java/com/devonfw/cobigen/tempeng/freemarker/FreeMarkerTemplateEngine.java

@@ -73,8 +73,14 @@ public void process(TextTemplate template, Map<String, Object> model, Writer out
        env.setLogTemplateExceptions(false); // no duplicate logging
        env.process();
      } catch (TemplateException e) {
+        String detailedCause = "";
+        if (e.getCause().getClass().getCanonicalName().contains("java.lang")) {


Just getting the first cause is maybe not what you want. Most probably you want to look at the root cause wouldn't you?

True! Next commit extracts the rootcause before building error message.

maybeec · 2022-11-18T16:11:54Z

...reemarker/src/main/java/com/devonfw/cobigen/tempeng/freemarker/FreeMarkerTemplateEngine.java

+        String detailedCause = "";
+        if (e.getCause().getClass().getCanonicalName().contains("java.lang")) {
+          detailedCause = ". A problem with Reflection has likely occurred: "
+                  + e.getCause().toString()


Never log an exception to string. That's most often resulting in garbage.

It seemed like a quick way to get both the canonical type of the exception and the message into one String. I rewrote the extraction manually.

- Removed the printStackTrace and instead split the debug statements into 2 depending on LOG.isDebugEnabled() - Fixed some whitespace issues - Fixed formatting - Extract root cause of exception in FreeMarkerTemplateEngine.java and build detailed message without directly using .toString() on the exception

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/CobiGenCLI.java

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/commands/GenerateCommand.java

- removed concatenation from added LOG statements

maybeec · 2022-12-06T11:40:07Z

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/CobiGenCLI.java

+          LOG.debug("Cobigen exited with exception: ", e);
+        } else {
+          LOG.error("An error occurred while executing CobiGen: {}", e.getMessage());
+        }


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.

maybeec · 2022-12-06T11:41:50Z

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/utils/ValidationUtils.java

      } else {
-        throw new CobiGenRuntimeException("Generation failed. Enable debug mode to see the exceptions occurred.",
-            report.getErrors().get(0));
+        LOG.error("Error: {}", e.getMessage());


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

maybeec · 2022-12-06T11:43:00Z

...reemarker/src/main/java/com/devonfw/cobigen/tempeng/freemarker/FreeMarkerTemplateEngine.java

+        Throwable rootCause = e;
+        while (rootCause.getCause() != null && rootCause.getCause() != rootCause) {
+          rootCause = rootCause.getCause();
+        }


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.

maybeec · 2022-12-06T11:44:47Z

cobigen/cobigen-core/src/main/java/com/devonfw/cobigen/impl/generator/InputInterpreterImpl.java

+        // 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());
+      }


again anti-pattern, see above

Lur1an added app:cli waiting:feedback labels Nov 15, 2022

github-actions bot added comp:core comp:tempeng:freemarker labels Nov 15, 2022

Lur1an requested a review from jan-vcapgemini November 15, 2022 07:54

Lur1an marked this pull request as ready for review November 16, 2022 07:36

Zylesto previously approved these changes Nov 16, 2022

View reviewed changes

Lur1an requested a review from EduardKrieger November 17, 2022 09:08

NelsonNew reviewed Nov 17, 2022

View reviewed changes

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/CobiGenCLI.java Outdated Show resolved Hide resolved

Fixed typo in CobiGenCLI

b83dcf1

Lur1an dismissed Zylesto’s stale review via b83dcf1 November 17, 2022 09:52

jan-vcapgemini requested changes Nov 17, 2022

View reviewed changes

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/CobiGenCLI.java Outdated Show resolved Hide resolved

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/commands/GenerateCommand.java Outdated Show resolved Hide resolved

Created constant for verbose hint to address change request.

923748d

maybeec requested changes Nov 18, 2022

View reviewed changes

jan-vcapgemini requested changes Nov 28, 2022

View reviewed changes

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/CobiGenCLI.java Outdated Show resolved Hide resolved

cobigen-cli/cli/src/main/java/com/devonfw/cobigen/cli/commands/GenerateCommand.java Outdated Show resolved Hide resolved

jan-vcapgemini self-assigned this Dec 2, 2022

Lur1an removed the waiting:feedback label Dec 3, 2022

Addressed change requests:

cb09e05

- removed concatenation from added LOG statements

jan-vcapgemini approved these changes Dec 5, 2022

View reviewed changes

jan-vcapgemini requested a review from maybeec December 5, 2022 17:16

Merge branch 'master' into 1593-improvement-of-cli-error-logging

2176b0c

maybeec requested changes Dec 6, 2022

View reviewed changes

maybeec and others added 4 commits January 3, 2023 14:30

Merge branch 'master' into 1593-improvement-of-cli-error-logging

56f0228

Merge branch 'master' into 1593-improvement-of-cli-error-logging

b8583d7

Merge branch 'master' into 1593-improvement-of-cli-error-logging

8b8f333

Merge branch 'master' into 1593-improvement-of-cli-error-logging

b3d3076

Lur1an closed this by deleting the head repository Jan 31, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

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

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

Lur1an commented Nov 15, 2022

maybeec Nov 18, 2022

maybeec Nov 18, 2022

Lur1an Nov 21, 2022

maybeec Nov 18, 2022

Lur1an Nov 21, 2022

maybeec Nov 18, 2022

Lur1an Nov 21, 2022

maybeec Nov 18, 2022

Lur1an Nov 21, 2022

maybeec Dec 6, 2022

maybeec Dec 6, 2022

maybeec Dec 6, 2022

maybeec Dec 6, 2022

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

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

Conversation

Lur1an commented Nov 15, 2022

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment