Linu
Linu

Reputation: 68

Tomcat 8 memory leak warning when stopping Tomcat

Implementing a small Microservice Architecture there is the following System-Architecture:

2 Tomcat8 instances running on the same machine, InstanceA on port 8080 and InstanceB on port 8081.

They are connected via Websocket-connection (javax.websocket.server.ServerEndpoint),

InstanceA is the Websocket-Client and InstanceB is the WebSocketServer. Implementing the ServletContextListener Interface the contextInitialized(ServletContextEvent arg0) Method gets invoked on tomcat startup.When this method gets invoked, I open the Websocket Connection to the WebSocketServer via

ContainerProvider.getWebSocketContainer().connectToServer(MyClientEndpoint.class, new URI(arService.getProtocol() + "://" + arService.getIp() + ":" + arService.getPort() + arService.getEndPointUrl()));

Connecting works perfectly fine but when I shutdown InstanceA I get the following StackTrace:

WARNING: The web application [AuronGateway] appears to have started a thread named [Thread-5] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 sun.misc.Unsafe.park(Native Method)
 java.util.concurrent.locks.LockSupport.park(Unknown Source)
 java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Unknown Source)
 java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source)
 java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source)
 java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source)
 java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
 java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
 java.lang.Thread.run(Unknown Source)

The curious thing is that I get this warning only on Microsoft Windows(tested it on Win7 and Win10 - same warning) using Oracle JDK. When deploying the same Code on Ubuntu14.04 with OpenJDK I don't get the Warning. I use Eclipse for deploying the WebApplication and Java 8 / Tomcat8 on both Systems.

While debugging the application I noticed that the websocket-Connection gets closed correctly.

edit: on the websocketServer-Side(InstanceB) I get the following Exception in onError Method:

java.io.IOException: Eine vorhandene Verbindung wurde vom Remotehost geschlossen
    at sun.nio.ch.SocketDispatcher.write0(Native Method)
    at sun.nio.ch.SocketDispatcher.write(Unknown Source)
    at sun.nio.ch.IOUtil.writeFromNativeBuffer(Unknown Source)
    at sun.nio.ch.IOUtil.write(Unknown Source)
    at sun.nio.ch.SocketChannelImpl.write(Unknown Source)
    at org.apache.tomcat.util.net.NioChannel.write(NioChannel.java:124)
    at org.apache.tomcat.util.net.NioSelectorPool.write(NioSelectorPool.java:183)
    at org.apache.coyote.http11.upgrade.NioServletOutputStream.doWriteInternal(NioServletOutputStream.java:94)
    at org.apache.coyote.http11.upgrade.NioServletOutputStream.doWrite(NioServletOutputStream.java:61)
    at org.apache.coyote.http11.upgrade.AbstractServletOutputStream.writeInternal(AbstractServletOutputStream.java:165)
    at org.apache.coyote.http11.upgrade.AbstractServletOutputStream.write(AbstractServletOutputStream.java:132)
    at org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.onWritePossible(WsRemoteEndpointImplServer.java:99)
    at org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.doWrite(WsRemoteEndpointImplServer.java:80)
    at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.writeMessagePart(WsRemoteEndpointImplBase.java:452)
    at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessage(WsRemoteEndpointImplBase.java:340)
    at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessageBlock(WsRemoteEndpointImplBase.java:272)
    at org.apache.tomcat.websocket.WsSession.sendCloseMessage(WsSession.java:586)
    at org.apache.tomcat.websocket.WsSession.doClose(WsSession.java:488)
    at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.onError(WsHttpUpgradeHandler.java:150)
    at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.access$300(WsHttpUpgradeHandler.java:48)
    at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListener.onError(WsHttpUpgradeHandler.java:211)
    at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListener.onDataAvailable(WsHttpUpgradeHandler.java:194)
    at org.apache.coyote.http11.upgrade.AbstractServletInputStream.onDataAvailable(AbstractServletInputStream.java:198)
    at org.apache.coyote.http11.upgrade.AbstractProcessor.upgradeDispatch(AbstractProcessor.java:96)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:647)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1500)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1456)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Unknown Source)

