Thread: Deadlock {JStack, JConsole}

Originally Posted by RusePS

Hello there.

I'm currently having a deadlock issue and I'm wondering if anyone can give me any suggestions on how to track it down, since I have tried everything.
JConsole isn't helping, and JStack prints this out:

Code:

)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject
.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.tak
e(ScheduledThreadPoolExecutor.java:1093)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.tak
e(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.ja
va: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)

"RMI TCP Connection(1)-ip address " #21 daemon prio=5 os_prio=0 tid=0x0000000
01b3c9800 nid=0xb60 runnable [0x000000001d28e000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:170)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
        - locked <0x0000000707d2b2a8> (a java.io.BufferedInputStream)
        at java.io.FilterInputStream.read(FilterInputStream.java:83)
        at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:5
50)
        at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTranspor
t.java:826)
        at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$254(T
CPTransport.java:683)
        at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$$Lambda$27/13548
43628.run(Unknown Source)
        at java.security.AccessController.doPrivileged(Native Method)
        at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport
.java:682)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.
java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor
.java:617)
        at java.lang.Thread.run(Thread.java:745)

"RMI TCP Accept-0" #20 daemon prio=5 os_prio=0 tid=0x000000001a82f800 nid=0xdb8
runnable [0x000000001d18e000]
   java.lang.Thread.State: RUNNABLE
        at java.net.DualStackPlainSocketImpl.accept0(Native Method)
        at java.net.DualStackPlainSocketImpl.socketAccept(DualStackPlainSocketIm
pl.java:131)
        at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:
404)
        at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:199)
        - locked <0x0000000707965708> (a java.net.SocksSocketImpl)
        at java.net.ServerSocket.implAccept(ServerSocket.java:545)
        at java.net.ServerSocket.accept(ServerSocket.java:513)
        at sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRM
IServerSocketFactory.java:52)
        at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTr
ansport.java:400)
        at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:3
72)
        at java.lang.Thread.run(Thread.java:745)

"Hashed wheel timer #1" #16 prio=5 os_prio=0 tid=0x000000001b475000 nid=0x14c wa
iting on condition [0x000000001ce8e000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
        at java.lang.Thread.sleep(Native Method)
        at org.jboss.netty.util.HashedWheelTimer$Worker.waitForNextTick(HashedWh
eelTimer.java:464)
        at org.jboss.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.jav
a:373)
        at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnabl
e.java:102)
        at java.lang.Thread.run(Thread.java:745)

"DestroyJavaVM" #19 prio=5 os_prio=0 tid=0x0000000002340800 nid=0x430 waiting on
 condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"GameThread" #18 prio=10 os_prio=2 tid=0x000000001b258000 nid=0xde0 waiting on c
ondition [0x000000001cd8f000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007051fca50> (a java.util.concurrent.lock
s.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject
.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.tak
e(ScheduledThreadPoolExecutor.java:1081)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.tak
e(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.ja
va: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)

"New I/O server boss #1 ([id: 0x5afa203f, /0:0:0:0:0:0:0:0:13377])" #17 prio=5 o
s_prio=0 tid=0x000000001b257800 nid=0x40c runnable [0x000000001cc8e000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.j
ava:296)
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(WindowsSelector
Impl.java:278)
        at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:159)

        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        - locked <0x00000007051fd738> (a sun.nio.ch.Util$2)
        - locked <0x00000007051fd728> (a java.util.Collections$UnmodifiableSet)
        - locked <0x00000007051fd258> (a sun.nio.ch.WindowsSelectorImpl)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101)
        at org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink$Boss.r
un(NioServerSocketPipelineSink.java:231)
        at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnabl
e.java:102)
        at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProof
Worker.java:42)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.
java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor
.java:617)
        at java.lang.Thread.run(Thread.java:745)

"New I/O  worker #4" #15 prio=5 os_prio=0 tid=0x000000001ad6f000 nid=0x864 runna
ble [0x000000001c98f000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.j
ava:296)
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(WindowsSelector
Impl.java:278)
        at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:159)

        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        - locked <0x00000007053d8888> (a sun.nio.ch.Util$2)
        - locked <0x00000007053d8878> (a java.util.Collections$UnmodifiableSet)
        - locked <0x00000007053d8718> (a sun.nio.ch.WindowsSelectorImpl)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at org.jboss.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.j
