Completely disable thread pool initialization for metrics feature

[dsultanr]

I have a strange issue in a Lotus Domino with the Slack api

[014201:000008-00007F0319398700] 04/19/2021 22:15:53   Agent Manager: Agent printing: sending slack message
[014201:000008-00007F0319398700] 04/19/2021 22:15:54   Agent Manager: Agent printing: sendSlackChannelMessage>pChannel ->membership<-
[014201:000008-00007F0319398700] 04/19/2021 22:15:56   Agent Manager: Agent printing: WebhookResponse(code=200, message=OK, body=ok)
[014201:000009-00007F03192D5700] 04/19/2021 22:15:56   Agent Manager: Agent  error: Exception in thread "slack-api-client-metrics-memory:e56980fe-worker-47" 
[014201:000010-00007F0319357700] 04/19/2021 22:15:56   Agent Manager: Agent  error: Exception in thread "slack-api-client-metrics-memory:cfa21c1a-worker-45" 
[014201:000011-00007F03192D5700] 04/19/2021 22:15:56   Agent Manager: Agent  error: java.lang.IllegalMonitorStateException
[014201:000012-00007F0319357700] 04/19/2021 22:15:56   Agent Manager: Agent  error: java.lang.IllegalMonitorStateException
[014201:000015-00007F0319316700] 04/19/2021 22:15:56   Agent Manager: Agent  error: Exception in thread "slack-api-client-metrics-memory:fe1c9a21-worker-46" 
[014201:000016-00007F03192D5700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.signal(AbstractQueuedSynchronizer.java:1950)
[014201:000018-00007F0319357700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.signal(AbstractQueuedSynchronizer.java:1950)
[014201:000019-00007F0319316700] 04/19/2021 22:15:56   Agent Manager: Agent  error: java.lang.IllegalMonitorStateException
[014201:000022-00007F0319316700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.signal(AbstractQueuedSynchronizer.java:1950)
[014201:000023-00007F0319357700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1114)
[014201:000026-00007F0319316700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1114)
[014201:000027-00007F0319357700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:820)
[014201:000029-00007F03192D5700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1114)
[014201:000031-00007F0319316700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:820)
[014201:000032-00007F03192D5700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:820)
[014201:000036-00007F03192D5700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1085)
[014201:000037-00007F0319316700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1085)
[014201:000039-00007F0319357700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1085)
[014201:000041-00007F03192D5700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[014201:000042-00007F0319357700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[014201:000045-00007F03192D5700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[014201:000048-00007F03192D5700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.lang.Thread.run(Thread.java:812)
[014201:000049-00007F0319357700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[014201:000052-00007F0319357700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.lang.Thread.run(Thread.java:812)
[014201:000053-00007F0319316700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[014201:000056-00007F0319316700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[014201:000058-00007F0319316700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.lang.Thread.run(Thread.java:812)
[014201:000007-00007F03198B4700] 04/19/2021 22:15:56   Agent Manager: Agent  error: Error cleaning up agent threads
[014201:000060-00007F0319212700] 04/19/2021 22:15:56   Agent Manager: Agent  error: Exception in thread "slack-api-client-metrics-memory:cfa21c1a-worker-53" 
[014201:000061-00007F0319294700] 04/19/2021 22:15:56   Agent Manager: Agent  error: Exception in thread "slack-api-client-metrics-memory:fe1c9a21-worker-52" 
[014201:000062-00007F0319253700] 04/19/2021 22:15:56   Agent Manager: Agent  error: Exception in thread "slack-api-client-metrics-memory:e56980fe-worker-54" 
[014201:000063-00007F0319294700] 04/19/2021 22:15:56   Agent Manager: Agent  error: java.lang.IllegalMonitorStateException
[014201:000064-00007F0319212700] 04/19/2021 22:15:56   Agent Manager: Agent  error: java.lang.IllegalMonitorStateException
[014201:000067-00007F0319253700] 04/19/2021 22:15:56   Agent Manager: Agent  error: java.lang.IllegalMonitorStateException
[014201:000068-00007F0319294700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.signal(AbstractQueuedSynchronizer.java:1950)
[014201:000069-00007F0319212700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.signal(AbstractQueuedSynchronizer.java:1950)
[014201:000072-00007F0319253700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.signal(AbstractQueuedSynchronizer.java:1950)
[014201:000074-00007F0319294700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1114)
[014201:000077-00007F0319294700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:820)
[014201:000078-00007F0319253700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1114)
[014201:000081-00007F0319294700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1085)
[014201:000082-00007F0319253700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:820)
[014201:000085-00007F0319294700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[014201:000086-00007F0319253700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1085)
[014201:000089-00007F0319294700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[014201:000090-00007F0319253700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[014201:000092-00007F0319212700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1114)
[014201:000094-00007F0319294700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.lang.Thread.run(Thread.java:812)
[014201:000097-00007F0319212700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:820)
[014201:000098-00007F0319253700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[014201:000101-00007F0319253700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.lang.Thread.run(Thread.java:812)
[014201:000103-00007F0319212700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1085)
[014201:000105-00007F0319212700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[014201:000107-00007F0319212700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[014201:000109-00007F0319212700] 04/19/2021 22:15:56   Agent Manager: Agent  error:  at java.lang.Thread.run(Thread.java:812)

The Slack SDK version

	<dependency>
		<groupId>com.slack.api</groupId>
		<artifactId>slack-api-client</artifactId>
		<version>1.6.2</version>
	</dependency>

Java Runtime version

[010392:000002-00007FF303406740] 04/21/2021 10:00:57 Java runtime version: 8.0.5.21 - pxa6480sr5fp21-20180830_01(SR5 FP21)
[010392:000002-00007FF303406740] 04/21/2021 10:00:57 JVM version: JRE 1.8.0 Linux amd64-64-Bit 20180829_395745 (JIT enabled, AOT enabled) OpenJ9 - e82188c OMR - eeaa30e IBM - 98805ca

OS info

Linux 46f0066d17e5 3.10.0-957.10.1.el7.x86_64 #1 SMP Mon Mar 18 15:06:45 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

Steps to reproduce:

public class SlackActions {

	public String sendSlackChannelMessage(String pChannel,String textBody) {
			String returnMsg = "OK, sent";
			String slackChannelURL = "...";
			
			Payload payload = Payload.builder().text(textBody).build();
			
			Slack slack = Slack.getInstance();		

			try {
				WebhookResponse response = slack.send(slackChannelURL, payload);
				System.out.println(response); // WebhookResponse(code=200, message=OK, body=ok)
			} catch (IOException e) {
				System.out.println( "Work/sendSlackChannelMessage>Something bad just happened." ); 
				System.out.println( "Work/sendSlackChannelMessage>" + e ); 
				e.printStackTrace();
				returnMsg = e.toString();
			}

			return returnMsg;
	}



public class JavaAgent extends AgentBase {
	
	public void NotesMain() {
		try {

			SlackActions slackActions = new SlackActions();
		    slackResponse = slackActions.sendSlackChannelMessage("membership",SMSTextBody);

		} catch (Exception e) {
			System.out.println("exception " + e);
	    }	
	}

Expected result:

clean exit

Actual result:

threads cleanup error, logs are in top of this message

error thrown even if I comment out block with slack.send call and just leave Slack.getInstance()

Did threads debug (debugger code here) before agent exit and here is the output:

[031267:000113-00007F5A59B2C700] 04/21/2021 00:10:31   Agent Manager: Agent printing: Dump the current threadgroup:
[031267:000113-00007F5A59B2C700] 04/21/2021 00:10:31   Agent Manager: Agent printing: ThreadGroup UTG: JavaAgent, objid = 1743864694
[031267:000113-00007F5A59B2C700] 04/21/2021 00:10:31   Agent Manager: Agent printing:   subgroups  = 3
[031267:000113-00007F5A59B2C700] 04/21/2021 00:10:31   Agent Manager: Agent printing:   total threads = 4
[031267:000113-00007F5A59B2C700] 04/21/2021 00:10:31   Agent Manager: Agent printing:  THREADNAME, THREADID, THREADGROUP
[031267:000113-00007F5A59B2C700] 04/21/2021 00:10:31   Agent Manager: Agent printing: AgentThread: JavaAgent, 563351903, UTG: JavaAgent

[seratch]

Hi @dsultanr, thanks for writing in!

Although the daemon thread pools for metrics work without any issues with OpenJDK etc, the part of this library might not be compatible with the runtime you use.

As a workaround, can you try a custom SlackConfig to pass for your Slack instantiation? With the config, this SDK never creates the threads for metrics. As the SlackConfig is thread-safe, you can reuse the same config object for Slack instantiation multiple times (it's also fine to use a singleton Slack instance).

package hello;

import com.slack.api.Slack;
import com.slack.api.SlackConfig;
import com.slack.api.audit.AuditConfig;
import com.slack.api.methods.MethodsConfig;
import com.slack.api.methods.response.api.ApiTestResponse;
import com.slack.api.scim.SCIMConfig;

public class Example {

    public static void main(String[] args) throws Exception {
        // You can reuse this config for all client instantiation
        SlackConfig config = new SlackConfig();
        config.setMethodsConfig(MethodsConfig.builder().statsEnabled(false).metricsDatastore(null).build());
        config.setSCIMConfig(SCIMConfig.builder().statsEnabled(false).metricsDatastore(null).build());
        config.setAuditConfig(AuditConfig.builder().statsEnabled(false).metricsDatastore(null).build());
        Slack slack = Slack.getInstance(config);

        ApiTestResponse response = slack.methods().apiTest(r -> r.foo("bar"));
        System.out.println(response);
    }

}

Also, okhttp (the underlying HTTP client of this library) generates its thread pool under the hood. To smoothly clean it up, I recommend calling Slack#close() when shutting your runtime down.

I hope this was helpful to you.

[dsultanr]

Hi @seratch, thanks for quick reply!

I added a config you proposed

		SlackConfig config = new SlackConfig();
	        config.setMethodsConfig(MethodsConfig.builder().statsEnabled(false).metricsDatastore(null).build());
	        config.setSCIMConfig(SCIMConfig.builder().statsEnabled(false).metricsDatastore(null).build());
	        config.setAuditConfig(AuditConfig.builder().statsEnabled(false).metricsDatastore(null).build());
	        Slack slack = Slack.getInstance(config);

but SDK still creates the threads for metrics here is the log:

[031267:000428-00007F5A32C05700] 04/21/2021 11:14:43   Agent Manager: Agent printing: Dump the current threadgroup:
[031267:000428-00007F5A32C05700] 04/21/2021 11:14:43   Agent Manager: Agent printing: ThreadGroup UTG: JavaAgent, objid = 1419510491
[031267:000428-00007F5A32C05700] 04/21/2021 11:14:43   Agent Manager: Agent printing:   subgroups  = 3
[031267:000428-00007F5A32C05700] 04/21/2021 11:14:43   Agent Manager: Agent printing:   total threads = 4
[031267:000428-00007F5A32C05700] 04/21/2021 11:14:43   Agent Manager: Agent printing:  THREADNAME, THREADID, THREADGROUP
[031267:000428-00007F5A32C05700] 04/21/2021 11:14:43   Agent Manager: Agent printing: AgentThread: JavaAgent, 589925707, UTG: JavaAgent
[031267:000428-00007F5A32C05700] 04/21/2021 11:14:43   Agent Manager: Agent printing: slack-api-client-metrics-memory:1f851381-worker-101, -707352037, slack-api-client-metrics-memory:1f851381
[031267:000428-00007F5A32C05700] 04/21/2021 11:14:43   Agent Manager: Agent printing: slack-api-client-metrics-memory:b041f442-worker-102, 1919586380, slack-api-client-metrics-memory:b041f442
[031267:000428-00007F5A32C05700] 04/21/2021 11:14:43   Agent Manager: Agent printing: slack-api-client-metrics-memory:23dddd42-worker-103, 265711126, slack-api-client-metrics-memory:23dddd42
[031267:000429-00007F5A32C46700] 04/21/2021 11:14:43   Agent Manager: Agent  error: Exception in thread "slack-api-client-metrics-memory:1f851381-worker-101" 
[031267:000430-00007F5A59708700] 04/21/2021 11:14:43   Agent Manager: Agent  error: Exception in thread "slack-api-client-metrics-memory:b041f442-worker-102" 
[031267:000431-00007F5A32C46700] 04/21/2021 11:14:43   Agent Manager: Agent  error: java.lang.IllegalMonitorStateException
[031267:000432-00007F5A59708700] 04/21/2021 11:14:43   Agent Manager: Agent  error: java.lang.IllegalMonitorStateException
[031267:000434-00007F5A58639700] 04/21/2021 11:14:43   Agent Manager: Agent  error: Exception in thread "slack-api-client-metrics-memory:23dddd42-worker-103" 
[031267:000436-00007F5A58639700] 04/21/2021 11:14:43   Agent Manager: Agent  error: java.lang.IllegalMonitorStateException

[seratch]

@dsultanr Thanks for sharing the result! hmm, this SDK should provide a new option to completely disable the metrics feature. I cannot tell when we can make the release yet but I will update you once the fix is available.

As a workaround, please consider using a different HTTP client for performing webhook requests and Web API calls for now.

[seratch]

After working on this task a bit today, I found that supporting this with full backward compatibility may take a bit longer than I expect (it's feasible but not so simple). Let me move this to v2 milestone.

[metaruslan]

@seratch do I understand correctly that the problem is with those threads not properly closed? And so does it mean that Slack#close() would only close okhttp threads, but not the metrics feature threads? As you mentioned you would add an option to disable metrics, but why not add the proper closing within Slack#close(), so that it would close everything and I wouldn't need to disable anything.

I may have misunderstood something completely, so my apologies if that is the case. My situation is that I'm invoking Slack#close() upon shutdown (tomcat shutdown), but I still get
{code}
28-Sep-2021 16:36:46.727 WARNING [main] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [batch] appears to have started a thread named [slack-api-client-metrics-memory:6106aae0-worker-45] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
{code}