edit2: I found out that when only connecting to the websocket-Server the warning doesn't apper. It appears only when sending some text via

session.getBasicRemote().sendText("TestMessage");

edit3: setting up a Testproject that is the implementation of the WebSocketClient:
Startup.java

package de.test.client;

import java.io.IOException;
import java.net.URI;
import java.net.URISyntaxException;

import javax.servlet.ServletContextEvent;
import javax.servlet.ServletContextListener;
import javax.websocket.ContainerProvider;
import javax.websocket.DeploymentException;
import javax.websocket.Session;

public class Startup implements ServletContextListener
{
    Session session = null;
    @Override
    public void contextDestroyed(ServletContextEvent arg0) {
        System.out.println("stopped Session");
    }

    @Override
    public void contextInitialized(ServletContextEvent arg0) {
        System.out.println("try to establish Connection");
            try {
                this.session = ContainerProvider.getWebSocketContainer().connectToServer(TestClient.class,
                        new URI("ws://127.0.0.1:8081/TestServer/wsEndMessageBroker"));

                session.getBasicRemote().sendText("Hello WebsocketServer");
            } catch (DeploymentException e) {
                // TODO Auto-generated catch block
                e.printStackTrace();
            } catch (IOException e) {
                // TODO Auto-generated catch block
                e.printStackTrace();
            } catch (URISyntaxException e) {
                // TODO Auto-generated catch block
                e.printStackTrace();
            }
    }
}

TestClient.java

package de.test.client;

import javax.websocket.ClientEndpoint;
import javax.websocket.CloseReason;
import javax.websocket.OnClose;
import javax.websocket.OnError;
import javax.websocket.OnMessage;
import javax.websocket.OnOpen;
import javax.websocket.Session;

@ClientEndpoint
public class TestClient {

        @OnOpen
        public void onOpen(final Session userSession)
        {
            System.out.println("Connection established");
        }

        @OnClose
        public void onClose(final Session userSession, final CloseReason reason)
        {
            System.out.println("close am Clientendpoint(MessageBroker-Service)");
        }

        @OnMessage
        public void onMessage(String jsonMessage)
        {
            System.out.println("message: " + jsonMessage);
        }
        @OnError
        public void onError(Throwable error)
        {
            error.printStackTrace();
        }
}

WebSocketServer:

TestServer.java

package de.test.server;

import javax.websocket.OnClose;
import javax.websocket.OnError;
import javax.websocket.OnMessage;
import javax.websocket.OnOpen;
import javax.websocket.Session;
import javax.websocket.server.ServerEndpoint;

@ServerEndpoint("/wsEndMessageBroker")
public class TestServer
{
    public TestServer()
    {
        System.out.println("TestServer started");
    }

    @OnOpen
    public void onOpen(Session session)
    {
        System.out.println("New Connection established SessionID: " + session.getId());
    }

    @OnMessage
    public void message(Session session, String jsonMessage)
    {
        System.out.println("new Message: " + jsonMessage);
    }
    @OnClose
    public void onClose(Session session)
    {
        System.out.println("Closed Connection: " + session.getId());
    }
    @OnError
    public void onError(Throwable error)
    {
        error.printStackTrace();
        System.out.println("Connection were closed unexpected");
    }
}

Log ClientSide