ava:64)
        at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioW
orker.java:244)
        at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:35)
        at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnabl
e.java:102)
        at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProof
Worker.java:42)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.
java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor
.java:617)
        at java.lang.Thread.run(Thread.java:745)

"New I/O  worker #3" #14 prio=5 os_prio=0 tid=0x000000001ad6b800 nid=0xca0 runna
ble [0x000000001c88e000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.j
ava:296)
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(WindowsSelector
Impl.java:278)
        at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:159)

        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        - locked <0x0000000705204fb0> (a sun.nio.ch.Util$2)
        - locked <0x0000000705204fa0> (a java.util.Collections$UnmodifiableSet)
        - locked <0x0000000705204e50> (a sun.nio.ch.WindowsSelectorImpl)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at org.jboss.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.j
ava:64)
        at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioW
orker.java:244)
        at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:35)
        at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnabl
e.java:102)
        at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProof
Worker.java:42)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.
java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor
.java:617)
        at java.lang.Thread.run(Thread.java:745)

"New I/O  worker #2" #13 prio=5 os_prio=0 tid=0x000000001af70800 nid=0x5b8 runna
ble [0x000000001c78f000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.j
ava:296)
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(WindowsSelector
Impl.java:278)
        at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:159)

        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        - locked <0x0000000705208a08> (a sun.nio.ch.Util$2)
        - locked <0x00000007052089f8> (a java.util.Collections$UnmodifiableSet)
        - locked <0x00000007052088a8> (a sun.nio.ch.WindowsSelectorImpl)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at org.jboss.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.j
ava:64)
        at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioW
orker.java:244)
        at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:35)
        at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnabl
e.java:102)
        at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProof
Worker.java:42)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.
java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor
.java:617)
        at java.lang.Thread.run(Thread.java:745)

"New I/O  worker #1" #12 prio=5 os_prio=0 tid=0x000000001af6f800 nid=0x7fc runna
ble [0x000000001a9de000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.j
ava:296)
        at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(WindowsSelector
Impl.java:278)
        at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:159)

        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        - locked <0x0000000705201558> (a sun.nio.ch.Util$2)
        - locked <0x0000000705201548> (a java.util.Collections$UnmodifiableSet)
        - locked <0x00000007052013f8> (a sun.nio.ch.WindowsSelectorImpl)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at org.jboss.netty.channel.socket.nio.SelectorUtil.select(SelectorUtil.j
ava:64)
        at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioW
orker.java:244)
        at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:35)
        at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnabl
e.java:102)
        at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProof
Worker.java:42)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.
java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor
.java:617)
        at java.lang.Thread.run(Thread.java:745)

"Service Thread" #8 daemon prio=9 os_prio=0 tid=0x0000000019216800 nid=0xdf0 run
nable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread1" #7 daemon prio=9 os_prio=2 tid=0x00000000191ac000 nid=0xdb4
 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #6 daemon prio=9 os_prio=2 tid=0x00000000191a8800 nid=0xcb8
 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x00000000191a7000 nid=0xaf0 wa
iting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x000000000243e000 nid=0xd4c
runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x0000000002432800 nid=0xeb4 in Objec
t.wait() [0x0000000019edf000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000007038d0650> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
        - locked <0x00000007038d0650> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x000000000242a000 nid=0xdfc
 in Object.wait() [0x0000000019dde000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:502)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:157)
        - locked <0x00000007038d0620> (a java.lang.ref.Reference$Lock)

"VM Thread" os_prio=2 tid=0x0000000019176000 nid=0x960 runnable

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x0000000002356000 nid=0xbdc runna
ble

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x0000000002357800 nid=0x6ac runna
ble

"VM Periodic Task Thread" os_prio=2 tid=0x000000001921b800 nid=0x8c8 waiting on
condition

JNI global references: 345

Press any key to continue . . .

And I don't really know how to translate that, lol. Any help would be nice.

Thanks!

"RMI TCP Connection(1)-IP-ADDRESS" Theres your IP unless its somebody on your server. Might wanna remove that. Also what do you do that causes the deadlock? Command? Object click? Logging in?

Originally Posted by RusePS

Thanks!

