Hystrix: Memory leak. HystrixMetricsPoller.pause throws exception on app shutdown. Poller keeps running.

Created on 23 Feb 2016  路  10Comments  路  Source: Netflix/Hystrix

Hi,

I deployed turbine and an app which exposes hystrix stream on same node of tomcat 8. Turbine, Hystrix and Hystrix stream worked as expected but after stopping the application i can see that a few threads related to these are still running. Tomcat manager's diagnostic also pointed out same.

below is exception seen in logs that suggests an issue with poller

24-Feb-2016 10:20:44.783 INFO [http-apr-8080-exec-2] org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading Illegal access: this web a
pplication instance has been stopped already. Could not load [java.util.concurrent.ScheduledFuture]. The following stack trace is thrown for debugging purpos
es as well as to attempt to terminate the thread which caused the illegal access.
java.lang.IllegalStateException: Illegal access: this web application instance has been stopped already. Could not load [java.util.concurrent.ScheduledFutur
e]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading(WebappClassLoaderBase.java:1353)
at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1341)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1206)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1167)
at com.netflix.hystrix.contrib.metrics.eventstream.HystrixMetricsPoller.pause(HystrixMetricsPoller.java:114)
at com.netflix.hystrix.contrib.metrics.eventstream.HystrixMetricsPoller.shutdown(HystrixMetricsPoller.java:126)
at com.netflix.hystrix.contrib.metrics.eventstream.HystrixMetricsStreamServlet.handleRequest(HystrixMetricsStreamServlet.java:192)
at

Used :- Hystrix / Hystrix stream version 1.4.23 and turbine-web-1.0.0.war

_Below are the threads from thread dump. _

Name: pool-5-thread-1
State: TIMED_WAITING
Total blocked: 1 Total waited: 11,610

Stack trace:
java.lang.Thread.sleep(Native Method)
com.netflix.turbine.handler.HandlerQueueTuple$PerHandlerDispatcher.doWork(HandlerQueueTuple.java:245)
com.netflix.turbine.utils.WorkerThread$1.call(WorkerThread.java:145)
com.netflix.turbine.utils.WorkerThread$1.call(WorkerThread.java:138)
java.util.concurrent.FutureTask.run(FutureTask.java:266)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)

Name: HystrixMetricPoller
State: TIMED_WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@1b7a7c15
Total blocked: 0 Total waited: 5,017

Stack trace:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)

bug metrics

Most helpful comment

Below code resolved issue related to polling thread of archaius. i wrote a Servlet context listener to perform below steps during app shutdown. I am not sure this covers all types of configuration which can poll. It will be good if archaius has an out of the box servlet context llistener to perform cleanup on app shutdown. I believe below steps should not be performed in case if archaius jar is shared among multiple apps running on same node.

try {
if (ConfigurationManager.getConfigInstance() instanceof DynamicConfiguration) {
DynamicConfiguration config = (DynamicConfiguration) ConfigurationManager.getConfigInstance();
config.stopLoading();
} else if (ConfigurationManager.getConfigInstance() instanceof ConcurrentCompositeConfiguration) {
ConcurrentCompositeConfiguration configInst = (ConcurrentCompositeConfiguration) ConfigurationManager
.getConfigInstance();
List<AbstractConfiguration> configs = configInst.getConfigurations();
if (configs != null) {
for (AbstractConfiguration config : configs) {
if (config instanceof DynamicConfiguration) {
((DynamicConfiguration) config).stopLoading();
break;
}
}
}
}
} catch (Exception e) {
e.printStackTrace();
}

All 10 comments

found reason behind illegal access exception that was causing memory leak. Hystrix stream servlets destroy method just sets a variable value which causes Shutdown method of poller to be called after some delay. This delayed access to ScheduledFuture from a thread is causing illegal access exception. This issue is resolved if i create my own servlet and put a delay after destroy(). Delay in destroy has to be more than delays for which pollers are running.

