Bug 1297930

Summary:	RemoteCacheManager.stop() takes a while to complete and logs exception
Product:	[JBoss] JBoss Data Grid 6	Reporter:	Adrian Nistor <anistor>
Component:	Infinispan	Assignee:	Tristan Tarrant <ttarrant>
Status:	VERIFIED ---	QA Contact:	Martin Gencur <mgencur>
Severity:	unspecified	Docs Contact:
Priority:	unspecified
Version:	6.6.0	CC:	jdg-bugs, pzapataf, vjuranek
Target Milestone:	CR2
Target Release:	6.6.0
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:		Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Adrian Nistor 2016-01-12 19:35:03 UTC

This only happens if a cache had any listeners.
RCM.stop() waits for a while then it logs the exception below on WARN level.
I was able to reproduce this using the SnowReport app in remote-query quickstart.

This seems related to ISPN-5727 but there is more to it because just backporting ISPN-5727 does not solve it.

Available actions:
0. Display available actions
1. Add/update forecast
2. Remove forecast
3. Add continuous query listener
4. Remove continuous query listener
5. Display snow report
6. Display all cache entries
7. Clear cache
8. Quit

> 3
Continuous query listener added.
> 4
Continuous query listener removed.
> 8
Bye!
Jan 12, 2016 9:23:08 PM org.infinispan.client.hotrod.event.ClientListenerNotifier$EventDispatcher run
WARN: ISPN004039: Unable to complete reading event from server null
java.nio.channels.IllegalBlockingModeException
	at sun.nio.ch.SocketAdaptor$SocketInputStream.read(SocketAdaptor.java:201)
	at sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103)
	at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
	at org.infinispan.client.hotrod.impl.transport.tcp.TcpTransport.readByte(TcpTransport.java:179)
	at org.infinispan.client.hotrod.impl.protocol.Codec20.readMagic(Codec20.java:305)
	at org.infinispan.client.hotrod.impl.protocol.Codec20.readEvent(Codec20.java:148)
	at org.infinispan.client.hotrod.event.ClientListenerNotifier$EventDispatcher.run(ClientListenerNotifier.java:251)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)

Comment 2 Vojtech Juranek 2016-01-12 23:13:52 UTC

Adrian, are you sure backporting ISPN-5727 doesn't solve the issue? Maybe you hit slightly different issue (I observe only the delay when RCM is stopped, but without any IllegalBlockingModeException), but proper executor shutdown solved the issue for me (i.e. it stops immediately now).

Could you post here a stack trace of client-listener thread?

What I see is bellow - it waits for executor stop:

"Client-Listener-83948a9fa8ea4b4d" #13 prio=5 os_prio=0 tid=0x00007f6a14628000 nid=0x1af9 waiting on condition [0x00007f6a55763000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000dc0cb680> (a java.util.concurrent.SynchronousQueue$TransferStack)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
        at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
        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)

Comment 3 Adrian Nistor 2016-01-13 09:17:09 UTC

When running with jdk 7 I still see IllegalBlockingModeException. With 8 I don't.
To solve IllegalBlockingModeException I added another commit, see here: https://github.com/infinispan/jdg/pull/849