I've tried everything, but the deadlock occurs at complete random. Even when people are just chilling at home.
Worth to mention there are no global tasks going on such as "global messages" either, so that's why this is so hard.

Hmm..check the process method in client.java..

I'm assuming this is PI?

Originally Posted by RusePS

Nah, it's a custom framework, haha.

Main:

Code:

public static void main(String[] params) {
		Runtime.getRuntime().addShutdownHook(new ShutdownHook());
		try {
			
			logger.info("Initializing the loader...");
            GameLoader loader = new GameLoader(GameSettings.GAME_PORT);
            loader.init();
            loader.bind();
            loader.finish();
            logger.info("The loader has finished, RusePS is now online on port "+GameSettings.GAME_PORT+"!");
            
		} catch (Exception ex) {
			logger.log(Level.SEVERE, "Could not start Ruse! Program terminated.", ex);
			System.exit(1);
		}
	}

Loader:

Code:

private final ExecutorService serviceLoader = Executors.newSingleThreadExecutor(new ThreadFactoryBuilder().setNameFormat("GameLoadingThread").build());
	private final int port;

	protected GameLoader(int port) {
		this.port = port;
	}

	public void init() {
		Preconditions.checkState(!serviceLoader.isShutdown(), "The bootstrap has been bound already!");
		executeServiceLoad();
		serviceLoader.shutdown();
	}

	public void bind() throws Exception {
		if (!serviceLoader.awaitTermination(15, TimeUnit.MINUTES))
			throw new IllegalStateException("The background service load took too long!");
		ServerBootstrap serverBootstrap = new ServerBootstrap (new NioServerSocketChannelFactory(Executors.newCachedThreadPool(), Executors.newCachedThreadPool()));
		serverBootstrap.setPipelineFactory (new PipelineFactory(new HashedWheelTimer()));
		serverBootstrap.bind(new InetSocketAddress(port));
	}
	
	public void finish() {
		GameEngine.start();
		GameServer.getLogger().info("The engine is now running!");
	}

	private void executeServiceLoad() {
		serviceLoader.execute(() -> ConnectionDenyManager.init());
		serviceLoader.execute(() -> PlayerPunishment.init());
		serviceLoader.execute(() -> StarterSaver.init());
		serviceLoader.execute(() -> GameObjectDefinition.init());
		serviceLoader.execute(() -> RegionClipping.init());
		serviceLoader.execute(() -> CustomObjects.init());
		serviceLoader.execute(() -> ItemDefinition.init());
		serviceLoader.execute(() -> NpcDefinition.parseNpcs().load());
		serviceLoader.execute(() -> WeaponInterfaces.parseInterfaces().load());
		serviceLoader.execute(() -> ShopManager.parseShops().load());
		serviceLoader.execute(() -> NPC.parseNpcs());
		serviceLoader.execute(() -> NPCDrops.init());
		serviceLoader.execute(() -> DialogueManager.init());
		serviceLoader.execute(() -> Lottery.init());
		serviceLoader.execute(() -> Scoreboards.init());
		serviceLoader.execute(() -> DesoSpan.init());
		serviceLoader.execute(() -> PuroPuro.init());
		serviceLoader.execute(() -> ClanChatManager.init());
		serviceLoader.execute(() -> CombatPoisonData.loadPoisonData());
		if (GameSettings.MYSQL_ENABLED) {
			serviceLoader.execute(() -> MySQLController.init());
		}
	}

Engine:

Code:

private static ScheduledExecutorService gameExecutor = Executors.newSingleThreadScheduledExecutor(
			new ThreadFactoryBuilder().setNameFormat("GameThread").setPriority(Thread.MAX_PRIORITY).build());

	public static void init() {
		gameExecutor.scheduleAtFixedRate(new GameEngine(), 0, 600, TimeUnit.MILLISECONDS);
		TaskManager.submit(new MinigamesProcessorTask());
	}

	@Override
	public void run() {
		try {

			World.sequence();

		} catch (Exception e) {
			e.printStackTrace();
			World.savePlayers();
		}
	}

	private GameEngine() {}

As you can see it's running everything on the "GameThread". Should I perhaps make a simple task to process the world instead..?

Hmm, I am sorry but I am not that advanced in java to see how a custom framework works, let alone java networking. Sorry again. At least I helped mask you public IP.