The v2 of the java client leaks RxJava threads on shutdown

mcarvalho · October 22, 2015, 6:10pm

@simonbasle @daschl Thank for helping until here, I really appreciate it.

After these advices, lib updates and shutdown changes, I’m able to not see any Thread lock error anymore although after disconnect from cb cluster and shutdown the env + schedulers, the cb pooling system reconnect in a blink and after that maintain pooling active even after the application shutdown at all, in some way it still there pooling and checking the buckets, creating a memory leak .

                couchCluster.disconnect();
	  	env.shutdown().toBlocking().single();
	  	Schedulers.shutdown();

and after that I get the cb trying to reconfigure the buckets:

18:08:57.835 [http-bio-8080-exec-5] DEBUG c.c.c.c.config.ConfigurationProvider - Closing all open buckets
18:08:57.850 [cb-computations-3] DEBUG c.c.c.c.config.ConfigurationProvider - Closing bucket ordering
18:08:57.853 [cb-computations-3] DEBUG c.c.c.c.config.ConfigurationProvider - Removing bucket ordering configuration from known configs.
18:08:57.853 [cb-computations-3] DEBUG c.c.client.core.RequestHandler - Got notified of a new configuration arriving.
18:08:57.854 [cb-computations-3] DEBUG c.c.client.core.RequestHandler - Starting reconfiguration.
18:08:57.854 [cb-computations-3] DEBUG c.c.client.core.RequestHandler - Starting reconfiguration for bucket databank-revisions
18:08:57.875 [cb-computations-3] DEBUG c.c.client.core.RequestHandler - Got notified of a new configuration arriving.
18:08:57.875 [cb-computations-3] DEBUG c.c.client.core.RequestHandler - Starting reconfiguration.
18:08:57.875 [cb-computations-3] DEBUG c.c.client.core.RequestHandler - Starting reconfiguration for bucket databank
18:08:57.875 [cb-computations-3] DEBUG c.c.client.core.RequestHandler - Node my-domain/208.94.39.167 already registered, skipping.

All buckets are live again at this point:

18:08:59.747 [Thread-65] INFO  c.c.client.core.env.CoreEnvironment - Shutdown Netty: success 
18:08:59.753 [http-bio-8080-exec-5] DEBUG c.lettersandarts.client.InitListener - --- Finished ROOT APP ---

Any tips, thoughts or ideas?

You should be able to easily reproduce it.
Any question LMK.

Regards,
Mauricio

mcarvalho · October 22, 2015, 6:50pm

Just for curious, I know this pooling system is something new included in the last version. Is possible to disable it before shutdown or for dev/test environments?

We are running in a cluster with 3 nodes, using 3 buckets each. it looks like below during application execution:

 11:48:33.623 [cb-core-3-1] DEBUG c.c.c.c.config.ConfigurationProvider - Received signal for outdated configuration.
