Merge pull request #882 from cqse/ts/43260_profiler_crash_after_missconfig

TS-43260 Profiler crash fix in case of invalid config options

Author: DreierF

CHANGELOG.md

@@ -5,6 +5,7 @@ We use [semantic versioning](http://semver.org/):
 - PATCH version when you make backwards compatible bug fixes.
 
 # Next version
+- [fix] _agent_: The profiled application no longer crashes when the profiler configuration is invalid (e.g., missing `teamscale-user`). Instead, the application starts normally without coverage collection.
 
 # 36.5.0
 - [feature] _agent_: Renamed the docker image to `cqse/teamscale-java-profiler` and added support for the `linux/arm64` platform

agent/src/main/java/com/teamscale/jacoco/agent/PreMain.java

@@ -35,7 +35,17 @@
 
 import static com.teamscale.jacoco.agent.logging.LoggingUtils.getLoggerContext;
 
-/** Container class for the premain entry point for the agent. */
+/**
+ * Container class for the premain entry point for the agent.
+ * <p>
+ * <b>Design decision: the agent must never crash the profiled application.</b>
+ * Even when the agent is misconfigured, startup must not propagate any exception out of
+ * {@link #premain(String, Instrumentation)}. An exception escaping {@code premain} would be re-thrown by the JVM as
+ * {@code IllegalAgentException}, which aborts startup of the profiled application. The profiler is an observational
+ * tool, so a failure to start up the profiler must degrade to "no coverage is collected" rather than taking down the
+ * application. All failure paths in {@code premain} are therefore logged and swallowed; see the top-level
+ * {@code try}/{@code catch} in {@link #premain(String, Instrumentation)}.
+ */
 public class PreMain {
 
 	private static LoggingUtils.LoggingResources loggingResources = null;
@@ -60,8 +70,26 @@ public class PreMain {
 
 	/**
 	 * Entry point for the agent, called by the JVM.
+	 * <p>
+	 * This method never throws. Any exception raised during startup is logged (to the file log and, if configured,
+	 * to Teamscale) and swallowed, and the JVM continues without coverage collection. See the class-level Javadoc for
+	 * the rationale.
 	 */
-	public static void premain(String options, Instrumentation instrumentation) throws Exception {
+	public static void premain(String options, Instrumentation instrumentation) {
+		try {
+			startProfiler(options, instrumentation);
+		} catch (Throwable t) {
+			// Top-level safety net: an exception escaping premain would be re-thrown by the JVM as
+			// IllegalAgentException and abort the profiled application. See class-level Javadoc.
+			logStartupFailure(t);
+		}
+	}
+
+	/**
+	 * Starts the profiler. Contains all logic that may legitimately throw during startup; every caller must route
+	 * through {@link #premain(String, Instrumentation)} which catches these exceptions.
+	 */
+	private static void startProfiler(String options, Instrumentation instrumentation) throws Exception {
 		if (System.getProperty(LOCKING_SYSTEM_PROPERTY) != null) {
 			return;
 		}
@@ -81,14 +109,12 @@ public static void premain(String options, Instrumentation instrumentation) thro
 					environmentConfigFile);
 			agentOptions = parseResult.getFirst();
 
-			// After parsing everything and configuring logging, we now
-			// can throw the caught exceptions.
+			// After parsing everything and configuring logging, we now can throw the caught exceptions. They are
+			// handled locally below and never propagate out of premain (see class-level Javadoc).
 			for (Exception exception : parseResult.getSecond()) {
 				throw exception;
 			}
 		} catch (AgentOptionParseException e) {
-			getLoggerContext().getLogger(PreMain.class).error(e.getMessage(), e);
-
 			// Flush logs to Teamscale, if configured.
 			closeLoggingResources();
 
@@ -97,7 +123,9 @@ public static void premain(String options, Instrumentation instrumentation) thro
 				agentOptions.configurationViaTeamscale.unregisterProfiler();
 			}
 
-			throw e;
+			// Don't crash the profiled application due to a configuration error
+			// (see TS-43260). The error has already been logged in getAndApplyAgentOptions.
+			return;
 		} catch (AgentOptionReceiveException e) {
 			// When Teamscale is not available, we don't want to fail hard to still allow for testing even if no
 			// coverage is collected (see TS-33237)
@@ -118,6 +146,29 @@ public static void premain(String options, Instrumentation instrumentation) thro
 		agent.registerShutdownHook();
 	}
 
+	/**
+	 * Logs a startup failure on a best-effort basis. Must not throw: even logging failures are swallowed so that
+	 * {@link #premain(String, Instrumentation)} keeps its no-throw contract.
+	 */
+	private static void logStartupFailure(Throwable t) {
+		try {
+			LoggingUtils.getLogger(PreMain.class).error(
+					"Teamscale Java Profiler failed to start up. The profiled application will continue to run "
+							+ "without coverage collection.", t);
+		} catch (Throwable loggingFailure) {
+			// The logger may not be initialized yet or may itself be broken. Fall back to stderr so the failure is
+			// at least visible somewhere, then give up silently.
+			try {
+				System.err.println(
+						"[Teamscale Java Profiler] Failed to start up and will not collect coverage: " + t);
+				loggingFailure.addSuppressed(t);
+				loggingFailure.printStackTrace();
+			} catch (Throwable ignored) {
+				// Nothing we can do; the alternative is to crash the profiled application, which we must not do.
+			}
+		}
+	}
+
 	private static Pair<AgentOptions, List<Exception>> getAndApplyAgentOptions(String options,
 			String environmentConfigId,
 			String environmentConfigFile) throws AgentOptionParseException, IOException, AgentOptionReceiveException {
@@ -158,7 +209,9 @@ private static Pair<AgentOptions, List<Exception>> getAndApplyAgentOptions(Strin
 			agentOptions = parseResult.getFirst();
 		} catch (AgentOptionParseException e) {
 			try (LoggingUtils.LoggingResources ignored = initializeFallbackLogging(options, delayedLogger)) {
-				delayedLogger.errorAndStdErr("Failed to parse agent options: " + e.getMessage(), e);
+				delayedLogger.errorAndStdErr(
+						"Failed to parse agent options: " + e.getMessage() + " The application should start up normally, but NO coverage will be collected!",
+						e);
 				attemptLogAndThrow(delayedLogger);
 				throw e;
 			}
@@ -204,9 +257,14 @@ private static void initializeLogging(AgentOptions agentOptions, DelayedLogger l
 		}
 	}
 
-	/** Closes the opened logging contexts. */
+	/**
+	 * Closes the opened logging contexts. Safe to call before logging has been initialized, in which case this is a
+	 * no-op.
+	 */
 	static void closeLoggingResources() {
-		loggingResources.close();
+		if (loggingResources != null) {
+			loggingResources.close();
+		}
 	}
 
 	/**

agent/src/main/java/com/teamscale/jacoco/agent/options/AgentOptionsParser.java

@@ -410,8 +410,18 @@ private void readConfigFromTeamscale(
 			return;
 		}
 		if (!options.teamscaleServer.isConfiguredForServerConnection()) {
+			List<String> missingOptions = new ArrayList<>();
+			if (options.teamscaleServer.url == null) {
+				missingOptions.add("teamscale-server-url");
+			}
+			if (options.teamscaleServer.userName == null) {
+				missingOptions.add("teamscale-user");
+			}
+			if (options.teamscaleServer.userAccessToken == null) {
+				missingOptions.add("teamscale-access-token");
+			}
 			throw new AgentOptionParseException(
-					"Config-id '" + options.teamscaleServer.configId + "' specified without teamscale url/user/accessKey! These options must be provided locally via config-file or command line argument.");
+					"Config-id '" + options.teamscaleServer.configId + "' specified but the following required option(s) are missing: " + String.join(", ", missingOptions) + ". These options must be provided locally via config-file or command line argument.");
 		}
 		// Set ssl validation option in case it needs to be off before trying to reach Teamscale.
 		HttpUtils.setShouldValidateSsl(options.shouldValidateSsl());

agent/src/test/java/com/teamscale/jacoco/agent/PreMainTest.java

@@ -0,0 +1,108 @@
+package com.teamscale.jacoco.agent;
+
+import com.teamscale.jacoco.agent.logging.LoggingUtils;
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.io.TempDir;
+
+import java.io.IOException;
+import java.lang.instrument.Instrumentation;
+import java.nio.charset.StandardCharsets;
+import java.nio.file.Files;
+import java.nio.file.Path;
+
+import static org.assertj.core.api.Assertions.assertThat;
+import static org.assertj.core.api.Assertions.assertThatCode;
+
+/**
+ * Verifies the cross-cutting design invariant documented on {@link PreMain}: a failure to start up the profiler
+ * (misconfiguration, missing files, environment issues, ...) must never propagate an exception out of
+ * {@link PreMain#premain(String, Instrumentation)}, because the JVM would turn that into an
+ * {@code IllegalAgentException} and abort the profiled application.
+ */
+class PreMainTest {
+
+	/**
+	 * {@link PreMain#premain(String, Instrumentation)} sets a system property on its first invocation and early-returns
+	 * on every subsequent one. Clearing it before each test ensures every test actually exercises the startup path
+	 * instead of silently short-circuiting.
+	 */
+	@BeforeEach
+	void resetPremainLock() {
+		System.clearProperty("TEAMSCALE_JAVA_PROFILER_ATTACHED");
+	}
+
+	/**
+	 * Stops the logger context so file appenders configured during {@code premain} release their file handles. Without
+	 * this, Windows refuses to delete the {@code @TempDir} that holds {@code agent.log} and the test fails during
+	 * cleanup.
+	 */
+	@AfterEach
+	void releaseLogFileHandles() {
+		LoggingUtils.getLoggerContext().stop();
+	}
+
+	/**
+	 * Invalid agent options produce an {@code AgentOptionParseException} internally. The agent must swallow it so the
+	 * profiled application keeps running.
+	 */
+	@Test
+	void premainDoesNotThrowOnInvalidOptions() {
+		assertThatCode(() -> PreMain.premain("this=is=not=a=valid=option,bogus-key=value", null))
+				.doesNotThrowAnyException();
+	}
+
+	/**
+	 * Regression test for TS-43260: a {@code config-id} without the required Teamscale credentials used to propagate an
+	 * {@code AgentOptionParseException} out of {@code premain} and abort the profiled application. It must now be
+	 * swallowed.
+	 */
+	@Test
+	void premainDoesNotThrowOnConfigIdWithoutCredentials() {
+		assertThatCode(() -> PreMain.premain("config-id=some-config", null))
+				.doesNotThrowAnyException();
+	}
+
+	/**
+	 * Exercises the top-level {@code try}/{@code catch} in {@link PreMain#premain(String, Instrumentation)} that routes
+	 * into {@code logStartupFailure} — the safety net for failures that surface <em>after</em> options have been parsed
+	 * (and are therefore not covered by the {@code AgentOption*Exception} catches inside {@code startProfiler}).
+	 * <p>
+	 * The trick: valid options pass parsing, then a {@code null} {@link Instrumentation} forces JaCoCo's runtime setup
+	 * to dereference {@code null} (first at {@code AgentModule.openPackage(inst, …)} inside
+	 * {@code JaCoCoPreMain.createRuntime}). The resulting {@link NullPointerException} is a stand-in for real-world
+	 * post-parse failures — e.g. a Jetty {@code BindException} when {@code http-server-port} is taken, or an
+	 * {@code UploaderException} during uploader construction — which would bubble up the same way. In production the
+	 * JVM always supplies a non-null {@code Instrumentation}; passing {@code null} here is only a cheap way to stage
+	 * the failure without a running JVM agent attach.
+	 * <p>
+	 * A custom {@code logging-config} points logback at a file inside {@code tempDir} so we can read back the emitted
+	 * error event. A plain {@link ch.qos.logback.core.read.ListAppender} attached in the test would be detached again
+	 * by the {@code LoggerContext.reset()} that {@code LoggingUtils.reconfigureLoggerContext} performs during option
+	 * parsing.
+	 */
+	@Test
+	void premainLogsFailureWhenJaCoCoSetupThrows(@TempDir Path tempDir) throws IOException {
+		Path logFile = tempDir.resolve("agent.log");
+		Path logbackConfig = tempDir.resolve("logback.xml");
+		Files.write(logbackConfig, ("<configuration>\n"
+				+ "  <appender name=\"FILE\" class=\"ch.qos.logback.core.FileAppender\">\n"
+				+ "    <file>" + logFile.toAbsolutePath() + "</file>\n"
+				+ "    <encoder><pattern>%-5level %logger - %msg%n%ex</pattern></encoder>\n"
+				+ "  </appender>\n"
+				+ "  <root level=\"INFO\"><appender-ref ref=\"FILE\"/></root>\n"
+				+ "</configuration>\n").getBytes(StandardCharsets.UTF_8));
+
+		assertThatCode(() -> PreMain.premain(
+				"logging-config=" + logbackConfig.toAbsolutePath() + ",includes=com.example.*", null))
+				.doesNotThrowAnyException();
+
+		assertThat(logFile).exists();
+		String log = new String(Files.readAllBytes(logFile), StandardCharsets.UTF_8);
+		assertThat(log)
+				.contains("ERROR")
+				.contains("failed to start up")
+				.contains("NullPointerException");
+	}
+}

agent/src/test/java/com/teamscale/jacoco/agent/options/AgentOptionsTest.java

@@ -489,6 +489,27 @@ private static AgentOptionsParser getAgentOptionsParserWithDummyLoggerAndCredent
 		return new AgentOptionsParser(new CommandLineLogger(), null, null, credentials, null);
 	}
 
+	/** Tests that config-id without teamscale-user reports the missing option by name. */
+	@Test
+	public void configIdWithMissingUserReportsMissingOption() {
+		assertThatThrownBy(
+				() -> parseAndMaybeThrow(
+						"config-id=test,teamscale-server-url=http://localhost:8080,teamscale-access-token=keyfoo"))
+				.isInstanceOf(AgentOptionParseException.class)
+				.hasMessageContaining("teamscale-user");
+	}
+
+	/** Tests that config-id with all required options missing reports all of them. */
+	@Test
+	public void configIdWithAllMissingOptionsReportsAll() {
+		assertThatThrownBy(
+				() -> parseAndMaybeThrow("config-id=test"))
+				.isInstanceOf(AgentOptionParseException.class)
+				.hasMessageContaining("teamscale-server-url")
+				.hasMessageContaining("teamscale-user")
+				.hasMessageContaining("teamscale-access-token");
+	}
+
 	/**
 	 * Delete created coverage folders
 	 */