GelfREDISSender.close() does not stop Sentinel pool

[alejojo]

Hi @mp911de, I've been using logstash-gelf -> graylog with no issues for the last 2 or 3 years, thank you!

Now I want to add caching redundancy so I am checking redis-sentinel. So far is working fine, except when stopping tomcat.

When starting up there is no problem, but when shutting down it stays in INFO: Stopping Coyote HTTP/1.1 on http-PORT until I kill it.

libs ver:

• tomcat-6 (yes, I know)
• java-1.7.0 (yes, I know..)
• commons-pool2-2.4.3.jar
• jedis-3.0.1.jar
• log4j-1.2.17.jar
• logstash-gelf-1.13.0.jar

log4j.properties:

log4j.appender.gelf=biz.paluch.logging.gelf.log4j.GelfLogAppender
log4j.appender.gelf.Threshold=INFO
log4j.appender.gelf.Host=redis-sentinel://IP_REDIS_MASTER:26379/0?masterId=mymaster#list
log4j.appender.gelf.Version=1.1
log4j.appender.gelf.Facility=java-gelf
log4j.appender.gelf.ExtractStackTrace=true
log4j.appender.gelf.FilterStackTrace=true
log4j.appender.gelf.MdcProfiling=false
log4j.appender.gelf.MaximumMessageSize=8192
log4j.appender.gelf.AdditionalFields=appname=app

Logs catalina.out

...
May 20, 2019 3:51:38 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 223699 ms
...
May 20, 2019 3:53:50 PM org.apache.coyote.http11.Http11Protocol pause
INFO: Pausing Coyote HTTP/1.1 on http-PORT
May 20, 2019 3:53:51 PM org.apache.catalina.core.StandardService stop
INFO: Stopping service Catalina
May 20, 2019 3:53:51 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/app] appears to have started a thread named [MasterListener-mymaster-[IP_REDIS_MASTER:26379]] but has failed to stop it. This is very likely to create a memory leak.
May 20, 2019 3:53:51 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/app] appears to have started a thread named [commons-pool-evictor-thread] but has failed to stop it. This is very likely to create a memory leak.
May 20, 2019 3:53:52 PM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks
SEVERE: The web application [/app] created a ThreadLocal with key of type [biz.paluch.logging.gelf.GelfMessageAssembler$1] (value [biz.paluch.logging.gelf.GelfMessageAssembler$1@75cf74e]) and a value of type [biz.paluch.logging.gelf.intern.PoolingGelfMessageBuilder] (value [biz.paluch.logging.gelf.intern.PoolingGelfMessageBuilder@687025a8]) but failed to remove it when the web application was stopped. This is very likely to create a memory leak.
May 20, 2019 3:53:52 PM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
May 20, 2019 3:53:55 PM org.apache.coyote.http11.Http11Protocol destroy
INFO: Stopping Coyote HTTP/1.1 on http-PORT

Make sure that:

• You have read the contribution guidelines.
• You specify the logstash-gelf version and environment so it's obvious which version is affected
• You provide a reproducible test case (either descriptive of as JUnit test) if it's a bug or the expected behavior differs from the actual behavior.

btw: Makefile is pointing to redis-2.8-something but latest release is 5.0.4

[mp911de]

Can you grab a thread dump to see which threads are preventing shutdown?

[mp911de]

Seems that we do not close the Pool in GelfREDISSender.close().

[mp911de]

logstash-gelf aims for maximum compatibility. That's why we keep dependency versions as low as possible to not accidentally use functionality that is available only in newer library versions. We're still compatible with Java 1.6 runtimes and pretty old logging library versions and this is, why we keep Redis also on version 2.8.

[alejojo]

awesome, thank you!
thread dump: https://gist.github.com/alejojo/4496fb0fb6618ba7a38f347ba73c5d09

[mp911de]

Thanks a lot. The stack trace confirms my assumption that MasterListener-mymaster threads are blocking shutdown. Care to upgrade to 1.14.0-SNAPSHOT and retest?

[alejojo]

Hi Mark,

thank you for such quick reply!

I've just compiled/tested version 1.14.0-SNAPSHOT and with same results, tdump attached.

https://gist.github.com/alejojo/225aadc92aa8925173ded58d76f9a149

catalina.out:

May 21, 2019 10:52:10 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 93503 ms
May 21, 2019 10:52:46 AM org.apache.coyote.http11.Http11Protocol pause
INFO: Pausing Coyote HTTP/1.1 on http-PORT
May 21, 2019 10:52:47 AM org.apache.catalina.core.StandardService stop
INFO: Stopping service Catalina
May 21, 2019 10:52:47 AM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/app] appears to have started a thread named [MasterListener-mymaster-[IP_REDIS_MASTER:26379]] but has failed to stop it. This is very likely to create a memory leak.
May 21, 2019 10:52:47 AM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/app] appears to have started a thread named [commons-pool-evictor-thread] but has failed to stop it. This is very likely to create a memory leak.
May 21, 2019 10:52:47 AM org.apache.catalina.loader.WebappClassLoader clearReferencesThreads
SEVERE: The web application [/app] appears to have started a thread named [Thread-2] but has failed to stop it. This is very likely to create a memory leak.
May 21, 2019 10:52:47 AM org.apache.catalina.loader.WebappClassLoader checkThreadLocalMapForLeaks
SEVERE: The web application [/app] created a ThreadLocal with key of type [biz.paluch.logging.gelf.GelfMessageAssembler$1] (value [biz.paluch.logging.gelf.GelfMessageAssembler$1@207b41f5]) and a value of type [biz.paluch.logging.gelf.intern.PoolingGelfMessageBuilder] (value [biz.paluch.logging.gelf.intern.PoolingGelfMessageBuilder@e8ebd3c]) but failed to remove it when the web application was stopped. This is very likely to create a memory leak.
May 21, 2019 10:52:48 AM org.apache.coyote.http11.Http11Protocol destroy
INFO: Stopping Coyote HTTP/1.1 on http-PORT

Cheers,

[mp911de]

Thanks a lot. I took a look at Jedis code. The Thread shutdown sets just a flag and sends a disconnect signal to the Socket connection which leaves the thread still active. We cannot do anything more from our side.

I would suggest downgrading to an earlier Jedis version for your case.

[alejojo]

got it. thanks