#608: enhance error messages (#653)

CHANGELOG.adoc

@@ -6,6 +6,7 @@ This file documents all notable changes to https://github.com/devonfw/IDEasy[IDE
 
 Release with new features and bugfixes:
 
+* https://github.com/devonfw/IDEasy/issues/608[#608]: Enhanced error messages. Now logs missing command output and error messages
 
 The full list of changes for this release can be found in https://github.com/devonfw/IDEasy/milestone/15?closed=1[milestone 2024.11.001].
 

cli/src/main/java/com/devonfw/tools/ide/process/ProcessContextImpl.java

@@ -19,7 +19,7 @@
 import com.devonfw.tools.ide.common.SystemPath;
 import com.devonfw.tools.ide.context.IdeContext;
 import com.devonfw.tools.ide.environment.VariableLine;
-import com.devonfw.tools.ide.log.IdeSubLogger;
+import com.devonfw.tools.ide.log.IdeLogLevel;
 import com.devonfw.tools.ide.os.SystemInfoImpl;
 import com.devonfw.tools.ide.os.WindowsPathSyntax;
 import com.devonfw.tools.ide.util.FilenameUtil;
@@ -180,14 +180,16 @@ public ProcessResult run(ProcessMode processMode) {
       }
 
       int exitCode;
+
       if (processMode.isBackground()) {
         exitCode = ProcessResult.SUCCESS;
       } else {
         exitCode = process.waitFor();
       }
 
       ProcessResult result = new ProcessResultImpl(exitCode, out, err);
-      performLogOnError(result, exitCode, interpreter);
+
+      performLogging(result, exitCode, interpreter);
 
       return result;
 
@@ -310,25 +312,29 @@ private String addExecutable(String exec, List<String> args) {
     return interpreter;
   }
 
-  private void performLogOnError(ProcessResult result, int exitCode, String interpreter) {
+  private void performLogging(ProcessResult result, int exitCode, String interpreter) {
 
     if (!result.isSuccessful() && (this.errorHandling != ProcessErrorHandling.NONE)) {
-      String message = createCommandMessage(interpreter, " failed with exit code " + exitCode + "!");
-      if (this.errorHandling == ProcessErrorHandling.THROW_CLI) {
-        throw new CliProcessException(message, result);
-      } else if (this.errorHandling == ProcessErrorHandling.THROW_ERR) {
-        throw new IllegalStateException(message);
-      }
-      IdeSubLogger level;
+      IdeLogLevel ideLogLevel;
+      String message = createCommandMessage(interpreter, "\nfailed with exit code " + exitCode + "!");
+
       if (this.errorHandling == ProcessErrorHandling.LOG_ERROR) {
-        level = this.context.error();
+        ideLogLevel = IdeLogLevel.ERROR;
       } else if (this.errorHandling == ProcessErrorHandling.LOG_WARNING) {
-        level = this.context.warning();
+        ideLogLevel = IdeLogLevel.WARNING;
       } else {
-        level = this.context.error();
+        ideLogLevel = IdeLogLevel.ERROR;
         this.context.error("Internal error: Undefined error handling {}", this.errorHandling);
       }
-      level.log(message);
+
+      context.level(ideLogLevel).log(message);
+      result.log(ideLogLevel, context);
+
+      if (this.errorHandling == ProcessErrorHandling.THROW_CLI) {
+        throw new CliProcessException(message, result);
+      } else if (this.errorHandling == ProcessErrorHandling.THROW_ERR) {
+        throw new IllegalStateException(message);
+      }
     }
   }
 

cli/src/main/java/com/devonfw/tools/ide/process/ProcessResult.java

@@ -2,6 +2,9 @@
 
 import java.util.List;
 
+import com.devonfw.tools.ide.context.IdeContext;
+import com.devonfw.tools.ide.log.IdeLogLevel;
+
 /**
  * Result of a {@link Process} execution.
  *
@@ -58,4 +61,20 @@ default boolean isSuccessful() {
    */
   List<String> getErr();
 
+  /**
+   * Logs output and error messages on the provided log level.
+   *
+   * @param level the {@link IdeLogLevel} to use e.g. IdeLogLevel.ERROR.
+   * @param context the {@link IdeContext} to use.
+   */
+  void log(IdeLogLevel level, IdeContext context);
+
+  /**
+   * Logs output and error messages on the provided log level.
+   *
+   * @param outLevel the {@link IdeLogLevel} to use for {@link #getOut()}.
+   * @param context the {@link IdeContext} to use.
+   * @param errorLevel the {@link IdeLogLevel} to use for {@link #getErr()}.
+   */
+  void log(IdeLogLevel outLevel, IdeContext context, IdeLogLevel errorLevel);
 }

