Skip to content

TS-40806 replace the artifical delayed logger with a delayed appender #614

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.

Sign up for GitHub

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

Open
flameJam wants to merge 10 commits into
base: master
Choose a base branch
from
Open

TS-40806 replace the artifical delayed logger with a delayed appender #614

Show file tree
Hide file tree
Changes from 7 commits
Commits
Show all changes
10 commits
Select commit Hold shift + click to select a range
3abf8b6
WIP
karottenreibe Oct 8, 2024
ebc6884
TS-40806 replace usages of delayedLogger with DelayedLogAppender
Dec 3, 2024
6ef19dc
TS-40806 clean-up
Dec 3, 2024
e8cdeea
TS-40806 clean-up
Dec 9, 2024
a53d202
TS-40806 adjust FilePatternResolver in Maven Plugin
Dec 9, 2024
9436f01
TS-40806 new todo
Dec 10, 2024
9aec90b
TS-40806 clean-up
Dec 16, 2024
b073c2e
TS-40806 Rework
Feb 13, 2025
80d3b22
TS-40806 add DelayedLogAppender to existing logging context.
Feb 22, 2025
d00f793
TS-40806 delete logback.xml
Feb 22, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
70 changes: 0 additions & 70 deletions agent/src/main/java/com/teamscale/jacoco/agent/DelayedLogger.java
View file
Open in desktop

This file was deleted.

85 changes: 38 additions & 47 deletions agent/src/main/java/com/teamscale/jacoco/agent/PreMain.java
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,7 +1,6 @@
package com.teamscale.jacoco.agent;

