Unable to log in the 'stop' method of GlobalExtension

[rtretyak]

Hi. Please consider this extension:

import groovy.util.logging.Slf4j
import org.spockframework.runtime.extension.AbstractGlobalExtension

@Slf4j
class LogExtension extends AbstractGlobalExtension {

    @Override
    void start() {
        log.info "I'm always logged"
    }

    @Override
    void stop() {
        log.info "I'm logged sometimes"
        sleep(1000)
        log.info "I'm never logged"
    }
}

Problem: The logging inside the 'stop' method is kind of broken. There seems to be some race condition, since the first log message in 'stop' will sometimes get logged (once in about 3 runs on my local machine), but any subsequent logs will never get logged. In debug inside 'stop', the 'log' instance reads PrivateConfig [loggerConfig=root, config=org.apache.logging.log4j.core.config.NullConfiguration@186eca4d, loggerConfigLevel=OFF, intLevel=0, logger=org.openkilda.functionaltests.extension.LogExtension:OFF in ffaa6af], which is different from what I get in the start or visitSpec methods (it reads a valid config and non-OFF log level). Problem also reproduces if I create the logger directly, without using the @Slf4j transformation. I'm configuring logger via log4j2.xml config which is located under src/test/resources. All other logs across all my framework do work as expected. Can somebody please point me to the reason of such behavior? How can I fix this? I want to perform some logging at the end of the test run. Spock version is 1.2-groovy-2.5, Groovy 2.5.3, log4j-slf4j-impl 2.10.0

[leonard84]

The stop method is currently run as a JVM shutown hook, this means that other system that also register a shutdown hook may cleanup their resources in parallel to your code. My guess is that is what is happening here. What happens if you are using System.out.println? With Spock 2.0 we can use the new hooks provided by the JUnit Plattform to run before the JVM is shutting down, but JUnit 4 simply doesn't provide this extensibility.

[rtretyak]

I'm able to do println with no issues inside stop. We've gone with some other solution to achieve what was planned, so this is not a blocker (at least for me). Looking forward to 2.0