@Override
public void destroy() {
super.destroy();
try {
Thread.sleep(10000);
} catch (InterruptedException e) {
e.printStackTrace();
}
}

i see another issue which is still causing memory leak and keeps apps classes from garbage collected. Below is exception for the same

24-Feb-2016 11:07:18.606 WARNING [http-apr-8080-exec-7] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [eventWS]
appears to have started a thread named [pollingConfigurationSource] but has failed to stop it. This is very likely to create a memory leak. Stack trace of t
hread:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)

@vinshar Thanks for the explanation. If you've got a code change that does effective shutdown, I'd be happy to review a PR.

I believe the pollerConfigurationSource thread is set up by Archaius. So any sort of app-shutdown would have to reach that Archaius thread.

Below code resolved issue related to polling thread of archaius. i wrote a Servlet context listener to perform below steps during app shutdown. I am not sure this covers all types of configuration which can poll. It will be good if archaius has an out of the box servlet context llistener to perform cleanup on app shutdown. I believe below steps should not be performed in case if archaius jar is shared among multiple apps running on same node.

try {
if (ConfigurationManager.getConfigInstance() instanceof DynamicConfiguration) {
DynamicConfiguration config = (DynamicConfiguration) ConfigurationManager.getConfigInstance();
config.stopLoading();
} else if (ConfigurationManager.getConfigInstance() instanceof ConcurrentCompositeConfiguration) {
ConcurrentCompositeConfiguration configInst = (ConcurrentCompositeConfiguration) ConfigurationManager
.getConfigInstance();
List<AbstractConfiguration> configs = configInst.getConfigurations();
if (configs != null) {
for (AbstractConfiguration config : configs) {
if (config instanceof DynamicConfiguration) {
((DynamicConfiguration) config).stopLoading();
break;
}
}
}
}
} catch (Exception e) {
e.printStackTrace();
}

destroy method of HystrixMetricsStreamServlet works in a async way. Below code makes it wait till all the pollers are stopped. This resolved my issue but this is not full proof. This may create problem if somebody started metrics polling with a huge delay.
full proof solution will be
1) Maintain a list or map of pollers HystrixMetricsStreamServlet
2) Remove pollers after shutdown in handleRequest method of HystrixMetricsStreamServlet
3) in HystrixMetricsStreamServlet.destroy call shutdown of each poller in the list or map.

I will send a PR for this.

