Unable to register shutdown hook because JVM is shutting down

[lennartkoopmann]

On current master when Elasticsearch connection failed:

2016-02-10 14:02:27,456 WARN : org.graylog2.initializers.IndexerSetupService - Could not connect to Elasticsearch
2016-02-10 14:02:27,456 INFO : org.graylog2.initializers.IndexerSetupService - If you're using multicast, check that it is working in your network and that Elasticsearch is accessible. Also check that the cluster name setting is correct.
2016-02-10 14:02:27,457 INFO : org.graylog2.initializers.IndexerSetupService - See http://docs.graylog.org/en/2.0/pages/configuring_es.html for details.
2016-02-10 14:02:27,458 INFO : org.graylog2.shared.initializers.ServiceManagerListener - Services are healthy
2016-02-10 14:02:27,459 INFO : org.graylog2.shared.initializers.InputSetupService - Triggering launching persisted inputs, node transitioned from Uninitialized [LB:DEAD] to Running [LB:ALIVE]
2016-02-10 14:02:27,460 INFO : org.graylog2.bootstrap.ServerBootstrap - Services started, startup times in ms: {BufferSynchronizerService [RUNNING]=1, InputSetupService [RUNNING]=7, MetricsReporterService [RUNNING]=19, OutputSetupService [RUNNING]=27, KafkaJournal [RUNNING]=43, JournalReader [RUNNING]=70, PeriodicalsService [RUNNING]=105, WebInterfaceService [RUNNING]=3065, RestApiService [RUNNING]=7585, IndexerSetupService [RUNNING]=8187}

...then I get this when trying to kill the process:

^C2016-02-10 14:02:33,706 INFO : org.graylog2.commands.Server - SIGNAL received. Shutting down.
2016-02-10 14:02:37,778 RestApiService STOPPING ERROR Unable to register shutdown hook because JVM is shutting down. java.lang.IllegalStateException: Cannot add new shutdown hook as this is not started. Current state: STOPPED
    at org.apache.logging.log4j.core.util.DefaultShutdownCallbackRegistry.addShutdownCallback(DefaultShutdownCallbackRegistry.java:113)
    at org.apache.logging.log4j.core.impl.Log4jContextFactory.addShutdownCallback(Log4jContextFactory.java:273)
    at org.apache.logging.log4j.core.LoggerContext.setUpShutdownHook(LoggerContext.java:256)
    at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:216)
    at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:145)
    at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:41)
    at org.apache.logging.log4j.LogManager.getContext(LogManager.java:182)
    at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:103)
    at org.apache.logging.log4j.jul.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:34)
    at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:42)
    at org.apache.logging.log4j.jul.LogManager.getLogger(LogManager.java:89)
    at java.util.logging.LogManager.demandLogger(LogManager.java:551)
    at java.util.logging.Logger.demandLogger(Logger.java:455)
    at java.util.logging.Logger.getLogger(Logger.java:502)
    at org.glassfish.grizzly.Grizzly.logger(Grizzly.java:69)
    at org.glassfish.grizzly.Context.<clinit>(Context.java:58)
    at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:536)
    at org.glassfish.grizzly.nio.NIOConnection.preClose(NIOConnection.java:836)
    at org.glassfish.grizzly.nio.transport.TCPNIOConnection.preClose(TCPNIOConnection.java:97)
    at org.glassfish.grizzly.nio.transport.TCPNIOServerConnection.preClose(TCPNIOServerConnection.java:219)
    at org.glassfish.grizzly.nio.NIOConnection.terminate0(NIOConnection.java:560)
    at org.glassfish.grizzly.nio.transport.TCPNIOConnection.terminate0(TCPNIOConnection.java:291)
    at org.glassfish.grizzly.nio.transport.TCPNIOServerConnection.closeGracefully0(TCPNIOServerConnection.java:294)
    at org.glassfish.grizzly.nio.NIOConnection.close(NIOConnection.java:476)
    at org.glassfish.grizzly.nio.transport.TCPNIOTransport.unbind(TCPNIOTransport.java:284)
    at org.glassfish.grizzly.nio.transport.TCPNIOTransport.unbindAll(TCPNIOTransport.java:306)
    at org.glassfish.grizzly.nio.NIOTransport.shutdownNow(NIOTransport.java:591)
    at org.glassfish.grizzly.http.server.NetworkListener.shutdownNow(NetworkListener.java:805)
    at org.glassfish.grizzly.http.server.HttpServer.removeListener(HttpServer.java:228)
    at org.glassfish.grizzly.http.server.HttpServer.shutdownNow(HttpServer.java:436)
    at org.graylog2.shared.initializers.RestApiService.shutDown(RestApiService.java:106)
    at com.google.common.util.concurrent.AbstractIdleService$DelegateService$2.run(AbstractIdleService.java:74)
    at com.google.common.util.concurrent.Callables$3.run(Callables.java:100)
    at java.lang.Thread.run(Thread.java:745)

The process is killed after this and there is no graceful shutdown happening. (I suspect this is the hook that is not executed.)

[bernd]

This seems to be an issue with Log4j 2.

More details:

• https://stackoverflow.com/questions/25877102/how-to-properly-shutdown-log4j2/28835409#28835409
• https://github.com/DjDCH/Log4j-StaticShutdown