From 4d828a0e5c80b58a9267688efad1b13ec2777ab4 Mon Sep 17 00:00:00 2001 From: Tomas Langer Date: Mon, 23 Jan 2023 10:43:08 +0100 Subject: [PATCH] =?UTF-8?q?Shutdown=20hook=20alignment=20N=C3=ADma=20and?= =?UTF-8?q?=20MP.=20(#5913)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Keep logging system active until shutdown hook completes. --- .../cdi/HelidonContainerImpl.java | 120 +++++++++++++----- .../server/ServerCdiExtension.java | 1 + .../io/helidon/nima/webserver/LoomServer.java | 74 ++++++++++- .../webserver/src/main/java/module-info.java | 2 + 4 files changed, 162 insertions(+), 35 deletions(-) diff --git a/microprofile/cdi/src/main/java/io/helidon/microprofile/cdi/HelidonContainerImpl.java b/microprofile/cdi/src/main/java/io/helidon/microprofile/cdi/HelidonContainerImpl.java index 3f9d7f936bf..14d993db4ee 100644 --- a/microprofile/cdi/src/main/java/io/helidon/microprofile/cdi/HelidonContainerImpl.java +++ b/microprofile/cdi/src/main/java/io/helidon/microprofile/cdi/HelidonContainerImpl.java @@ -1,5 +1,5 @@ /* - * Copyright (c) 2019, 2022 Oracle and/or its affiliates. + * Copyright (c) 2019, 2023 Oracle and/or its affiliates. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -17,9 +17,11 @@ import java.lang.annotation.Annotation; import java.net.URL; +import java.util.ArrayList; import java.util.Collection; import java.util.HashMap; import java.util.HashSet; +import java.util.List; import java.util.Map; import java.util.ServiceLoader; import java.util.UUID; @@ -92,6 +94,8 @@ final class HelidonContainerImpl extends Weld implements HelidonContainer { private static final String EXIT_ON_STARTED_KEY = "exit.on.started"; private static final boolean EXIT_ON_STARTED = "!".equals(System.getProperty(EXIT_ON_STARTED_KEY)); private static final Context ROOT_CONTEXT; + // whether the current shutdown was invoked by the shutdown hook + private static final AtomicBoolean FROM_SHUTDOWN_HOOK = new AtomicBoolean(); static { HelidonFeatures.flavor(HelidonFlavor.MP); @@ -107,8 +111,10 @@ final class HelidonContainerImpl extends Weld implements HelidonContainer { CDI.setCDIProvider(new HelidonCdiProvider()); } + private static volatile Thread shutdownHook; private final WeldBootstrap bootstrap; private final String id; + private HelidonCdi cdi; HelidonContainerImpl() { @@ -303,39 +309,10 @@ private HelidonContainerImpl doStart() { // let's add a Handler // this is to workaround https://bugs.openjdk.java.net/browse/JDK-8161253 - Thread shutdownHook = new Thread(() -> { - cdi.close(); - }, "helidon-cdi-shutdown-hook"); - - Logger rootLogger = LogManager.getLogManager().getLogger(""); - Handler[] handlers = rootLogger.getHandlers(); - Handler[] newHandlers = new Handler[handlers.length + 1]; - newHandlers[0] = new Handler() { - @Override - public void publish(LogRecord record) { - // noop - } - - @Override - public void flush() { - // noop - } + shutdownHook = new Thread(new CdiShutdownHook(cdi), + "helidon-cdi-shutdown-hook"); - @Override - public void close() throws SecurityException { - try { - shutdownHook.join(); - } catch (InterruptedException ignored) { - } - } - }; - System.arraycopy(handlers, 0, newHandlers, 1, handlers.length); - for (Handler handler : handlers) { - rootLogger.removeHandler(handler); - } - for (Handler newHandler : newHandlers) { - rootLogger.addHandler(newHandler); - } + keepLoggingActive(shutdownHook); bm.getEvent().select(Initialized.Literal.APPLICATION).fire(new ContainerInitialized(id)); @@ -351,6 +328,35 @@ public void close() throws SecurityException { return this; } + private void keepLoggingActive(Thread shutdownHook) { + Logger rootLogger = LogManager.getLogManager().getLogger(""); + Handler[] handlers = rootLogger.getHandlers(); + + List newHandlers = new ArrayList<>(); + + boolean added = false; + for (Handler handler : handlers) { + if (handler instanceof KeepLoggingActiveHandler) { + // we want to replace it with our current shutdown hook + newHandlers.add(new KeepLoggingActiveHandler(shutdownHook)); + added = true; + } else { + newHandlers.add(handler); + } + } + if (!added) { + // out handler must be first, so other handlers are not closed before we finish shutdown hook + newHandlers.add(0, new KeepLoggingActiveHandler(shutdownHook)); + } + + for (Handler handler : handlers) { + rootLogger.removeHandler(handler); + } + for (Handler newHandler : newHandlers) { + rootLogger.addHandler(newHandler); + } + } + private void exitOnStarted() { LOGGER.info(String.format("Exiting, -D%s set.", EXIT_ON_STARTED_KEY)); System.exit(0); @@ -395,6 +401,13 @@ public void close() { IN_RUNTIME.set(false); // need to reset - if somebody decides to restart CDI (such as a test) ContainerInstanceHolder.reset(); + + if (!FROM_SHUTDOWN_HOOK.get()) { + Thread thread = shutdownHook; + if (thread != null) { + Runtime.getRuntime().removeShutdownHook(thread); + } + } } @Override @@ -443,4 +456,45 @@ private BeanDeploymentArchive getArchive(Deployment deployment) { return deployment.loadBeanDeploymentArchive(WeldContainer.class); } } + + private static final class CdiShutdownHook implements Runnable { + private final HelidonCdi cdi; + + private CdiShutdownHook(HelidonCdi cdi) { + this.cdi = cdi; + } + + @Override + public void run() { + LOGGER.info("Shutdown requested by JVM shutting down"); + FROM_SHUTDOWN_HOOK.set(true); + cdi.close(); + LOGGER.info("Shutdown finished"); + } + } + private static final class KeepLoggingActiveHandler extends Handler { + private final Thread shutdownHook; + + private KeepLoggingActiveHandler(Thread shutdownHook) { + this.shutdownHook = shutdownHook; + } + + @Override + public void publish(LogRecord record) { + // noop + } + + @Override + public void flush() { + // noop + } + + @Override + public void close() { + try { + shutdownHook.join(); + } catch (InterruptedException ignored) { + } + } + } } diff --git a/microprofile/server/src/main/java/io/helidon/microprofile/server/ServerCdiExtension.java b/microprofile/server/src/main/java/io/helidon/microprofile/server/ServerCdiExtension.java index b90ff2cfd33..99083f89956 100644 --- a/microprofile/server/src/main/java/io/helidon/microprofile/server/ServerCdiExtension.java +++ b/microprofile/server/src/main/java/io/helidon/microprofile/server/ServerCdiExtension.java @@ -80,6 +80,7 @@ public class ServerCdiExtension implements Extension { private final Map, RoutingConfiguration> serviceBeans = Collections.synchronizedMap(new IdentityHashMap<>()); // build time private WebServer.Builder serverBuilder = WebServer.builder() + .shutdownHook(false) // we use a custom CDI shutdown hook in HelidonContainerImpl .port(7001); private HttpRouting.Builder routingBuilder = HttpRouting.builder(); diff --git a/nima/webserver/webserver/src/main/java/io/helidon/nima/webserver/LoomServer.java b/nima/webserver/webserver/src/main/java/io/helidon/nima/webserver/LoomServer.java index 90bd05a7e5e..19d0d785bb3 100644 --- a/nima/webserver/webserver/src/main/java/io/helidon/nima/webserver/LoomServer.java +++ b/nima/webserver/webserver/src/main/java/io/helidon/nima/webserver/LoomServer.java @@ -17,6 +17,7 @@ package io.helidon.nima.webserver; import java.lang.management.ManagementFactory; +import java.util.ArrayList; import java.util.HashMap; import java.util.HashSet; import java.util.LinkedList; @@ -31,6 +32,10 @@ import java.util.concurrent.locks.Lock; import java.util.concurrent.locks.ReentrantLock; import java.util.function.Consumer; +import java.util.logging.Handler; +import java.util.logging.LogManager; +import java.util.logging.LogRecord; +import java.util.logging.Logger; import io.helidon.common.Version; import io.helidon.common.context.Context; @@ -172,7 +177,11 @@ public Context context() { } private void stopIt() { - parallel("stop", ServerListener::stop); + // We may be in a shutdown hook and new threads may not be created + for (ServerListener listener : listeners.values()) { + listener.stop(); + } + running.set(false); LOGGER.log(System.Logger.Level.INFO, "Níma server stopped all channels."); @@ -210,13 +219,19 @@ private void startIt() { private void registerShutdownHook() { this.shutdownHook = new Thread(() -> { + LOGGER.log(System.Logger.Level.INFO, "Shutdown requested by JVM shutting down"); listeners.values().forEach(ServerListener::stop); if (startFutures != null) { startFutures.forEach(future -> future.future().cancel(true)); } - }, "shutdown-hook"); + LOGGER.log(System.Logger.Level.INFO, "Shutdown finished"); + }, "nima-shutdown-hook"); Runtime.getRuntime().addShutdownHook(shutdownHook); + // we also need to keep the logging system active until the shutdown hook completes + // this introduces a hard dependency on JUL, as we cannot abstract this easily away + // this is to workaround https://bugs.openjdk.java.net/browse/JDK-8161253 + keepLoggingActive(shutdownHook); } private void deregisterShutdownHook() { @@ -255,6 +270,61 @@ private boolean parallel(String taskName, Consumer task) { return result; } + private void keepLoggingActive(Thread shutdownHook) { + Logger rootLogger = LogManager.getLogManager().getLogger(""); + Handler[] handlers = rootLogger.getHandlers(); + + List newHandlers = new ArrayList<>(); + + boolean added = false; + for (Handler handler : handlers) { + if (handler instanceof KeepLoggingActiveHandler) { + // we want to replace it with our current shutdown hook + newHandlers.add(new KeepLoggingActiveHandler(shutdownHook)); + added = true; + } else { + newHandlers.add(handler); + } + } + if (!added) { + // out handler must be first, so other handlers are not closed before we finish shutdown hook + newHandlers.add(0, new KeepLoggingActiveHandler(shutdownHook)); + } + + for (Handler handler : handlers) { + rootLogger.removeHandler(handler); + } + for (Handler newHandler : newHandlers) { + rootLogger.addHandler(newHandler); + } + } + private record ListenerFuture(ServerListener listener, Future future) { } + + private static final class KeepLoggingActiveHandler extends Handler { + private final Thread shutdownHook; + + private KeepLoggingActiveHandler(Thread shutdownHook) { + this.shutdownHook = shutdownHook; + } + + @Override + public void publish(LogRecord record) { + // noop + } + + @Override + public void flush() { + // noop + } + + @Override + public void close() { + try { + shutdownHook.join(); + } catch (InterruptedException ignored) { + } + } + } } diff --git a/nima/webserver/webserver/src/main/java/module-info.java b/nima/webserver/webserver/src/main/java/module-info.java index b6f6bcccfb3..ff67dd66ba8 100644 --- a/nima/webserver/webserver/src/main/java/module-info.java +++ b/nima/webserver/webserver/src/main/java/module-info.java @@ -41,6 +41,8 @@ requires io.helidon.pico.builder.config; requires java.management; + // only used to keep logging active until shutdown hook finishes + requires java.logging; requires jakarta.annotation; requires io.helidon.common.uri;