cli/src/main/java/com/devonfw/tools/ide/process/ProcessResultImpl.java

@@ -2,6 +2,10 @@
 
 import java.util.Collections;
 import java.util.List;
+import java.util.Objects;
+
+import com.devonfw.tools.ide.context.IdeContext;
+import com.devonfw.tools.ide.log.IdeLogLevel;
 
 /**
  * Implementation of {@link ProcessResult}.
@@ -25,16 +29,8 @@ public ProcessResultImpl(int exitCode, List<String> out, List<String> err) {
 
     super();
     this.exitCode = exitCode;
-    if (out == null) {
-      this.out = Collections.emptyList();
-    } else {
-      this.out = out;
-    }
-    if (err == null) {
-      this.err = Collections.emptyList();
-    } else {
-      this.err = err;
-    }
+    this.out = Objects.requireNonNullElse(out, Collections.emptyList());
+    this.err = Objects.requireNonNullElse(err, Collections.emptyList());
   }
 
   @Override
@@ -55,4 +51,29 @@ public List<String> getErr() {
     return this.err;
   }
 
+  @Override
+  public void log(IdeLogLevel level, IdeContext context) {
+    log(level, context, level);
+  }
+
+  public void log(IdeLogLevel outLevel, IdeContext context, IdeLogLevel errorLevel) {
+
+    if (!this.out.isEmpty()) {
+      doLog(outLevel, this.out, context);
+    }
+    if (!this.err.isEmpty()) {
+      doLog(errorLevel, this.err, context);
+    }
+  }
+
+  private void doLog(IdeLogLevel level, List<String> lines, IdeContext context) {
+    for (String line : lines) {
+      // remove !MESSAGE from log message
+      if (line.startsWith("!MESSAGE ")) {
+        line = line.substring(9);
+      }
+      context.level(level).log(line);
+    }
+  }
+
 }

cli/src/main/java/com/devonfw/tools/ide/tool/dotnet/DotNet.java

@@ -6,6 +6,10 @@
 import com.devonfw.tools.ide.context.IdeContext;
 import com.devonfw.tools.ide.tool.LocalToolCommandlet;
 
+/**
+ * {@link LocalToolCommandlet} for <a href="https://docs.microsoft.com/en-us/dotnet/core/tools/">dotnet</a>. The .NET CLI (Command Line Interface)
+ * cross-platform tool for building, running, and managing .NET applications.
+ */
 public class DotNet extends LocalToolCommandlet {
 
   /**

cli/src/main/java/com/devonfw/tools/ide/tool/eclipse/Eclipse.java

@@ -5,7 +5,6 @@
 import java.nio.channels.FileLock;
 import java.nio.file.Files;
 import java.nio.file.Path;
-import java.util.List;
 import java.util.Set;
 
 import com.devonfw.tools.ide.cli.CliException;
@@ -90,19 +89,9 @@ public void installPlugin(ToolPluginDescriptor plugin, Step step) {
         }
       }
     }
-    log(IdeLogLevel.DEBUG, result.getOut());
-    log(IdeLogLevel.ERROR, result.getErr());
-    step.error("Failed to install plugin {} ({}): exit code was {}", plugin.name(), plugin.id(), result.getExitCode());
-  }
-
-  private void log(IdeLogLevel level, List<String> lines) {
 
-    for (String line : lines) {
-      if (line.startsWith("!MESSAGE ")) {
-        line = line.substring(9);
-      }
-      this.context.level(level).log(line);
-    }
+    result.log(IdeLogLevel.DEBUG, context, IdeLogLevel.ERROR);
+    step.error("Failed to install plugin {} ({}): exit code was {}", plugin.name(), plugin.id(), result.getExitCode());
   }
 
   @Override

cli/src/test/java/com/devonfw/tools/ide/context/ProcessContextTestImpl.java

@@ -1,6 +1,6 @@
 package com.devonfw.tools.ide.context;
 
-import com.devonfw.tools.ide.cli.CliProcessException;
+import com.devonfw.tools.ide.log.IdeLogLevel;
 import com.devonfw.tools.ide.process.ProcessContextImpl;
 import com.devonfw.tools.ide.process.ProcessMode;
 import com.devonfw.tools.ide.process.ProcessResult;
@@ -22,24 +22,11 @@ public ProcessContextTestImpl(IdeContext context) {
 
   @Override
   public ProcessResult run(ProcessMode processMode) {
-
-    ProcessResult result;
-    try {
-      result = super.run(ProcessMode.DEFAULT_CAPTURE);
-      logOutput(result);
-      return result;
-    } catch (CliProcessException e) {
-      logOutput(e.getProcessResult());
-      throw e;
-    }
-  }
-
-  private void logOutput(ProcessResult result) {
-    for (String out : result.getOut()) {
-      this.context.info(out);
-    }
-    for (String err : result.getErr()) {
-      this.context.error(err);
+    ProcessResult result = super.run(ProcessMode.DEFAULT_CAPTURE);
+    // this hack is still required to capture test script output
+    if (result.isSuccessful() && (processMode == ProcessMode.DEFAULT || processMode == ProcessMode.BACKGROUND)) {
+      result.log(IdeLogLevel.INFO, context);
     }
+    return result;
   }
 }

cli/src/test/java/com/devonfw/tools/ide/process/ProcessContextImplTest.java

@@ -26,7 +26,7 @@
  */
 public class ProcessContextImplTest extends AbstractIdeContextTest {
 
-  private ProcessContextImpl processConttextUnderTest;
+  private ProcessContextImpl processContextUnderTest;
 
   private Process processMock;
 
@@ -39,20 +39,20 @@ public void setUp() throws Exception {
 
     this.mockProcessBuilder = mock(ProcessBuilder.class);
     this.context = newContext(PROJECT_BASIC, null, false);
-    this.processConttextUnderTest = new ProcessContextImpl(this.context);
+    this.processContextUnderTest = new ProcessContextImpl(this.context);
 
     Field field = ReflectionUtils.findFields(ProcessContextImpl.class, f -> f.getName().equals("processBuilder"),
         ReflectionUtils.HierarchyTraversalMode.TOP_DOWN).get(0);
 
     field.setAccessible(true);
-    field.set(this.processConttextUnderTest, this.mockProcessBuilder);
+    field.set(this.processContextUnderTest, this.mockProcessBuilder);
     field.setAccessible(false);
 
     // underTest needs executable
     Field underTestExecutable = ReflectionUtils.findFields(ProcessContextImpl.class,
         f -> f.getName().equals("executable"), ReflectionUtils.HierarchyTraversalMode.TOP_DOWN).get(0);
     underTestExecutable.setAccessible(true);
-    underTestExecutable.set(this.processConttextUnderTest,
+    underTestExecutable.set(this.processContextUnderTest,
         TEST_PROJECTS.resolve("_ide/software/nonExistingBinaryForTesting"));
     underTestExecutable.setAccessible(false);
 
@@ -77,12 +77,12 @@ public void missingExecutableShouldThrowIllegalState() throws Exception {
     Field underTestExecutable = ReflectionUtils.findFields(ProcessContextImpl.class,
         f -> f.getName().equals("executable"), ReflectionUtils.HierarchyTraversalMode.TOP_DOWN).get(0);
     underTestExecutable.setAccessible(true);
-    underTestExecutable.set(this.processConttextUnderTest, null);
+    underTestExecutable.set(this.processContextUnderTest, null);
     underTestExecutable.setAccessible(false);
 
     // act & assert
     Exception exception = assertThrows(IllegalStateException.class, () -> {
-      this.processConttextUnderTest.run(ProcessMode.DEFAULT);
+      this.processContextUnderTest.run(ProcessMode.DEFAULT);
     });
 
     String actualMessage = exception.getMessage();
@@ -98,7 +98,7 @@ public void onSuccessfulProcessStartReturnSuccessResult() throws Exception {
     when(this.processMock.waitFor()).thenReturn(ProcessResult.SUCCESS);
 
     // act
-    ProcessResult result = this.processConttextUnderTest.run(ProcessMode.DEFAULT);
+    ProcessResult result = this.processContextUnderTest.run(ProcessMode.DEFAULT);
 
     // assert
     verify(this.mockProcessBuilder).redirectOutput(
@@ -126,7 +126,7 @@ public void enablingCaptureShouldRedirectAndCaptureStreamsCorrectly() throws Exc
       when(this.processMock.getErrorStream()).thenReturn(errorStream);
 
       // act
-      ProcessResult result = this.processConttextUnderTest.run(ProcessMode.DEFAULT_CAPTURE);
+      ProcessResult result = this.processContextUnderTest.run(ProcessMode.DEFAULT_CAPTURE);
 
       // assert
       verify(this.mockProcessBuilder).redirectOutput(
@@ -149,7 +149,7 @@ public void enablingBackgroundProcessShouldNotBeAwaitedAndShouldNotPassStreams(P
     when(this.processMock.waitFor()).thenReturn(ProcessResult.SUCCESS);
 
     // act
-    ProcessResult result = this.processConttextUnderTest.run(processMode);
+    ProcessResult result = this.processContextUnderTest.run(processMode);
 
     // assert
     if (processMode == ProcessMode.BACKGROUND) {
@@ -179,11 +179,11 @@ public void unsuccessfulProcessShouldThrowIllegalState() throws Exception {
     // arrange
     when(this.processMock.waitFor()).thenReturn(ProcessResult.TOOL_NOT_INSTALLED);
 
-    this.processConttextUnderTest.errorHandling(ProcessErrorHandling.THROW_ERR);
+    this.processContextUnderTest.errorHandling(ProcessErrorHandling.THROW_ERR);
 
     // act & assert
     assertThrows(IllegalStateException.class, () -> {
-      this.processConttextUnderTest.run(ProcessMode.DEFAULT);
+      this.processContextUnderTest.run(ProcessMode.DEFAULT_CAPTURE);
     });
 
   }
@@ -194,16 +194,33 @@ public void processWarningAndErrorShouldBeLogged(ProcessErrorHandling processErr
 
     // arrange
     when(this.processMock.waitFor()).thenReturn(ProcessResult.TOOL_NOT_INSTALLED);
-    this.processConttextUnderTest.errorHandling(processErrorHandling);
+    this.processContextUnderTest.errorHandling(processErrorHandling);
     String expectedMessage = "failed with exit code 4!";
     // act
-    this.processConttextUnderTest.run(ProcessMode.DEFAULT);
+    this.processContextUnderTest.run(ProcessMode.DEFAULT);
 
     // assert
     IdeLogLevel level = convertToIdeLogLevel(processErrorHandling);
     assertThat(this.context).log(level).hasMessageContaining(expectedMessage);
   }
 
+  @Test
+  public void enablingCaptureShouldRedirectAndCaptureStreamsWithErrorsCorrectly() {
+    // arrange
+    IdeTestContext context = newContext(PROJECT_BASIC, null, false);
+
+    // act
+    IllegalStateException thrown = assertThrows(IllegalStateException.class,
+        () -> context.newProcess().executable(TEST_RESOURCES.resolve("process-context").resolve("dotnet.sh")).run());
+
+    // assert
+    assertThat(thrown.getMessage()).contains("failed with exit code 2");
+    assertThat(context).log(IdeLogLevel.ERROR).hasMessageContaining("content to stdout");
+    assertThat(context).log(IdeLogLevel.ERROR).hasMessageContaining("more content to stdout");
+    assertThat(context).log(IdeLogLevel.ERROR).hasMessageContaining("error message to stderr");
+    assertThat(context).log(IdeLogLevel.ERROR).hasMessageContaining("another error message to stderr");
+  }
+
   private IdeLogLevel convertToIdeLogLevel(ProcessErrorHandling processErrorHandling) {
 
     return switch (processErrorHandling) {