INFORMATION: Initializing ProtocolHandler ["http-nio-8080"]
Feb 12, 2016 9:54:29 AM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
INFORMATION: Using a shared selector for servlet write/read
Feb 12, 2016 9:54:29 AM org.apache.coyote.AbstractProtocol init
INFORMATION: Initializing ProtocolHandler ["ajp-nio-8009"]
Feb 12, 2016 9:54:29 AM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
INFORMATION: Using a shared selector for servlet write/read
Feb 12, 2016 9:54:29 AM org.apache.catalina.startup.Catalina load
INFORMATION: Initialization processed in 787 ms
Feb 12, 2016 9:54:29 AM org.apache.catalina.core.StandardService startInternal
INFORMATION: Starting service Catalina
Feb 12, 2016 9:54:29 AM org.apache.catalina.core.StandardEngine startInternal
INFORMATION: Starting Servlet Engine: Apache Tomcat/8.0.32
Feb 12, 2016 9:54:30 AM org.apache.jasper.servlet.TldScanner scanJars
INFORMATION: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Feb 12, 2016 9:54:30 AM org.apache.jasper.servlet.TldScanner scanJars
INFORMATION: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Versuche Verbindung aufzubauen
Connection established
Feb 12, 2016 9:54:30 AM org.apache.coyote.AbstractProtocol start
INFORMATION: Starting ProtocolHandler ["http-nio-8080"]
Feb 12, 2016 9:54:30 AM org.apache.coyote.AbstractProtocol start
INFORMATION: Starting ProtocolHandler ["ajp-nio-8009"]
Feb 12, 2016 9:54:30 AM org.apache.catalina.startup.Catalina start
INFORMATION: Server startup in 956 ms
Feb 12, 2016 9:54:34 AM org.apache.catalina.core.StandardServer await
INFORMATION: A valid shutdown command was received via the shutdown port. Stopping the Server instance.
Feb 12, 2016 9:54:34 AM org.apache.coyote.AbstractProtocol pause
INFORMATION: Pausing ProtocolHandler ["http-nio-8080"]
Feb 12, 2016 9:54:34 AM org.apache.coyote.AbstractProtocol pause
INFORMATION: Pausing ProtocolHandler ["ajp-nio-8009"]
Feb 12, 2016 9:54:34 AM org.apache.catalina.core.StandardService stopInternal
INFORMATION: Stopping service Catalina
stopped Session
Feb 12, 2016 9:54:34 AM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
WARNUNG: The web application [TestClient] appears to have started a thread named [Thread-5] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 sun.misc.Unsafe.park(Native Method)
 java.util.concurrent.locks.LockSupport.park(Unknown Source)
 java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Unknown Source)
 java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source)
 java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(Unknown Source)
 java.util.concurrent.ThreadPoolExecutor.getTask(Unknown Source)
 java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
 java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
 java.lang.Thread.run(Unknown Source)
Feb 12, 2016 9:54:34 AM org.apache.coyote.AbstractProtocol stop
INFORMATION: Stopping ProtocolHandler ["http-nio-8080"]
Feb 12, 2016 9:54:34 AM org.apache.coyote.AbstractProtocol stop
INFORMATION: Stopping ProtocolHandler ["ajp-nio-8009"]
Feb 12, 2016 9:54:34 AM org.apache.coyote.AbstractProtocol destroy
INFORMATION: Destroying ProtocolHandler ["http-nio-8080"]
Feb 12, 2016 9:54:34 AM org.apache.coyote.AbstractProtocol destroy
INFORMATION: Destroying ProtocolHandler ["ajp-nio-8009"]

Log ServerSide