11:48:33.623 [cb-core-3-1] DEBUG c.c.c.c.config.ConfigurationProvider - Received signal for outdated configuration.
11:48:33.638 [cb-computations-3] DEBUG c.c.c.c.config.ConfigurationProvider - New Bucket databank-revisions config proposed.
11:48:33.639 [cb-computations-4] DEBUG c.c.c.c.config.ConfigurationProvider - New Bucket ordering config proposed.
11:48:33.646 [cb-computations-1] DEBUG c.c.c.c.config.ConfigurationProvider - New Bucket ordering config proposed.
11:48:33.649 [cb-computations-3] DEBUG c.c.c.c.c.refresher.CarrierRefresher - Completed refreshing config for bucket "databank-revisions"
11:48:33.650 [cb-computations-3] DEBUG c.c.c.c.config.ConfigurationProvider - New Bucket databank-revisions config proposed.
11:48:33.650 [cb-computations-1] DEBUG c.c.c.c.c.refresher.CarrierRefresher - Completed refreshing config for bucket "ordering"
11:48:33.651 [cb-computations-3] DEBUG c.c.c.c.c.refresher.CarrierRefresher - Completed refreshing config for bucket "databank-revisions"
11:48:33.653 [cb-computations-2] DEBUG c.c.c.c.config.ConfigurationProvider - New Bucket ordering config proposed.
11:48:33.657 [cb-computations-3] DEBUG c.c.c.c.config.ConfigurationProvider - New Bucket databank config proposed.
11:48:33.657 [cb-computations-4] DEBUG c.c.c.c.c.refresher.CarrierRefresher - Completed refreshing config for bucket "ordering"
11:48:33.657 [cb-computations-1] DEBUG c.c.c.c.config.ConfigurationProvider - New Bucket databank config proposed.
11:48:33.660 [cb-computations-4] DEBUG c.c.c.c.config.ConfigurationProvider - New Bucket databank-revisions config proposed.
11:48:33.661 [cb-computations-2] DEBUG c.c.c.c.c.refresher.CarrierRefresher - Completed refreshing config for bucket "ordering"
11:48:33.661 [cb-computations-2] DEBUG c.c.c.c.config.ConfigurationProvider - New Bucket databank config proposed.
11:48:33.662 [cb-computations-1] DEBUG c.c.c.c.c.refresher.CarrierRefresher - Completed refreshing config for bucket "databank"
11:48:33.662 [cb-computations-4] DEBUG c.c.c.c.c.refresher.CarrierRefresher - Completed refreshing config for bucket "databank-revisions"
11:48:33.662 [cb-computations-3] DEBUG c.c.c.c.c.refresher.CarrierRefresher - Completed refreshing config for bucket "databank"
11:48:33.663 [cb-computations-2] DEBUG c.c.c.c.c.refresher.CarrierRefresher - Completed refreshing config for bucket "databank"

simonbasle · October 26, 2015, 8:42am

ha good catch, indeed the Refresher should stop polling once the environment has been shut down…
JVMCBC-257

mcarvalho · October 26, 2015, 10:54pm

Thank you @simonbasle. I’m waiting for the fix release version.

By the way, how can I assign for me and pull request some bug fixes?
Do you guys have any how-to for open source contribution to couchbase SDK?

I’m getting close to this amazing solution and I’m feeling confident to try some bug fixes.

Regards,
Mauricio

simonbasle · October 27, 2015, 9:15am

awesome @mcarvalho, I’ve continued the discussion about contributing in Contributing to the Java SDK

simonbasle · November 3, 2015, 6:57pm

the connection polling (JVMCBC-257) has been fixed and will be part of the upcoming 2.2.2 release, expected by next week at most.
also great news, RxJava 1.0.15 is officially out
(we’ve bumped dependency to 1.0.15 in SDK 2.2.2 by the way)

mcarvalho · December 15, 2015, 11:25pm

Hello @simonbasle. I’m back
After update to RxJava 1.0.15 and couchbase 2.2.2 and core-io 1.2.2 I’m getting this memory leak

SEVERE: The web application [/mauricio] appears to have started a thread named [initialSeedUniquifierGenerator] but has failed to stop it. This is very likely to create a memory leak.

I had noticed that env.shutdown().toBlocking().single(); //is marked as deprecated.

Do you think it is related?
By the way, what should I use instead of it?

My environment is the same as described above with the libs updated.

Thanks.

simonbasle · December 16, 2015, 9:05am

Hi @mcarvalho

The deprecated warning is fine, it is there to avoid someone doing just env.shutdown(), but in your case you are actually blocking on the call so it’s all fine. We’ll migrate shutdown to be blocking (not returning an Observable) so we have introduced shutdownAsync for the non-blocking semantics. Up to you if you want to use that or fix the code when it becomes blocking later on (probably not before 2.3).

The leak warning seems to be coming from Netty (and specifically RandomThreadLocal) . Not sure of the actual workaround there You do not use Netty do you? (just to check this is due to the SDK’s Netty)

mcarvalho · December 16, 2015, 2:01pm

@simonbasle sorry about the last one. I had updated the RXJava from snapshot to current 1.0.15 and it is working now without memory leaks logs. Unfortunately looks like the refresher continue working after shutdown the application it reconnect to our buckets in a blink of eyes.

Any ideia?