Skip to content
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

Cleanup after tests to avoid OOME: Metaspace in fast-run testOnly sequence #254

Open
wants to merge 2 commits into
base: develop
Choose a base branch
from
Open

Cleanup after tests to avoid OOME: Metaspace in fast-run testOnly sequence #254

Changes from 1 commit
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
dd7b74a
Cleanup after tests to avoid OOME: Metaspace in fast-run testOnly seq…
retronym Jul 13, 2018
50b57ef
Cleanup Log4J in the test classloader, not SBT's
retronym Jul 16, 2018
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
25 changes: 24 additions & 1 deletion build.sbt
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -30,7 +30,11 @@ def commonSettings: Seq[Setting[_]] = Def.settings(
inCompileAndTest(scalacOptions in console --= Vector("-Ywarn-unused-import", "-Ywarn-unused", "-Xlint")),
publishArtifact in Compile := true,
publishArtifact in Test := false,
parallelExecution in Test := false
parallelExecution in Test := false,
testOptions in Test += {
val log = streams.value.log
Tests.Cleanup { loader => cleanupTests(loader, log) }
}
)

val mimaSettings = Def settings (
Expand Down Expand Up @@ -275,3 +279,22 @@ inThisBuild(Seq(

def inCompileAndTest(ss: SettingsDefinition*): Seq[Setting[_]] =
Seq(Compile, Test) flatMap (inConfig(_)(Def.settings(ss: _*)))


// TODO move into sbt-house-rules?
def cleanupTests(loader: ClassLoader, log: sbt.internal.util.ManagedLogger): Unit = {
// shutdown Log4J to avoid classloader leaks
try {
val logManager = Class.forName("org.apache.logging.log4j.LogManager")
logManager.getMethod("shutdown").invoke(null)
Copy link
Member

Choose a reason for hiding this comment

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

Since I am using async logging, I am guessing calling shutdown right away would risk some logs not showing up. But I think it would make sense to remove loggers that are no longer needed at some point.

Copy link
Member Author

Choose a reason for hiding this comment

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

Log4J might block until these are written:

    /**
     * Shutdown using the LoggerContext appropriate for the caller of this method.
     * This is equivalent to calling {@code LogManager.shutdown(false)}.
     *
     * This call is synchronous and will block until shut down is complete.
     * This may include flushing pending log events over network connections.
     *
     * @since 2.6
     */
    public static void shutdown() {
        shutdown(false);
    }

I haven't tested this.

I don't think it matters much for tests in any case.

Copy link
Member

Choose a reason for hiding this comment

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

Another problem is that some appenders are long-living (relay appender used by server, backing appender, I think), so I can't stop them. If the loggers are leaking the loaders then I'd need to find out how to prevent that in general, I think.

Copy link
Member Author

@retronym retronym Jul 15, 2018 •
edited
Loading

Choose a reason for hiding this comment

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

To be clear, this is shutting down Log4J that is in the classloader of the tests themselves, not Log4J used in the SBT build that is calling the tests.

If the test were forked, you get away without explicitly shutting down because Log4J registers a shutdown hook to clean up. But that shutdown hook becomes a classloader leak in a "container" environment like a webapp or SBT.

Copy link
Member Author

Choose a reason for hiding this comment

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

https://logging.apache.org/log4j/2.x/manual/webapp.html

Because of the nature of class loaders within web applications, Log4j resources cannot be cleaned up through normal means. Log4j must be "started" when the web application deploys and "shut down" when the web application undeploys.

Copy link
Member

Choose a reason for hiding this comment

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

I see. Wouldn't val logManager = Class.forName("org.apache.logging.log4j.LogManager") load log4j in the context of the build tho?

Copy link
Member Author

Choose a reason for hiding this comment

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

Oh, you're right. I meant to use loader. I'll push a fix.

} catch {
case _: Throwable =>
log.warn("Could not shut down Log4J")
}
// Scala Test loads property bundles, let's eagerly clear then from the internal cache
// TODO move into SBT itself?
java.util.ResourceBundle.clearCache(loader)
// Scala Test also starts TimerThreads that it doesn't eagerly cancel. This can weakly retain
// metaspace until a full GC.
System.gc()
}