Feb 12, 2016 9:54:26 AM org.apache.coyote.AbstractProtocol init
INFORMATION: Initializing ProtocolHandler ["http-nio-8081"]
Feb 12, 2016 9:54:26 AM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
INFORMATION: Using a shared selector for servlet write/read
Feb 12, 2016 9:54:26 AM org.apache.coyote.AbstractProtocol init
INFORMATION: Initializing ProtocolHandler ["ajp-nio-8010"]
Feb 12, 2016 9:54:26 AM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
INFORMATION: Using a shared selector for servlet write/read
Feb 12, 2016 9:54:26 AM org.apache.catalina.startup.Catalina load
INFORMATION: Initialization processed in 992 ms
Feb 12, 2016 9:54:26 AM org.apache.catalina.core.StandardService startInternal
INFORMATION: Starting service Catalina
Feb 12, 2016 9:54:26 AM org.apache.catalina.core.StandardEngine startInternal
INFORMATION: Starting Servlet Engine: Apache Tomcat/8.0.32
Feb 12, 2016 9:54:27 AM org.apache.jasper.servlet.TldScanner scanJars
INFORMATION: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Feb 12, 2016 9:54:27 AM org.apache.jasper.servlet.TldScanner scanJars
INFORMATION: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Feb 12, 2016 9:54:27 AM org.apache.coyote.AbstractProtocol start
INFORMATION: Starting ProtocolHandler ["http-nio-8081"]
Feb 12, 2016 9:54:27 AM org.apache.coyote.AbstractProtocol start
INFORMATION: Starting ProtocolHandler ["ajp-nio-8010"]
Feb 12, 2016 9:54:27 AM org.apache.catalina.startup.Catalina start
INFORMATION: Server startup in 895 ms
TestServer started
New Connection established SessionID: 0
new Message: Hello WebsocketServer
java.io.IOException: Unable to write the complete message as the WebSocket connection has been closed
    at org.apache.tomcat.websocket.WsSession.registerFuture(WsSession.java:664)
    at org.apache.tomcat.websocket.FutureToSendHandler.get(FutureToSendHandler.java:92)
    at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessageBlock(WsRemoteEndpointImplBase.java:277)
    at org.apache.tomcat.websocket.WsSession.sendCloseMessage(WsSession.java:586)
    at org.apache.tomcat.websocket.WsSession.doClose(WsSession.java:488)
    at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.onError(WsHttpUpgradeHandler.java:150)
    at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.access$300(WsHttpUpgradeHandler.java:48)
    at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListener.onError(WsHttpUpgradeHandler.java:211)
    at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListener.onDataAvailable(WsHttpUpgradeHandler.java:194)
    at org.apache.coyote.http11.upgrade.AbstractServletInputStream.onDataAvailable(AbstractServletInputStream.java:198)
    at org.apache.coyote.http11.upgrade.AbstractProcessor.upgradeDispatch(AbstractProcessor.java:96)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:647)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1500)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1456)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Unknown Source)
Connection were closed unexpected
Closed Connection: 0
java.io.IOException: Eine vorhandene Verbindung wurde vom Remotehost geschlossen
    at sun.nio.ch.SocketDispatcher.read0(Native Method)
    at sun.nio.ch.SocketDispatcher.read(Unknown Source)
    at sun.nio.ch.IOUtil.readIntoNativeBuffer(Unknown Source)
    at sun.nio.ch.IOUtil.read(Unknown Source)
    at sun.nio.ch.SocketChannelImpl.read(Unknown Source)
    at org.apache.tomcat.util.net.NioChannel.read(NioChannel.java:137)
    at org.apache.coyote.http11.upgrade.NioServletInputStream.fillReadBuffer(NioServletInputStream.java:136)
    at org.apache.coyote.http11.upgrade.NioServletInputStream.doRead(NioServletInputStream.java:80)
    at org.apache.coyote.http11.upgrade.AbstractServletInputStream.read(AbstractServletInputStream.java:124)
    at org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFrameServer.java:60)
    at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListener.onDataAvailable(WsHttpUpgradeHandler.java:186)
    at org.apache.coyote.http11.upgrade.AbstractServletInputStream.onDataAvailable(AbstractServletInputStream.java:198)
    at org.apache.coyote.http11.upgrade.AbstractProcessor.upgradeDispatch(AbstractProcessor.java:96)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:647)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1500)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1456)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Unknown Source)
Connection were closed unexpected

Upvotes: 2

Views: 5174

Answers (1)

eztam
eztam

Reputation: 3829

The stack trace says that there was a Thread created with the name "Thread-5" that has not stopped when the application has shut down. This could maybe just considered as warning since tomcat is able to handle such problems . But it could also be the cause of a memory leak, when you don't restart your tomcat each time after you redeploy your application.

You could set a conditional breakpoint in the java.lang.Thread class in order to find out from where the Thread with name "Thread-5" was created. After you've found the creator of the thread, you can investigate how to gracefully shutdown the component that created this thread.

The shutdown functionality could be placed into the contextDestroyed() method of a ServletContextListener or in a method with the Spring @PreDestroy annotation.

Upvotes: 3

Related Questions