Letztens haben wir versucht einen Java agent auszuliefernden. Dieser wird dann in eine andere ‚beliebige‘ Java Applikation eingebaut.

Wie es so mit Java Applikationen ist, gibt es ja einen bunten Blumenstrauß an Logging Frameworks mit noch mehr Versionen. Unser Java Agent soll aber unabhängig von der Applikation loggen können und das am Besten mit eigener Konfiguration. Auch soll die instrumentalisierte Java Applikation nicht durch das Logging des Agents beeinflusst werden.

Das Erste, was mir dazu einfällt, um dieses Problem zu lösen ist das maven shading plugin. Damit bekomme ich ‚mein‘ logging Framework in den Agent UND kann verhindern, dass das logging der Java Applikation benutzt wird. 

 <plugin>
     <groupId>org.apache.maven.plugins</groupId>
     <artifactId>maven-shade-plugin</artifactId>
     <executions>
         <execution>
             <phase>package</phase>
             <goals>
                 <goal>shade</goal>
             </goals>
         </execution>
     </executions>
     <configuration>
         <finalName>agent-shaded</finalName>
         <shadedArtifactAttached>true</shadedArtifactAttached>
         <shadedClassifierName>shaded</shadedClassifierName>
         <createDependencyReducedPom>true</createDependencyReducedPom>
         <relocations>
             <relocation>
                 <pattern>org.slf4j</pattern>
                 <shadedPattern>my.package.org.slf4j</shadedPattern>
             </relocation>
             <relocation>
                 <pattern>ch.qos.logback</pattern>
                 <shadedPattern>my.package.ch.qos.logback</shadedPattern>
             </relocation>
         </relocations>
         <transformers>
             <transformer implementation="org.apache.maven.plugins.shade.resource.ManifestResourceTransformer">
                 <manifestEntries>
                     <Premain-Class>my.package.instrumentation.InstrumentationAgent</Premain-Class>
                     <Can-Redefine-Classes>true</Can-Redefine-Classes>
                     <Can-Retransform-Classes>true</Can-Retransform-Classes>
                 </manifestEntries>
             </transformer>
         </transformers>
     </configuration>
 </plugin>

Das mit der Relocation klappt schon ganz gut. Das Logback, dass im Agent ist, kann jetzt nicht mehr von der Java Applikation angesprochen werden, da es ja jetzt unter my.package.ch.qos.logback liegt und nicht mehr unter ch.qos.logback. Das Selbe gilt für slf4j.

Aber jetzt kommt die BÖSE Konfiguration:
Wenn die Java Anwendung mit den Agent gestartet wird und die Java Anwendung kein logback benutzt, dann ist alles ganz einfach. Mann benutzt die normale Logback Konfiguration und passt die Pfade auf das Relocation an:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <appender name="OPS_FILE" class="my.package.ch.qos.logback.core.rolling.RollingFileAppender">
        <file>agent.log</file>
        <rollingPolicy class="my.package.ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>agent.%d{yyyy-MM-dd}.%i.gz</fileNamePattern>
            <maxFileSize>20MB</maxFileSize>
            <maxHistory>30</maxHistory>
            <totalSizeCap>1GB</totalSizeCap>
        </rollingPolicy>
        <append>true</append>
        <immediateFlush>true</immediateFlush>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss,SSS} %-5level %thread [%c{15}] %msg%ex%n</pattern>
        </encoder>
    </appender>
    <root level="DEBUG">
        <appender-ref ref="OPS_FILE"/>
    </root>
</configuration>

Benutzt die Java Applikation aber jetzt selber logback, dann bekommt man mit der Konfigurationsauflösung von logback Probleme:
Benutzt die Anwendung z.B. eine logback.xml auf dem Classpath, dann bekommt das auch logback im Agent mit.
Da die Klassen durch das shading anders heißen fliegen beim Auflösen der Konfiguration im Agent Fehlermeldungen, die unschön sind.

Das Problem bzw. die Lösung liegt in der Auto Konfiguration in der Methode ch.qos.logback.classic.util.ContextInitializer. Man kann hier leider nicht eingreifen, da hier alles über Konvention automatisch läuft. Siehe auch http://logback.qos.ch/manual/configuration.html.

Jetzt könnte man sich die logback forken, die Klasse anpassen und sein eigenes logback benutzten. Aber wenn man schon Java Agent benutzt, kann man auch für dieses Problem anpassen.

import java.lang.instrument.ClassFileTransformer;
import java.lang.instrument.IllegalClassFormatException;
import java.security.ProtectionDomain;

import javassist.ClassPool;
import javassist.CtClass;
import javassist.CtMethod;

public class LoggingTransformer implements ClassFileTransformer {

    @Override
     public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined,
            ProtectionDomain protectionDomain, byte[] classfileBuffer) throws IllegalClassFormatException {
        byte[] byteCode = classfileBuffer;

        if (className.equals("my/package/ch/qos/logback/classic/util/ContextInitializer")) {
            try {
                ClassPool cp = ClassPool.getDefault();
                CtClass cc = cp.get("my.package.ch.qos.logback.classic.util.ContextInitializer");
                CtMethod m = cc.getDeclaredMethod("autoConfig");
                // If we return null here we skip the default configuration file resolution.
                // Thus we have the BasicConfigurator.
                m.setBody("{return null;}");
                byteCode = cc.toBytecode();
                cc.detach();
            } catch (Exception ex) {
                ex.printStackTrace();
            }
        }
        return byteCode;
    }
}

Somit hat man die komplette Autokonfiguration von logback zerstört und man kann seine eigene Konfiguration übergeben. z.B. über ein Konfigurationsfile:

        JoranConfigurator configurator = new JoranConfigurator();

        LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
        configurator.setContext(context);

        String pathToLogbackConfig = System.getProperty("agent.logback.configurationFile");
        if (pathToLogbackConfig == null) {
            System.out.println("There was no configuration for logging of the agent provided.");
            return;
        }

        try {
            File file = new File(pathToLogbackConfig);
            if (file.exists()) {
                context.reset();
                configurator.doConfigure(file);
            } else {
                System.err.println(
                        "There was no 'agent-logback.xml' logging-configuration provided. This means all logging of the agent is lost!");
            }
        } catch (JoranException e) {
            System.err.println("There was an error during building the agent logging configuration.");
            System.out.println(e);
        }

Jetzt kann man den Agent nach Belieben Konfigurieren und das logging der Java Applikation und des Agent ist komplett getrennt.