@Override
public void destroy() {
/* set marker so the loops can break out */
isDestroyed = true;
super.destroy();
try {
while (concurrentConnections.get() > 0) {
logger.warn("Waiting for pollers to stop. Pollers active count "+concurrentConnections.get());
Thread.sleep(1000);
}
} catch (Exception e) {
logger.debug("InterruptedException. Will exit destroy.");
} }`

I just noticed that a almost all threads that Hystrix starts are left running on app shutdown. example thread names are - RxCachedWorkerPoolEvictor-1, RxComputationThreadPool-1, HystrixTimer-1, hystrix-group_name-1.

Is Hystrix built only for environments where each host has just one process and we always restart node? any pointers how can i hook shutdown of these threads and pools with app shutdown?

@vinshar Yes, you're correct. At Netflix, we treat servers as disposable and so just terminate cloud instances rather than try to restart/reset individual instances. The implementation heavily reflects that, and it's not a personal/Netflix priority to support graceful shutdown.

However, I'm sure a more graceful shutdown is useful, so I'm happy to include contributions / review code.

Its makes sense that graceful shutdown is not supported because of the reason you mentioned. but Hystrix is a very useful tool not only for cloud applications but for other apps as well. Without graceful shutdown its cannot be used in environments where servers are not disposable.
I will send contribute my code if i am able to implement graceful shutdown.

As mentioned in my previous comment this problem is not just with metrics. Hystrix core's thread pools etc are also need to be stopped during shutdown to make it graceful. Do we need to add more labels to this bug?

I just noticed that a almost all threads that Hystrix starts are left running on app shutdown. example thread names are - RxCachedWorkerPoolEvictor-1, RxComputationThreadPool-1, HystrixTimer-1, hystrix-group_name-1.

Is Hystrix built only for environments where each host has just one process and we always restart node? any pointers how can i hook shutdown of these threads and pools with app shutdown?

The reason its not really feasible is that Hystrix is currently a true static singleton (via HystrixPlugins) and does not have any lifecycle other than lazy loading.

As soon as you introduce a lifecycle fairly complicated state management, resource management, and general concurrency comes into play. For example on the complexity see Guava's Service support. To support this you will also want to make Hystrix not a singleton which brings the issues of plugin/component loading. The typical solution to this is to use a dependency injection framework or force the developer to wire up everything manually.

Even if the above was implemented, Hystrix may have to fundamentally change its design pattern/usage. The above is all fairly difficult if not impossible because Hystrix follows the command pattern where inheritance of an abstract class is used to configure and then execute. I suppose one could make it work by perhaps require passing a HystrixPlugins (whatever the root is) as constructor parameter to a command. However the lifecycle stuff would still need to be implemented (presumably in the HystrixPlugins class). Speaking of which the Timer thread pool (HystrixTimer-1) should be a HystrixPlugin as well. This is probably a ton of work.

Of course you could just implement a brute force shutdown on the singleton but beware extremely odd behavior along with NPE and various other exceptions will probably happen because of all the static access. Non singletons prevent this because of GC. That being said a simple AtomicBoolean flag could be added which might help your servlet problem but I believe most of your problems are really Archaius and the Servlet itself. Which case you may want to use Archaius 2 and the new HystrixDynamicProperties support. See #1083

My own company we follow a message bus pattern where the commands are really just immutable data objects (think structs). The actual execution is then put in another class as well as the configuration. That is the behavior, configuration (threadpools), and parameter data are all separated at the cost of greater complexity but with the flexibility that lifecycle is easier since not everything is glued together. I plan on releasing this framework at some point but candidly its far easier to use Hystrix particularly on dealing with fallbacks and other adhoc customization.

Memory Leak Issue with spring-cloud-starter-hystrix and spring-cloud-starter-archaius integration

Issue : We are using spring-cloud-starter-hystrix with spring-cloud-starter-archaius where we are unable to stop the poolingconfigurationSource thread of archaius once the war is un-deployed. But spring-cloud-starter-archaius is working fine without hystrix and thread is stopped once war is un-deployed.

"pollingConfigurationSource" thread is not killed automatically when application is un-deployed from application server. This thread is created by archaius API. Checked thread dump in visualVM after starting application and undeploying application. At the time of un-deployment , same thread is killed automatically and then immediately new thread is created with same name (pollingConfigurationSource).

Thread Dump :
"pollingConfigurationSource" #227 daemon prio=5 os_prio=0 tid=0x000000001cafd800 nid=0x218 waiting on condition [0x000000002dd0f000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000ebfed3c8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)

Locked ownable synchronizers:
- None

Please help.

Solution:

After applying below solution given by vinshar , issue is resolved.

THANKS A LOT VINSHAR , You have saved my day. Thanks again !

try {
if (ConfigurationManager.getConfigInstance() instanceof DynamicConfiguration) {
DynamicConfiguration config = (DynamicConfiguration) ConfigurationManager.getConfigInstance();
config.stopLoading();
} else if (ConfigurationManager.getConfigInstance() instanceof ConcurrentCompositeConfiguration) {
ConcurrentCompositeConfiguration configInst = (ConcurrentCompositeConfiguration) ConfigurationManager
.getConfigInstance();
List configs = configInst.getConfigurations();
if (configs != null) {
for (AbstractConfiguration config : configs) {
if (config instanceof DynamicConfiguration) {
((DynamicConfiguration) config).stopLoading();
break;
}
}
}
}
} catch (Exception e) {
e.printStackTrace();
}

Was this page helpful?
0 / 5 - 0 ratings