Logging in the plugin interferes with logging in ids.server

[fisherab]

Steve said:

| Because of the above constraints:
| 1. I have not found a good way to do logging so am no longer using it
| within plugins.

Rolf replies:

That is a drawback. Logging in the plugin is important. Any serious
development with non-trivial conditions in the plugin becomes rather
difficult without logging.

(Btw.: despite the "As before", using the same libraries in the plugin
and in IDS itself and in particular logging did work fine in
ids.server 1.7.0. I only tested this with Glassfish 4 though, so it
might be a Payara vs. Glassfish issue rather then a ids.server 1.8.0
vs. 1.7.0 issue.)

[RKrahl]

This is tricky, because I don't fully understand the underlying issues. It is related with the way GlassFish/Payara manages the classpath and some classes shadowing others. The symptom is that the plugin must embed all third party libraries it uses in its own jar and it cannot use any third party library that is also used in ids.server. As a result, the plugin cannot use logback and SLF4J.

With earlier ids.server versions, if you tried nevertheless, it was somewhat working, it just had strange effects, such as the plugin needing to bring its own logback.xml and the one from the plugin was shadowing ids.server's logback.xml even for ids.server's own logging. With the current version it has the effect that logging becomes completely unusable also for ids.server. Though I suspect that this change is more related with the transition from GlassFish to Payara rather then with ids.server versions.

[EmilJunker]

Logging in storage plugins is still possible. By making the following changes to the plugin, one can achieve the same behavior as in earlier versions (where the logging was working, and the plugin's own logback.xml was shadowing ids.server's logback.xml).

Step 1: Add these dependencies to the pom.xml of the plugin

<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.6.6</version>
</dependency>

<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.1.3</version>
</dependency>

Step 2: Setup the maven shade plugin to embed the logback and SLF4J libraries within the plugin's own jar by adding these 3 lines to the pom.xml of the plugin (without this, the plugin wouldn't install)

 <plugin>
     <groupId>org.apache.maven.plugins</groupId>
     <artifactId>maven-shade-plugin</artifactId>
     <version>2.4.1</version>
     <configuration>
         <artifactSet>
             <includes>
                 <include>org.icatproject:ids.plugin</include>
+                <include>org.slf4j:slf4j-api</include>
+                <include>ch.qos.logback:logback-classic</include>
+                <include>ch.qos.logback:logback-core</include>
             </includes>
         </artifactSet>
     </configuration>
     ...
 </plugin>

Step 3: In the plugin's source code, now use logging like this

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

private static final Logger logger = LoggerFactory.getLogger(ArchiveFileStorage.class);

logger.info("log message");

Step 4: In the plugin under /src/main/resources, create a file logback.xml which will be shadowing the one from ids.server (without this, logging would not work even for ids.server)

<configuration>

    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${HOME}/logs/ids.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${HOME}/logs/ids.log.%d{yyyy-MM-dd}.%i.zip
            </fileNamePattern>
            <maxHistory>30</maxHistory>
            <timeBasedFileNamingAndTriggeringPolicy
                class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>

        <encoder>
            <pattern>%date %level [%thread] %C{0} - %msg%n
            </pattern>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="FILE" />
    </root>

    <logger name="org.icatproject.ids.FileChecker" level="INFO" />

</configuration>

I have successfully tested this with both ids.storage_test and ids.storage_file.

[RKrahl]

That is good news, many thanks for checking! I'm not sure what I got wrong when I made my last year's comment.

The fact that the the plugin need to have it's own logback.xml embedded in the jar file and that this interferes with logging in ids.server is still a significant inconvenience. We should still try to fix that and therefore, I leave this issue open. But it became less urgent now, so I'll remove it from the 0.10.0 milestone.