From 228d69bb36f08fd21c4f8580b93c29ff0cbe7c7d Mon Sep 17 00:00:00 2001 From: Niketh Sabbineni Date: Thu, 24 Aug 2017 16:39:21 -0700 Subject: [PATCH 01/14] Add graceful shutdown timeout --- docs/content/configuration/broker.md | 1 + docs/content/configuration/historical.md | 1 + .../druid/server/initialization/ServerConfig.java | 10 ++++++++++ .../initialization/jetty/JettyServerModule.java | 13 +++++++++++++ 4 files changed, 25 insertions(+) diff --git a/docs/content/configuration/broker.md b/docs/content/configuration/broker.md index 349d96442ffd..734267ededa7 100644 --- a/docs/content/configuration/broker.md +++ b/docs/content/configuration/broker.md @@ -39,6 +39,7 @@ Druid uses Jetty to serve HTTP requests. |`druid.server.http.maxIdleTime`|The Jetty max idle time for a connection.|PT5m| |`druid.server.http.defaultQueryTimeout`|Query timeout in millis, beyond which unfinished queries will be cancelled|300000| |`druid.server.http.maxScatterGatherBytes`|Maximum number of bytes gathered from data nodes such as historicals and realtime processes to execute a query. This is an advance configuration that allows to protect in case broker is under heavy load and not utilizing the data gathered in memory fast enough and leading to OOMs. This limit can be further reduced at query time using `maxScatterGatherBytes` in the context. Note that having large limit is not necessarily bad if broker is never under heavy concurrent load in which case data gathered is processed quickly and freeing up the memory used.|Long.MAX_VALUE| +|`druid.server.http.gracefulShutdownTimeout`|The maximum amount of time Jetty waits after receiving shutdown signal. After this timeout the threads will be forcefully shutdown. This allows any queries that are executing to complete.|PT5s| |`druid.broker.http.numConnections`|Size of connection pool for the Broker to connect to historical and real-time processes. If there are more queries than this number that all need to speak to the same node, then they will queue up.|20| |`druid.broker.http.compressionCodec`|Compression codec the Broker uses to communicate with historical and real-time processes. May be "gzip" or "identity".|gzip| |`druid.broker.http.readTimeout`|The timeout for data reads from historical and real-time processes.|PT15M| diff --git a/docs/content/configuration/historical.md b/docs/content/configuration/historical.md index 28319fd230f3..53250c6fbab8 100644 --- a/docs/content/configuration/historical.md +++ b/docs/content/configuration/historical.md @@ -50,6 +50,7 @@ Druid uses Jetty to serve HTTP requests. |`druid.server.http.numThreads`|Number of threads for HTTP requests.|max(10, (Number of cores * 17) / 16 + 2) + 30| |`druid.server.http.maxIdleTime`|The Jetty max idle time for a connection.|PT5m| |`druid.server.http.defaultQueryTimeout`|Query timeout in millis, beyond which unfinished queries will be cancelled|300000| +|`druid.server.http.gracefulShutdownTimeout`|The maximum amount of time Jetty waits after receiving shutdown signal. After this timeout the threads will be forcefully shutdown. This allows any queries that are executing to complete.|PT5s| #### Processing diff --git a/server/src/main/java/io/druid/server/initialization/ServerConfig.java b/server/src/main/java/io/druid/server/initialization/ServerConfig.java index 82e85318ee58..aeaa3a8fc56c 100644 --- a/server/src/main/java/io/druid/server/initialization/ServerConfig.java +++ b/server/src/main/java/io/druid/server/initialization/ServerConfig.java @@ -52,6 +52,10 @@ public class ServerConfig @JsonProperty private boolean tls = false; + @JsonProperty + @NotNull + private Period gracefulShutdownTimeout = new Period("PT5s"); + public int getNumThreads() { return numThreads; @@ -82,6 +86,11 @@ public boolean isTls() return tls; } + public Period getGracefulShutdownTimeout() + { + return gracefulShutdownTimeout; + } + @Override public boolean equals(Object o) { @@ -116,6 +125,7 @@ public String toString() ", maxScatterGatherBytes=" + maxScatterGatherBytes + ", plaintext=" + plaintext + ", tls=" + tls + + ", gracefulStopTimeout=" + gracefulShutdownTimeout + '}'; } } diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index 424eb21d322b..fec725819d5d 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -85,6 +85,7 @@ public class JettyServerModule extends JerseyServletModule private static final Logger log = new Logger(JettyServerModule.class); private static final AtomicInteger activeConnections = new AtomicInteger(); + private static final String GRACEFUL_SHUTDOWN_TIME = "graceful_shutdown_time"; @Override protected void configureServlets() @@ -227,6 +228,7 @@ static Server makeJettyServer(DruidNode node, ServerConfig config, TLSServerConf } server.setConnectors(connectors); + server.setAttribute(GRACEFUL_SHUTDOWN_TIME, config.getGracefulShutdownTimeout().getMillis()); return server; } @@ -253,6 +255,17 @@ public void start() throws Exception @Override public void stop() { + if (activeConnections.get() != 0) { + long graceFullShutDownTime = (int)server.getAttribute(GRACEFUL_SHUTDOWN_TIME); + log.info("Waiting for [%s] milliseconds for active requests to be zero, current active requests=[%s]", + graceFullShutDownTime, activeConnections.get()); + try { + Thread.sleep(graceFullShutDownTime); + } catch (InterruptedException e) { + log.error("Sleep has been interrupted, while waiting for active requests to be zero"); + } + } + log.info("Stopping Jetty Server with active requests=[%s]", activeConnections.get()); try { server.stop(); } From e9d329a60c47f776007f89c130162e3236d19d2b Mon Sep 17 00:00:00 2001 From: Niketh Sabbineni Date: Thu, 24 Aug 2017 16:59:30 -0700 Subject: [PATCH 02/14] Handle interruptedException --- .../server/initialization/jetty/JettyServerModule.java | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index fec725819d5d..71bac826a5e0 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -256,13 +256,15 @@ public void start() throws Exception public void stop() { if (activeConnections.get() != 0) { - long graceFullShutDownTime = (int)server.getAttribute(GRACEFUL_SHUTDOWN_TIME); + long graceFullShutDownTime = (int) server.getAttribute(GRACEFUL_SHUTDOWN_TIME); log.info("Waiting for [%s] milliseconds for active requests to be zero, current active requests=[%s]", graceFullShutDownTime, activeConnections.get()); try { Thread.sleep(graceFullShutDownTime); - } catch (InterruptedException e) { + } + catch (InterruptedException e) { log.error("Sleep has been interrupted, while waiting for active requests to be zero"); + Thread.currentThread().interrupt(); } } log.info("Stopping Jetty Server with active requests=[%s]", activeConnections.get()); From 4f09b3fb76a1ab7f70358fd2c7756cf876fcb5c8 Mon Sep 17 00:00:00 2001 From: Niketh Sabbineni Date: Mon, 28 Aug 2017 20:26:08 -0700 Subject: [PATCH 03/14] Incorporate code review comments --- .../initialization/jetty/JettyServerModule.java | 15 +++++++++++---- 1 file changed, 11 insertions(+), 4 deletions(-) diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index 71bac826a5e0..e3ed94376573 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -228,7 +228,7 @@ static Server makeJettyServer(DruidNode node, ServerConfig config, TLSServerConf } server.setConnectors(connectors); - server.setAttribute(GRACEFUL_SHUTDOWN_TIME, config.getGracefulShutdownTimeout().getMillis()); + server.setAttribute(GRACEFUL_SHUTDOWN_TIME, config.getGracefulShutdownTimeout().toStandardDuration().getMillis()); return server; } @@ -256,17 +256,24 @@ public void start() throws Exception public void stop() { if (activeConnections.get() != 0) { - long graceFullShutDownTime = (int) server.getAttribute(GRACEFUL_SHUTDOWN_TIME); + long graceFulShutDownTime = (long) server.getAttribute(GRACEFUL_SHUTDOWN_TIME); log.info("Waiting for [%s] milliseconds for active requests to be zero, current active requests=[%s]", - graceFullShutDownTime, activeConnections.get()); + graceFulShutDownTime, activeConnections.get()); try { - Thread.sleep(graceFullShutDownTime); + Thread.sleep(graceFulShutDownTime); } catch (InterruptedException e) { log.error("Sleep has been interrupted, while waiting for active requests to be zero"); + stopImmediately(); Thread.currentThread().interrupt(); + return; } } + stopImmediately(); + } + + private void stopImmediately() + { log.info("Stopping Jetty Server with active requests=[%s]", activeConnections.get()); try { server.stop(); From 42a7d314b2e0d2ded8ce6ebb5c48aff25dd52c4c Mon Sep 17 00:00:00 2001 From: Niketh Sabbineni Date: Tue, 29 Aug 2017 12:29:35 -0700 Subject: [PATCH 04/14] Address code review comments --- .../server/initialization/jetty/JettyServerModule.java | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index e3ed94376573..437c95e5cc8f 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -255,12 +255,12 @@ public void start() throws Exception @Override public void stop() { - if (activeConnections.get() != 0) { - long graceFulShutDownTime = (long) server.getAttribute(GRACEFUL_SHUTDOWN_TIME); + if (activeConnections.get() > 0) { + long gracefulShutDownTime = (long) server.getAttribute(GRACEFUL_SHUTDOWN_TIME); log.info("Waiting for [%s] milliseconds for active requests to be zero, current active requests=[%s]", - graceFulShutDownTime, activeConnections.get()); + gracefulShutDownTime, activeConnections.get()); try { - Thread.sleep(graceFulShutDownTime); + Thread.sleep(gracefulShutDownTime); } catch (InterruptedException e) { log.error("Sleep has been interrupted, while waiting for active requests to be zero"); From 127ed338ac47ed7408dea91d77fb9aad7f8616b6 Mon Sep 17 00:00:00 2001 From: Niketh Sabbineni Date: Tue, 5 Sep 2017 15:36:58 -0700 Subject: [PATCH 05/14] Poll for activeConnections to be zero --- .../server/initialization/ServerConfig.java | 2 +- .../initialization/jetty/JettyServerModule.java | 17 +++++++++++------ 2 files changed, 12 insertions(+), 7 deletions(-) diff --git a/server/src/main/java/io/druid/server/initialization/ServerConfig.java b/server/src/main/java/io/druid/server/initialization/ServerConfig.java index aeaa3a8fc56c..8ec704fff60d 100644 --- a/server/src/main/java/io/druid/server/initialization/ServerConfig.java +++ b/server/src/main/java/io/druid/server/initialization/ServerConfig.java @@ -54,7 +54,7 @@ public class ServerConfig @JsonProperty @NotNull - private Period gracefulShutdownTimeout = new Period("PT5s"); + private Period gracefulShutdownTimeout = new Period("PT15s"); public int getNumThreads() { diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index 437c95e5cc8f..99a6257fefda 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -85,7 +85,7 @@ public class JettyServerModule extends JerseyServletModule private static final Logger log = new Logger(JettyServerModule.class); private static final AtomicInteger activeConnections = new AtomicInteger(); - private static final String GRACEFUL_SHUTDOWN_TIME = "graceful_shutdown_time"; + private static final String GRACEFUL_SHUTDOWN_TIMEOUT = "graceful_shutdown_timeout"; @Override protected void configureServlets() @@ -228,7 +228,7 @@ static Server makeJettyServer(DruidNode node, ServerConfig config, TLSServerConf } server.setConnectors(connectors); - server.setAttribute(GRACEFUL_SHUTDOWN_TIME, config.getGracefulShutdownTimeout().toStandardDuration().getMillis()); + server.setAttribute(GRACEFUL_SHUTDOWN_TIMEOUT, config.getGracefulShutdownTimeout().toStandardDuration().getMillis()); return server; } @@ -255,12 +255,16 @@ public void start() throws Exception @Override public void stop() { - if (activeConnections.get() > 0) { - long gracefulShutDownTime = (long) server.getAttribute(GRACEFUL_SHUTDOWN_TIME); + long startTime = System.currentTimeMillis(); + long gracefulShutDownTimeout = (long) server.getAttribute(GRACEFUL_SHUTDOWN_TIMEOUT); + + while (activeConnections.get() > 0 && + System.currentTimeMillis() - startTime < gracefulShutDownTimeout) { log.info("Waiting for [%s] milliseconds for active requests to be zero, current active requests=[%s]", - gracefulShutDownTime, activeConnections.get()); + gracefulShutDownTimeout, activeConnections.get()); + try { - Thread.sleep(gracefulShutDownTime); + Thread.sleep(500); } catch (InterruptedException e) { log.error("Sleep has been interrupted, while waiting for active requests to be zero"); @@ -269,6 +273,7 @@ public void stop() return; } } + stopImmediately(); } From 0d07ba55862462e2980597fb7306af7cb5bd6670 Mon Sep 17 00:00:00 2001 From: Niketh Sabbineni Date: Wed, 13 Sep 2017 11:04:46 -0700 Subject: [PATCH 06/14] Use statistics handler to get active requests --- docs/content/configuration/broker.md | 2 +- docs/content/configuration/historical.md | 2 +- .../jetty/JettyServerModule.java | 47 +++++++++++++------ .../cli/QueryJettyServerInitializer.java | 20 +++++--- 4 files changed, 49 insertions(+), 22 deletions(-) diff --git a/docs/content/configuration/broker.md b/docs/content/configuration/broker.md index 734267ededa7..2bc8a94022d0 100644 --- a/docs/content/configuration/broker.md +++ b/docs/content/configuration/broker.md @@ -39,7 +39,7 @@ Druid uses Jetty to serve HTTP requests. |`druid.server.http.maxIdleTime`|The Jetty max idle time for a connection.|PT5m| |`druid.server.http.defaultQueryTimeout`|Query timeout in millis, beyond which unfinished queries will be cancelled|300000| |`druid.server.http.maxScatterGatherBytes`|Maximum number of bytes gathered from data nodes such as historicals and realtime processes to execute a query. This is an advance configuration that allows to protect in case broker is under heavy load and not utilizing the data gathered in memory fast enough and leading to OOMs. This limit can be further reduced at query time using `maxScatterGatherBytes` in the context. Note that having large limit is not necessarily bad if broker is never under heavy concurrent load in which case data gathered is processed quickly and freeing up the memory used.|Long.MAX_VALUE| -|`druid.server.http.gracefulShutdownTimeout`|The maximum amount of time Jetty waits after receiving shutdown signal. After this timeout the threads will be forcefully shutdown. This allows any queries that are executing to complete.|PT5s| +|`druid.server.http.gracefulShutdownTimeout`|The maximum amount of time Jetty waits after receiving shutdown signal. After this timeout the threads will be forcefully shutdown. This allows any queries that are executing to complete.|PT15s| |`druid.broker.http.numConnections`|Size of connection pool for the Broker to connect to historical and real-time processes. If there are more queries than this number that all need to speak to the same node, then they will queue up.|20| |`druid.broker.http.compressionCodec`|Compression codec the Broker uses to communicate with historical and real-time processes. May be "gzip" or "identity".|gzip| |`druid.broker.http.readTimeout`|The timeout for data reads from historical and real-time processes.|PT15M| diff --git a/docs/content/configuration/historical.md b/docs/content/configuration/historical.md index 53250c6fbab8..b368bdad3512 100644 --- a/docs/content/configuration/historical.md +++ b/docs/content/configuration/historical.md @@ -50,7 +50,7 @@ Druid uses Jetty to serve HTTP requests. |`druid.server.http.numThreads`|Number of threads for HTTP requests.|max(10, (Number of cores * 17) / 16 + 2) + 30| |`druid.server.http.maxIdleTime`|The Jetty max idle time for a connection.|PT5m| |`druid.server.http.defaultQueryTimeout`|Query timeout in millis, beyond which unfinished queries will be cancelled|300000| -|`druid.server.http.gracefulShutdownTimeout`|The maximum amount of time Jetty waits after receiving shutdown signal. After this timeout the threads will be forcefully shutdown. This allows any queries that are executing to complete.|PT5s| +|`druid.server.http.gracefulShutdownTimeout`|The maximum amount of time Jetty waits after receiving shutdown signal. After this timeout the threads will be forcefully shutdown. This allows any queries that are executing to complete.|PT15s| #### Processing diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index 99a6257fefda..af826eab264e 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -67,6 +67,7 @@ import org.eclipse.jetty.server.Server; import org.eclipse.jetty.server.ServerConnector; import org.eclipse.jetty.server.SslConnectionFactory; +import org.eclipse.jetty.server.handler.StatisticsHandler; import org.eclipse.jetty.util.ssl.SslContextFactory; import org.eclipse.jetty.util.thread.QueuedThreadPool; import org.eclipse.jetty.util.thread.ScheduledExecutorScheduler; @@ -227,6 +228,7 @@ static Server makeJettyServer(DruidNode node, ServerConfig config, TLSServerConf connector.setConnectionFactories(monitoredConnFactories); } + server.setHandler(new StatisticsHandler()); server.setConnectors(connectors); server.setAttribute(GRACEFUL_SHUTDOWN_TIMEOUT, config.getGracefulShutdownTimeout().toStandardDuration().getMillis()); @@ -252,26 +254,44 @@ public void start() throws Exception server.start(); } + private Handler getStatisticsHandler() + { + for (Handler handler : server.getHandlers()) { + if (handler.getClass().equals(StatisticsHandler.class)) { + return handler; + } + } + + return null; + } + @Override public void stop() { - long startTime = System.currentTimeMillis(); - long gracefulShutDownTimeout = (long) server.getAttribute(GRACEFUL_SHUTDOWN_TIMEOUT); + StatisticsHandler statisticsHandler = (StatisticsHandler) getStatisticsHandler(); - while (activeConnections.get() > 0 && - System.currentTimeMillis() - startTime < gracefulShutDownTimeout) { - log.info("Waiting for [%s] milliseconds for active requests to be zero, current active requests=[%s]", - gracefulShutDownTimeout, activeConnections.get()); + if (statisticsHandler != null) { + long startTime = System.currentTimeMillis(); + long gracefulShutDownTimeout = (long) server.getAttribute(GRACEFUL_SHUTDOWN_TIMEOUT); - try { - Thread.sleep(500); + if (statisticsHandler.getRequestsActive() > 0) { + log.info("Waiting for upto [%s] milliseconds for active requests to be zero, current active requests=[%s]", + gracefulShutDownTimeout, statisticsHandler.getRequestsActive()); } - catch (InterruptedException e) { - log.error("Sleep has been interrupted, while waiting for active requests to be zero"); - stopImmediately(); - Thread.currentThread().interrupt(); - return; + + while (statisticsHandler.getRequestsActive() > 0 && + System.currentTimeMillis() - startTime < gracefulShutDownTimeout) { + try { + Thread.sleep(500); + } + catch (InterruptedException e) { + log.error("Sleep has been interrupted, while waiting for active requests to be zero"); + stopImmediately(); + Thread.currentThread().interrupt(); + return; + } } + log.info("Stopping Jetty Server with active requests=[%s]", statisticsHandler.getRequestsActive()); } stopImmediately(); @@ -279,7 +299,6 @@ public void stop() private void stopImmediately() { - log.info("Stopping Jetty Server with active requests=[%s]", activeConnections.get()); try { server.stop(); } diff --git a/services/src/main/java/io/druid/cli/QueryJettyServerInitializer.java b/services/src/main/java/io/druid/cli/QueryJettyServerInitializer.java index d3d3f8b9fd43..7feafe1d95cc 100644 --- a/services/src/main/java/io/druid/cli/QueryJettyServerInitializer.java +++ b/services/src/main/java/io/druid/cli/QueryJettyServerInitializer.java @@ -57,13 +57,21 @@ public void initialize(Server server, Injector injector) root.addFilter(GuiceFilter.class, "/*", null); final HandlerList handlerList = new HandlerList(); - final Handler[] handlers = new Handler[extensionHandlers.size() + 2]; - handlers[0] = JettyServerInitUtils.getJettyRequestLogHandler(); - handlers[handlers.length - 1] = JettyServerInitUtils.wrapWithDefaultGzipHandler(root); - for (int i = 0; i < extensionHandlers.size(); i++) { - handlers[i + 1] = extensionHandlers.get(i); + // Do not change the order of the handlers that have already been added + for (Handler handler : server.getHandlers()) { + handlerList.addHandler(handler); } - handlerList.setHandlers(handlers); + + handlerList.addHandler(JettyServerInitUtils.getJettyRequestLogHandler()); + + // Add all extension handlers + for (Handler handler : extensionHandlers) { + handlerList.addHandler(handler); + } + + // Add Gzip handler at the very end + handlerList.addHandler(JettyServerInitUtils.wrapWithDefaultGzipHandler(root)); + server.setHandler(handlerList); } } From cda069878bdb6e05f142a3692891b17bdd06d0b7 Mon Sep 17 00:00:00 2001 From: Charles Allen Date: Thu, 1 Mar 2018 10:29:42 -0800 Subject: [PATCH 07/14] Use native jetty shutdown gracefully --- .../jetty/JettyServerModule.java | 80 ++++++++----------- 1 file changed, 35 insertions(+), 45 deletions(-) diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index a323119ff70c..992e8e3e4650 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -70,6 +70,7 @@ import org.eclipse.jetty.server.ServerConnector; import org.eclipse.jetty.server.SslConnectionFactory; import org.eclipse.jetty.server.handler.StatisticsHandler; +import org.eclipse.jetty.util.component.LifeCycle; import org.eclipse.jetty.util.ssl.SslContextFactory; import org.eclipse.jetty.util.thread.QueuedThreadPool; import org.eclipse.jetty.util.thread.ScheduledExecutorScheduler; @@ -92,7 +93,6 @@ public class JettyServerModule extends JerseyServletModule private static final Logger log = new Logger(JettyServerModule.class); private static final AtomicInteger activeConnections = new AtomicInteger(); - private static final String GRACEFUL_SHUTDOWN_TIMEOUT = "graceful_shutdown_timeout"; @Override protected void configureServlets() @@ -298,7 +298,39 @@ static Server makeAndInitializeServer( server.setHandler(new StatisticsHandler()); server.setConnectors(connectors); - server.setAttribute(GRACEFUL_SHUTDOWN_TIMEOUT, config.getGracefulShutdownTimeout().toStandardDuration().getMillis()); + server.setStopTimeout(config.getGracefulShutdownTimeout().toStandardDuration().getMillis()); + server.addLifeCycleListener(new LifeCycle.Listener() + { + @Override + public void lifeCycleStarting(LifeCycle event) + { + log.debug("Jetty lifecycle starting [%s]", event.getClass()); + } + + @Override + public void lifeCycleStarted(LifeCycle event) + { + log.debug("Jetty lifeycle started [%s]", event.getClass()); + } + + @Override + public void lifeCycleFailure(LifeCycle event, Throwable cause) + { + log.warn(cause, "Jetty lifecycle event failed [%s]", event.getClass()); + } + + @Override + public void lifeCycleStopping(LifeCycle event) + { + log.debug("Jetty lifecycle stopping [%s]", event.getClass()); + } + + @Override + public void lifeCycleStopped(LifeCycle event) + { + log.debug("Jetty lifecycle stopped [%s]", event.getClass()); + } + }); // initialize server JettyServerInitializer initializer = injector.getInstance(JettyServerInitializer.class); @@ -340,53 +372,11 @@ public void start() throws Exception } } - private Handler getStatisticsHandler() - { - for (Handler handler : server.getHandlers()) { - if (handler.getClass().equals(StatisticsHandler.class)) { - return handler; - } - } - - return null; - } - @Override public void stop() { - StatisticsHandler statisticsHandler = (StatisticsHandler) getStatisticsHandler(); - - if (statisticsHandler != null) { - long startTime = System.currentTimeMillis(); - long gracefulShutDownTimeout = (long) server.getAttribute(GRACEFUL_SHUTDOWN_TIMEOUT); - - if (statisticsHandler.getRequestsActive() > 0) { - log.info("Waiting for upto [%s] milliseconds for active requests to be zero, current active requests=[%s]", - gracefulShutDownTimeout, statisticsHandler.getRequestsActive()); - } - - while (statisticsHandler.getRequestsActive() > 0 && - System.currentTimeMillis() - startTime < gracefulShutDownTimeout) { - try { - Thread.sleep(500); - } - catch (InterruptedException e) { - log.error("Sleep has been interrupted, while waiting for active requests to be zero"); - stopImmediately(); - Thread.currentThread().interrupt(); - return; - } - } - log.info("Stopping Jetty Server with active requests=[%s]", statisticsHandler.getRequestsActive()); - } - - stopImmediately(); - } - - private void stopImmediately() - { + log.info("Stopping jetty server..."); try { - log.info("Stopping Jetty Server..."); server.stop(); } catch (Exception e) { From 0048c0aa7183b8f8c13f1a76a323657e9200d1cd Mon Sep 17 00:00:00 2001 From: Charles Allen Date: Thu, 1 Mar 2018 10:33:17 -0800 Subject: [PATCH 08/14] Move log line back to where it was --- .../io/druid/server/initialization/jetty/JettyServerModule.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index 992e8e3e4650..70e9a2f2ea51 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -375,8 +375,8 @@ public void start() throws Exception @Override public void stop() { - log.info("Stopping jetty server..."); try { + log.info("Stopping jetty server..."); server.stop(); } catch (Exception e) { From e6951907d6ddb2e9c607f495710fd5797c8f1b90 Mon Sep 17 00:00:00 2001 From: Charles Allen Date: Fri, 2 Mar 2018 09:43:37 -0800 Subject: [PATCH 09/14] Add unannounce wait time --- docs/content/configuration/broker.md | 1 + docs/content/configuration/historical.md | 1 + .../server/initialization/ServerConfig.java | 16 ++++++++++++++-- .../initialization/jetty/JettyServerModule.java | 17 ++++++++++++++++- 4 files changed, 32 insertions(+), 3 deletions(-) diff --git a/docs/content/configuration/broker.md b/docs/content/configuration/broker.md index bde543ac1e50..2a20a4075c14 100644 --- a/docs/content/configuration/broker.md +++ b/docs/content/configuration/broker.md @@ -42,6 +42,7 @@ Druid uses Jetty to serve HTTP requests. |`druid.server.http.defaultQueryTimeout`|Query timeout in millis, beyond which unfinished queries will be cancelled|300000| |`druid.server.http.maxScatterGatherBytes`|Maximum number of bytes gathered from data nodes such as historicals and realtime processes to execute a query. This is an advance configuration that allows to protect in case broker is under heavy load and not utilizing the data gathered in memory fast enough and leading to OOMs. This limit can be further reduced at query time using `maxScatterGatherBytes` in the context. Note that having large limit is not necessarily bad if broker is never under heavy concurrent load in which case data gathered is processed quickly and freeing up the memory used.|Long.MAX_VALUE| |`druid.server.http.gracefulShutdownTimeout`|The maximum amount of time Jetty waits after receiving shutdown signal. After this timeout the threads will be forcefully shutdown. This allows any queries that are executing to complete.|PT15s| +|`druid.server.http.unannouncePropogationDelay`|How long to wait for zookeeper unannouncements to propgate before shutting down Jetty. This is a minimum and `druid.server.http.gracefulShutdownTimeout` does not start counting down until after this period elapses.|`PT0s` (do not wait)| |`druid.broker.http.numConnections`|Size of connection pool for the Broker to connect to historical and real-time processes. If there are more queries than this number that all need to speak to the same node, then they will queue up.|20| |`druid.broker.http.compressionCodec`|Compression codec the Broker uses to communicate with historical and real-time processes. May be "gzip" or "identity".|gzip| |`druid.broker.http.readTimeout`|The timeout for data reads from historical and real-time processes.|PT15M| diff --git a/docs/content/configuration/historical.md b/docs/content/configuration/historical.md index c39df7a8916c..7305f0f23727 100644 --- a/docs/content/configuration/historical.md +++ b/docs/content/configuration/historical.md @@ -55,6 +55,7 @@ Druid uses Jetty to serve HTTP requests. |`druid.server.http.enableRequestLimit`|If enabled, no requests would be queued in jetty queue and "HTTP 429 Too Many Requests" error response would be sent. |false| |`druid.server.http.defaultQueryTimeout`|Query timeout in millis, beyond which unfinished queries will be cancelled|300000| |`druid.server.http.gracefulShutdownTimeout`|The maximum amount of time Jetty waits after receiving shutdown signal. After this timeout the threads will be forcefully shutdown. This allows any queries that are executing to complete.|PT15s| +|`druid.server.http.unannouncePropogationDelay`|How long to wait for zookeeper unannouncements to propgate before shutting down Jetty. This is a minimum and `druid.server.http.gracefulShutdownTimeout` does not start counting down until after this period elapses.|`PT0s` (do not wait)| |`druid.server.http.maxQueryTimeout`|Maximum allowed value (in milliseconds) for `timeout` parameter. See [query-context](query-context.html) to know more about `timeout`. Query is rejected if the query context `timeout` is greater than this value. |Long.MAX_VALUE| |`druid.server.http.maxRequestHeaderSize`|Maximum size of a request header in bytes. Larger headers consume more memory and can make a server more vulnerable to denial of service attacks.|8 * 1024| diff --git a/server/src/main/java/io/druid/server/initialization/ServerConfig.java b/server/src/main/java/io/druid/server/initialization/ServerConfig.java index 24e2566d6ad4..e2f53dcd7b65 100644 --- a/server/src/main/java/io/druid/server/initialization/ServerConfig.java +++ b/server/src/main/java/io/druid/server/initialization/ServerConfig.java @@ -64,6 +64,10 @@ public class ServerConfig @NotNull private Period gracefulShutdownTimeout = new Period("PT15s"); + @JsonProperty + @NotNull + private Period unannouncePropogationDelay = Period.ZERO; + public int getNumThreads() { return numThreads; @@ -109,6 +113,11 @@ public Period getGracefulShutdownTimeout() return gracefulShutdownTimeout; } + public Period getUnannouncePropogationDelay() + { + return unannouncePropogationDelay; + } + @Override public boolean equals(Object o) { @@ -127,7 +136,8 @@ public boolean equals(Object o) maxQueryTimeout == that.maxQueryTimeout && maxRequestHeaderSize == that.maxRequestHeaderSize && Objects.equals(maxIdleTime, that.maxIdleTime) && - Objects.equals(gracefulShutdownTimeout, that.gracefulShutdownTimeout); + Objects.equals(gracefulShutdownTimeout, that.gracefulShutdownTimeout) && + Objects.equals(unannouncePropogationDelay, that.unannouncePropogationDelay); } @Override @@ -143,7 +153,8 @@ public int hashCode() maxScatterGatherBytes, maxQueryTimeout, maxRequestHeaderSize, - gracefulShutdownTimeout + gracefulShutdownTimeout, + unannouncePropogationDelay ); } @@ -160,6 +171,7 @@ public String toString() ", maxQueryTimeout=" + maxQueryTimeout + ", maxRequestHeaderSize=" + maxRequestHeaderSize + ", gracefulShutdownTimeout=" + gracefulShutdownTimeout + + ", unannouncePropogationDelay=" + unannouncePropogationDelay + '}'; } } diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index 70e9a2f2ea51..1b1f85f9f12a 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -74,6 +74,7 @@ import org.eclipse.jetty.util.ssl.SslContextFactory; import org.eclipse.jetty.util.thread.QueuedThreadPool; import org.eclipse.jetty.util.thread.ScheduledExecutorScheduler; +import org.joda.time.Period; import javax.net.ssl.KeyManagerFactory; import javax.net.ssl.SSLEngine; @@ -376,9 +377,23 @@ public void start() throws Exception public void stop() { try { - log.info("Stopping jetty server..."); + final Period unannounceDelay = config.getUnannouncePropogationDelay(); + if (unannounceDelay != null) { + final long waitTime = unannounceDelay.toStandardDuration().getMillis(); + if (waitTime > 0) { + log.info("Waiting %s for unannouncement to propogate.", unannounceDelay); + Thread.sleep(unannounceDelay.toStandardDuration().getMillis()); + } else { + log.debug("Skipping unannounce wait."); + } + } + log.info("Stopping Jetty Server..."); server.stop(); } + catch (InterruptedException e) { + Thread.currentThread().interrupt(); + throw new RE(e, "Interrupted waiting for jetty shutdown."); + } catch (Exception e) { log.warn(e, "Unable to stop Jetty server."); } From 6317dac8396221e7bc8c18ce49c35c7d7541c316 Mon Sep 17 00:00:00 2001 From: Charles Allen Date: Wed, 7 Mar 2018 15:32:01 -0800 Subject: [PATCH 10/14] Make the default retain prior behavior --- .../java/io/druid/server/initialization/ServerConfig.java | 2 +- .../druid/server/initialization/jetty/JettyServerModule.java | 5 ++++- 2 files changed, 5 insertions(+), 2 deletions(-) diff --git a/server/src/main/java/io/druid/server/initialization/ServerConfig.java b/server/src/main/java/io/druid/server/initialization/ServerConfig.java index e2f53dcd7b65..8fa80d5e50b6 100644 --- a/server/src/main/java/io/druid/server/initialization/ServerConfig.java +++ b/server/src/main/java/io/druid/server/initialization/ServerConfig.java @@ -62,7 +62,7 @@ public class ServerConfig @JsonProperty @NotNull - private Period gracefulShutdownTimeout = new Period("PT15s"); + private Period gracefulShutdownTimeout = Period.ZERO; @JsonProperty @NotNull diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index 1b1f85f9f12a..eb2ccfc228e8 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -299,7 +299,10 @@ static Server makeAndInitializeServer( server.setHandler(new StatisticsHandler()); server.setConnectors(connectors); - server.setStopTimeout(config.getGracefulShutdownTimeout().toStandardDuration().getMillis()); + final long gracefulStop = config.getGracefulShutdownTimeout().toStandardDuration().getMillis(); + if (gracefulStop > 0) { + server.setStopTimeout(gracefulStop); + } server.addLifeCycleListener(new LifeCycle.Listener() { @Override From efde5ba7c2a59760e7c68f5b124c0ed08edb50c5 Mon Sep 17 00:00:00 2001 From: Charles Allen Date: Wed, 7 Mar 2018 15:33:50 -0800 Subject: [PATCH 11/14] Update docs with new config defaults --- docs/content/configuration/broker.md | 2 +- docs/content/configuration/historical.md | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/docs/content/configuration/broker.md b/docs/content/configuration/broker.md index 2a20a4075c14..f36ae2a95e2d 100644 --- a/docs/content/configuration/broker.md +++ b/docs/content/configuration/broker.md @@ -41,7 +41,7 @@ Druid uses Jetty to serve HTTP requests. |`druid.server.http.enableRequestLimit`|If enabled, no requests would be queued in jetty queue and "HTTP 429 Too Many Requests" error response would be sent. |false| |`druid.server.http.defaultQueryTimeout`|Query timeout in millis, beyond which unfinished queries will be cancelled|300000| |`druid.server.http.maxScatterGatherBytes`|Maximum number of bytes gathered from data nodes such as historicals and realtime processes to execute a query. This is an advance configuration that allows to protect in case broker is under heavy load and not utilizing the data gathered in memory fast enough and leading to OOMs. This limit can be further reduced at query time using `maxScatterGatherBytes` in the context. Note that having large limit is not necessarily bad if broker is never under heavy concurrent load in which case data gathered is processed quickly and freeing up the memory used.|Long.MAX_VALUE| -|`druid.server.http.gracefulShutdownTimeout`|The maximum amount of time Jetty waits after receiving shutdown signal. After this timeout the threads will be forcefully shutdown. This allows any queries that are executing to complete.|PT15s| +|`druid.server.http.gracefulShutdownTimeout`|The maximum amount of time Jetty waits after receiving shutdown signal. After this timeout the threads will be forcefully shutdown. This allows any queries that are executing to complete.|`PT0s` (do not wait)| |`druid.server.http.unannouncePropogationDelay`|How long to wait for zookeeper unannouncements to propgate before shutting down Jetty. This is a minimum and `druid.server.http.gracefulShutdownTimeout` does not start counting down until after this period elapses.|`PT0s` (do not wait)| |`druid.broker.http.numConnections`|Size of connection pool for the Broker to connect to historical and real-time processes. If there are more queries than this number that all need to speak to the same node, then they will queue up.|20| |`druid.broker.http.compressionCodec`|Compression codec the Broker uses to communicate with historical and real-time processes. May be "gzip" or "identity".|gzip| diff --git a/docs/content/configuration/historical.md b/docs/content/configuration/historical.md index 7305f0f23727..7d2d1ff49873 100644 --- a/docs/content/configuration/historical.md +++ b/docs/content/configuration/historical.md @@ -54,7 +54,7 @@ Druid uses Jetty to serve HTTP requests. |`druid.server.http.maxIdleTime`|The Jetty max idle time for a connection.|PT5m| |`druid.server.http.enableRequestLimit`|If enabled, no requests would be queued in jetty queue and "HTTP 429 Too Many Requests" error response would be sent. |false| |`druid.server.http.defaultQueryTimeout`|Query timeout in millis, beyond which unfinished queries will be cancelled|300000| -|`druid.server.http.gracefulShutdownTimeout`|The maximum amount of time Jetty waits after receiving shutdown signal. After this timeout the threads will be forcefully shutdown. This allows any queries that are executing to complete.|PT15s| +|`druid.server.http.gracefulShutdownTimeout`|The maximum amount of time Jetty waits after receiving shutdown signal. After this timeout the threads will be forcefully shutdown. This allows any queries that are executing to complete.|`PT0s` (do not wait)| |`druid.server.http.unannouncePropogationDelay`|How long to wait for zookeeper unannouncements to propgate before shutting down Jetty. This is a minimum and `druid.server.http.gracefulShutdownTimeout` does not start counting down until after this period elapses.|`PT0s` (do not wait)| |`druid.server.http.maxQueryTimeout`|Maximum allowed value (in milliseconds) for `timeout` parameter. See [query-context](query-context.html) to know more about `timeout`. Query is rejected if the query context `timeout` is greater than this value. |Long.MAX_VALUE| |`druid.server.http.maxRequestHeaderSize`|Maximum size of a request header in bytes. Larger headers consume more memory and can make a server more vulnerable to denial of service attacks.|8 * 1024| From 94c8699198c06a29e1b2fbffa17cd83ba39de920 Mon Sep 17 00:00:00 2001 From: Charles Allen Date: Fri, 9 Mar 2018 09:31:11 -0800 Subject: [PATCH 12/14] Make duration handling on jetty shutdown more consistent --- .../initialization/jetty/JettyServerModule.java | 16 ++++++---------- 1 file changed, 6 insertions(+), 10 deletions(-) diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index eb2ccfc228e8..7a9ed6e7cc49 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -74,7 +74,6 @@ import org.eclipse.jetty.util.ssl.SslContextFactory; import org.eclipse.jetty.util.thread.QueuedThreadPool; import org.eclipse.jetty.util.thread.ScheduledExecutorScheduler; -import org.joda.time.Period; import javax.net.ssl.KeyManagerFactory; import javax.net.ssl.SSLEngine; @@ -380,15 +379,12 @@ public void start() throws Exception public void stop() { try { - final Period unannounceDelay = config.getUnannouncePropogationDelay(); - if (unannounceDelay != null) { - final long waitTime = unannounceDelay.toStandardDuration().getMillis(); - if (waitTime > 0) { - log.info("Waiting %s for unannouncement to propogate.", unannounceDelay); - Thread.sleep(unannounceDelay.toStandardDuration().getMillis()); - } else { - log.debug("Skipping unannounce wait."); - } + final long unannounceDelay = config.getUnannouncePropogationDelay().toStandardDuration().getMillis(); + if (unannounceDelay > 0) { + log.info("Waiting %s ms for unannouncement to propogate.", unannounceDelay); + Thread.sleep(unannounceDelay); + } else { + log.debug("Skipping unannounce wait."); } log.info("Stopping Jetty Server..."); server.stop(); From 2919aa348186f8d8b483dc85ddfffba88b6cc299 Mon Sep 17 00:00:00 2001 From: Charles Allen Date: Fri, 9 Mar 2018 11:05:08 -0800 Subject: [PATCH 13/14] StatisticsHandler is a wrapper --- .../server/initialization/jetty/JettyServerModule.java | 2 -- .../main/java/io/druid/cli/QueryJettyServerInitializer.java | 6 +++++- 2 files changed, 5 insertions(+), 3 deletions(-) diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index 7a9ed6e7cc49..57e627548f00 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -69,7 +69,6 @@ import org.eclipse.jetty.server.Server; import org.eclipse.jetty.server.ServerConnector; import org.eclipse.jetty.server.SslConnectionFactory; -import org.eclipse.jetty.server.handler.StatisticsHandler; import org.eclipse.jetty.util.component.LifeCycle; import org.eclipse.jetty.util.ssl.SslContextFactory; import org.eclipse.jetty.util.thread.QueuedThreadPool; @@ -296,7 +295,6 @@ static Server makeAndInitializeServer( connector.setConnectionFactories(monitoredConnFactories); } - server.setHandler(new StatisticsHandler()); server.setConnectors(connectors); final long gracefulStop = config.getGracefulShutdownTimeout().toStandardDuration().getMillis(); if (gracefulStop > 0) { diff --git a/services/src/main/java/io/druid/cli/QueryJettyServerInitializer.java b/services/src/main/java/io/druid/cli/QueryJettyServerInitializer.java index c00faf066fed..e9ddfb6f1c63 100644 --- a/services/src/main/java/io/druid/cli/QueryJettyServerInitializer.java +++ b/services/src/main/java/io/druid/cli/QueryJettyServerInitializer.java @@ -39,6 +39,7 @@ import org.eclipse.jetty.server.Handler; import org.eclipse.jetty.server.Server; import org.eclipse.jetty.server.handler.HandlerList; +import org.eclipse.jetty.server.handler.StatisticsHandler; import org.eclipse.jetty.servlet.DefaultServlet; import org.eclipse.jetty.servlet.FilterHolder; import org.eclipse.jetty.servlet.ServletContextHandler; @@ -126,6 +127,9 @@ public void initialize(Server server, Injector injector) // Add Gzip handler at the very end handlerList.addHandler(JettyServerInitUtils.wrapWithDefaultGzipHandler(root)); - server.setHandler(handlerList); + final StatisticsHandler statisticsHandler = new StatisticsHandler(); + statisticsHandler.setHandler(handlerList); + + server.setHandler(statisticsHandler); } } From 9714efac5f4816cb7087ec8979308b1a51a8b38d Mon Sep 17 00:00:00 2001 From: Charles Allen Date: Mon, 19 Mar 2018 11:08:46 -0700 Subject: [PATCH 14/14] Move jetty lifecycle error logging to error --- .../io/druid/server/initialization/jetty/JettyServerModule.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java index 57e627548f00..57292fce9433 100644 --- a/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java +++ b/server/src/main/java/io/druid/server/initialization/jetty/JettyServerModule.java @@ -317,7 +317,7 @@ public void lifeCycleStarted(LifeCycle event) @Override public void lifeCycleFailure(LifeCycle event, Throwable cause) { - log.warn(cause, "Jetty lifecycle event failed [%s]", event.getClass()); + log.error(cause, "Jetty lifecycle event failed [%s]", event.getClass()); } @Override