import com.teamscale.client.HttpUtils;
import com.teamscale.client.TeamscaleServer;
import com.teamscale.jacoco.agent.configuration.AgentOptionReceiveException;
import com.teamscale.jacoco.agent.logging.LogToTeamscaleAppender;
import com.teamscale.jacoco.agent.options.AgentOptionParseException;
Expand All @@ -13,7 +12,6 @@
import com.teamscale.jacoco.agent.options.TeamscalePropertiesUtils;
import com.teamscale.jacoco.agent.testimpact.TestwiseCoverageAgent;
import com.teamscale.jacoco.agent.upload.UploaderException;
import com.teamscale.jacoco.agent.upload.teamscale.TeamscaleConfig;
import com.teamscale.jacoco.agent.util.AgentUtils;
import com.teamscale.jacoco.agent.logging.DebugLogDirectoryPropertyDefiner;
import com.teamscale.jacoco.agent.logging.LogDirectoryPropertyDefiner;
Expand All @@ -39,6 +37,8 @@
/** Container class for the premain entry point for the agent. */
public class PreMain {

private static final Logger LOGGER = LoggingUtils.getLogger(PreMain.class);

private static LoggingUtils.LoggingResources loggingResources = null;

/**
Expand Down Expand Up @@ -82,7 +82,7 @@ public static void premain(String options, Instrumentation instrumentation) thro

Logger logger = LoggingUtils.getLogger(Agent.class);

logger.info("Teamscale Java profiler version " + AgentUtils.VERSION);
logger.info("Teamscale Java profiler version {}", AgentUtils.VERSION);
logger.info("Starting JaCoCo's agent");
JacocoAgentOptionsBuilder agentBuilder = new JacocoAgentOptionsBuilder(agentOptions);
JaCoCoPreMain.premain(agentBuilder.createJacocoAgentOptions(), instrumentation, logger);
Expand All @@ -98,61 +98,48 @@ public static void premain(String options, Instrumentation instrumentation) thro
private static AgentOptions getAndApplyAgentOptions(String options, String environmentConfigId,
String environmentConfigFile) throws AgentOptionParseException, IOException, AgentOptionReceiveException {

DelayedLogger delayedLogger = new DelayedLogger();
List<String> javaAgents = CollectionUtils.filter(ManagementFactory.getRuntimeMXBean().getInputArguments(),
s -> s.contains("-javaagent"));
if (javaAgents.size() > 1) {
delayedLogger.warn("Using multiple java agents could interfere with coverage recording.");
LOGGER.warn("Using multiple java agents could interfere with coverage recording.");
}
if (!javaAgents.get(0).contains("teamscale-jacoco-agent.jar")) {
delayedLogger.warn("For best results consider registering the Teamscale JaCoCo Agent first.");
LOGGER.warn("For best results consider registering the Teamscale JaCoCo Agent first.");
}

TeamscaleCredentials credentials = TeamscalePropertiesUtils.parseCredentials();
if (credentials == null) {
delayedLogger.warn("Did not find a teamscale.properties file!");
LOGGER.warn("Did not find a teamscale.properties file!");
Copy link
Copy Markdown
Contributor

@DreierF DreierF Dec 17, 2024

Choose a reason for hiding this comment

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

When I run the sample-app on master with logging-config=./tmp/teamscale-jacoco-agent/logging/logback.rolling-file.xml the console output is

Picked up JAVA_TOOL_OPTIONS: -javaagent:tmp/teamscale-jacoco-agent/lib/teamscale-jacoco-agent.jar=config-file=./log-test.properties

on this branch it is

Picked up JAVA_TOOL_OPTIONS: -javaagent:tmp/teamscale-jacoco-agent/lib/teamscale-jacoco-agent.jar=config-file=./log-test.properties
16:00:35.529 [main] WARN com.teamscale.jacoco.agent.PreMain -- Did not find a teamscale.properties file!
16:00:35.531 [main] DEBUG com.teamscale.jacoco.agent.options.AgentOptionsParser -- Parsing options: config-file=./log-test.properties

which I would not have expected as the log output is expected to be written to the file system. Not 100% sure though where those logs are written to the console though.

Copy link
Copy Markdown
Author

@flameJam flameJam Dec 18, 2024 •
edited
Loading

Choose a reason for hiding this comment

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

I think this was caused by the fact that the delayed appender wasn't actually used at all - I think for some reason a console logger was picked up somewhere instead? And I mistook its output for the output of the console appender that was supposed to be used after initializing the correct logger... At least in my current implementation it is not actually used when calling LOGGER.error(...) 🤔 I'm working on it

}
AgentOptions agentOptions;
try {
agentOptions = AgentOptionsParser.parse(options, environmentConfigId, environmentConfigFile, credentials, delayedLogger);
agentOptions = AgentOptionsParser.parse(options, environmentConfigId, environmentConfigFile, credentials);
} catch (AgentOptionParseException e) {
try (LoggingUtils.LoggingResources ignored = initializeFallbackLogging(options, delayedLogger)) {
delayedLogger.errorAndStdErr("Failed to parse agent options: " + e.getMessage(), e);
attemptLogAndThrow(delayedLogger);
try (LoggingUtils.LoggingResources ignored = initializeFallbackLogging(options)) {
String message = "Failed to parse agent options: " + e.getMessage();
logAndPrintError(e, message);
throw e;
}
} catch (AgentOptionReceiveException e) {
try (LoggingUtils.LoggingResources ignored = initializeFallbackLogging(options, delayedLogger)) {
delayedLogger.errorAndStdErr(
e.getMessage() + " The application should start up normally, but NO coverage will be collected!",
e);
attemptLogAndThrow(delayedLogger);
try (LoggingUtils.LoggingResources ignored = initializeFallbackLogging(options)) {
String message = e.getMessage() + " The application should start up normally, but NO coverage will be collected!";
logAndPrintError(e, message);
throw e;
}
}

initializeLogging(agentOptions, delayedLogger);
Logger logger = LoggingUtils.getLogger(Agent.class);
delayedLogger.logTo(logger);
initializeLogging(agentOptions);
HttpUtils.setShouldValidateSsl(agentOptions.shouldValidateSsl());
return agentOptions;
}

private static void attemptLogAndThrow(DelayedLogger delayedLogger) {
// We perform actual logging output after writing to console to
// ensure the console is reached even in case of logging issues
// (see TS-23151). We use the Agent class here (same as below)
Logger logger = LoggingUtils.getLogger(Agent.class);
delayedLogger.logTo(logger);
}

/** Initializes logging during {@link #premain(String, Instrumentation)} and also logs the log directory. */
private static void initializeLogging(AgentOptions agentOptions, DelayedLogger logger) throws IOException {
private static void initializeLogging(AgentOptions agentOptions) throws IOException {
if (agentOptions.isDebugLogging()) {
initializeDebugLogging(agentOptions, logger);
initializeDebugLogging(agentOptions);
} else {
loggingResources = LoggingUtils.initializeLogging(agentOptions.getLoggingConfig());
logger.info("Logging to " + new LogDirectoryPropertyDefiner().getPropertyValue());
LOGGER.info("Logging to " + new LogDirectoryPropertyDefiner().getPropertyValue());
}

if (agentOptions.getTeamscaleServerOptions().isConfiguredForServerConnection()) {
Expand Down Expand Up @@ -182,13 +169,13 @@ private static AgentBase createAgent(AgentOptions agentOptions,
* Initializes debug logging during {@link #premain(String, Instrumentation)} and also logs the log directory if
* given.
*/
private static void initializeDebugLogging(AgentOptions agentOptions, DelayedLogger logger) {
private static void initializeDebugLogging(AgentOptions agentOptions) {
loggingResources = LoggingUtils.initializeDebugLogging(agentOptions.getDebugLogDirectory());
Path logDirectory = Paths.get(new DebugLogDirectoryPropertyDefiner().getPropertyValue());
if (FileSystemUtils.isValidPath(logDirectory.toString()) && Files.isWritable(logDirectory)) {
logger.info("Logging to " + logDirectory);
LOGGER.info("Logging to " + logDirectory);
} else {
logger.warn("Could not create " + logDirectory + ". Logging to console only.");
LOGGER.warn("Could not create " + logDirectory + ". Logging to console only.");
}
}

Expand All @@ -197,31 +184,30 @@ private static void initializeDebugLogging(AgentOptions agentOptions, DelayedLog
* {@link #premain(String, Instrumentation)} (see TS-23151). This tries to extract the logging configuration and use
* this and falls back to the default logger.
*/
private static LoggingUtils.LoggingResources initializeFallbackLogging(String premainOptions,
DelayedLogger delayedLogger) {
private static LoggingUtils.LoggingResources initializeFallbackLogging(String premainOptions) {
if (premainOptions == null) {
return LoggingUtils.initializeDefaultLogging();
}
for (String optionPart : premainOptions.split(",")) {
if (optionPart.startsWith(AgentOptionsParser.LOGGING_CONFIG_OPTION + "=")) {
return createFallbackLoggerFromConfig(optionPart.split("=", 2)[1], delayedLogger);
return createFallbackLoggerFromConfig(optionPart.split("=", 2)[1]);
}

if (optionPart.startsWith(AgentOptionsParser.CONFIG_FILE_OPTION + "=")) {
String configFileValue = optionPart.split("=", 2)[1];
Optional<String> loggingConfigLine = Optional.empty();
try {
File configFile = new FilePatternResolver(delayedLogger).parsePath(
File configFile = new FilePatternResolver().parsePath(
AgentOptionsParser.CONFIG_FILE_OPTION, configFileValue).toFile();
loggingConfigLine = FileSystemUtils.readLinesUTF8(configFile).stream()
.filter(line -> line.startsWith(AgentOptionsParser.LOGGING_CONFIG_OPTION + "="))
.findFirst();
} catch (IOException | AgentOptionParseException e) {
delayedLogger.error("Failed to load configuration from " + configFileValue + ": " + e.getMessage(),
e);
String message = "Failed to load configuration from " + configFileValue + ": " + e.getMessage();
logAndPrintError(e, message);
}
if (loggingConfigLine.isPresent()) {
return createFallbackLoggerFromConfig(loggingConfigLine.get().split("=", 2)[1], delayedLogger);
return createFallbackLoggerFromConfig(loggingConfigLine.get().split("=", 2)[1]);
}
}
}
Expand All @@ -230,19 +216,24 @@ private static LoggingUtils.LoggingResources initializeFallbackLogging(String pr
}

/** Creates a fallback logger using the given config file. */
private static LoggingUtils.LoggingResources createFallbackLoggerFromConfig(String configLocation,
DelayedLogger delayedLogger) {
private static LoggingUtils.LoggingResources createFallbackLoggerFromConfig(String configLocation) {
try {
return LoggingUtils.initializeLogging(
new FilePatternResolver(delayedLogger).parsePath(AgentOptionsParser.LOGGING_CONFIG_OPTION,
new FilePatternResolver().parsePath(AgentOptionsParser.LOGGING_CONFIG_OPTION,
configLocation));
} catch (IOException | AgentOptionParseException e) {
String message = "Failed to load log configuration from location " + configLocation + ": " + e.getMessage();
delayedLogger.error(message, e);
// output the message to console as well, as this might
// otherwise not make it to the user
System.err.println(message);
logAndPrintError(e, message);
return LoggingUtils.initializeDefaultLogging();
}
}

/**
* Log the error and also print it to System Error, as the error might prevent the initialization of a real logger.
*/
private static void logAndPrintError(Exception e, String message) {
LOGGER.error(message,
e);
Comment thread
flameJam marked this conversation as resolved.
Outdated
System.err.println(message);
}
}
5 changes: 2 additions & 3 deletions agent/src/main/java/com/teamscale/jacoco/agent/configuration/ConfigurationViaTeamscale.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,6 @@
import com.teamscale.client.TeamscaleServiceGenerator;
import com.teamscale.jacoco.agent.options.AgentOptionParseException;
import com.teamscale.jacoco.agent.logging.LoggingUtils;
import com.teamscale.report.util.ILogger;
import okhttp3.HttpUrl;
import okhttp3.ResponseBody;
import retrofit2.Response;
Expand Down Expand Up @@ -51,13 +50,13 @@ public ConfigurationViaTeamscale(ITeamscaleService teamscaleClient, ProfilerRegi
* Tries to retrieve the profiler configuration from Teamscale. In case retrieval fails the method throws a
* {@link AgentOptionReceiveException}.
*/
public static ConfigurationViaTeamscale retrieve(ILogger logger, String configurationId, HttpUrl url,
public static ConfigurationViaTeamscale retrieve(String configurationId, HttpUrl url,
String userName,
String userAccessToken) throws AgentOptionReceiveException, AgentOptionParseException {
ITeamscaleService teamscaleClient = TeamscaleServiceGenerator
.createService(ITeamscaleService.class, url, userName, userAccessToken, LONG_TIMEOUT, LONG_TIMEOUT);
try {
ProcessInformation processInformation = new ProcessInformationRetriever(logger).getProcessInformation();
ProcessInformation processInformation = new ProcessInformationRetriever().getProcessInformation();
Response<ProfilerRegistration> response = teamscaleClient.registerProfiler(configurationId,
processInformation).execute();
if (!response.isSuccessful()) {
Expand Down
9 changes: 3 additions & 6 deletions ...t/src/main/java/com/teamscale/jacoco/agent/configuration/ProcessInformationRetriever.java
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,7 +1,8 @@
package com.teamscale.jacoco.agent.configuration;

import com.teamscale.client.ProcessInformation;
import com.teamscale.report.util.ILogger;
import com.teamscale.jacoco.agent.logging.LoggingUtils;
import org.slf4j.Logger;

import java.lang.management.ManagementFactory;
import java.lang.reflect.InvocationTargetException;
Expand All @@ -13,11 +14,7 @@
*/
public class ProcessInformationRetriever {

private final ILogger logger;

public ProcessInformationRetriever(ILogger logger) {
this.logger = logger;
}
private final Logger logger = LoggingUtils.getLogger(this);

/**
* Retrieves the process information, including the host name and process ID.
Expand Down
3 changes: 1 addition & 2 deletions agent/src/main/java/com/teamscale/jacoco/agent/convert/ConvertCommand.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,6 @@
import com.teamscale.jacoco.agent.options.ClasspathUtils;
import com.teamscale.jacoco.agent.options.FilePatternResolver;
import com.teamscale.report.EDuplicateClassFileBehavior;
import com.teamscale.report.util.CommandLineLogger;
import org.conqat.lib.commons.assertion.CCSMAssert;
import org.conqat.lib.commons.filesystem.FileSystemUtils;
import org.conqat.lib.commons.string.StringUtils;
Expand Down Expand Up @@ -95,7 +94,7 @@ public class ConvertCommand implements ICommand {
/** @see #classDirectoriesOrZips */
public List<File> getClassDirectoriesOrZips() throws AgentOptionParseException {
return ClasspathUtils
.resolveClasspathTextFiles("class-dir", new FilePatternResolver(new CommandLineLogger()),
.resolveClasspathTextFiles("class-dir", new FilePatternResolver(),
classDirectoriesOrZips);
}

Expand Down
39 changes: 39 additions & 0 deletions agent/src/main/java/com/teamscale/jacoco/agent/logging/DelayedLogAppender.java
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,39 @@
package com.teamscale.jacoco.agent.logging;

import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.AppenderBase;

import java.util.ArrayList;
import java.util.List;

/**
* An appender that collects log statements in its buffer until it's asked to empty it into a given
* {@link LoggerContext}. It can be used to log log-messages before an actual logging appender has been configured using
* the options passed to the agent.
* */
Copy link
Copy Markdown
Contributor

@DreierF DreierF Dec 17, 2024

Choose a reason for hiding this comment

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

We should also document here how logback picks up this appender. I guess this will feel a bit to magical without further logback knowledge.

public class DelayedLogAppender extends AppenderBase<ILoggingEvent> {

private static final List<ILoggingEvent> BUFFER = new ArrayList<>();

/** Appends the given {@link ILoggingEvent} to logger's buffer. */
@Override
protected void append(ILoggingEvent eventObject) {
synchronized (BUFFER) {
BUFFER.add(eventObject);
}
}

/**
* logs the log-messages currently stored in the buffer into the given {@link LoggerContext} and empties the
* buffer.
* */
public static void logTo(LoggerContext context) {
synchronized (BUFFER) {
for (ILoggingEvent event : BUFFER) {
context.getLogger(event.getLoggerName()).callAppenders(event);
}
BUFFER.clear();
}
}
}
Loading