[jira] [Commented] (AMQ-5888) Transport Connection to: tcp://127.0.0.1:41062 failed: java.io.EOFException shows up in log when closing connection normally

["Ganesh (JIRA)" <ji...@apache.org>]

    [ https://issues.apache.org/jira/browse/AMQ-5888?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14628027#comment-14628027 ] 

Ganesh commented on AMQ-5888:
-----------------------------

The log message is output from the public void serviceTransportException(IOException e) method of the org.apache.activemq.broker.TransportConnection class only if the stopping and the pendingStop flags have not been already set before the serviceTransportException(IOException e)  is called as seen from the following code snippet - 

        if (!stopping.get() && !pendingStop) {
            transportException.set(e);
            if (TRANSPORTLOG.isDebugEnabled()) {
                TRANSPORTLOG.debug(this + " failed: " + e, e);
            } else if (TRANSPORTLOG.isWarnEnabled() && !expected(e)) {
                TRANSPORTLOG.warn(this + " failed: " + e);   //--> This is where the WARN is written to the log.
            }
            stopAsync(e);
        }

Sequence of events - 
1. The close() method on the ActiveMQConnection sends a ShutdownInfo to the server and immediately closes the socket from the client side. 
2. The broker's TcpTransportConnection is handling this ShutdownInfo but it so happens that the Inactivity monitor also fires off a write to the closed socket and fails with an EOFException or SocketException.
3. The public void stopAsync() in the org.apache.activemq.broker.jmx.ManagedTransportConnection makes a call to unregister the MBeans and then sets the  stopping flag. The latency involved in unregistering the beans is causing the stopping flag to not be set in time, so the WARN message is caused. 

Moving the stopping flag to be set before the unregister bean call should set the stopping flag to be set and prevent the WARN message from being written to the log.

I have attached a patch a test.

Thanks.

> Transport Connection to: tcp://127.0.0.1:41062 failed: java.io.EOFException shows up in log when closing connection normally
> ----------------------------------------------------------------------------------------------------------------------------
>
>                 Key: AMQ-5888
>                 URL: https://issues.apache.org/jira/browse/AMQ-5888
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: JMS client
>    Affects Versions: 5.11.1
>            Reporter: Ganesh
>            Priority: Minor
>
> Closing an ActiveMQConnection by calling the close() method caused the following warning message to show in the log
> 17:59:05,384 | WARN  | org.apache.activemq.broker.TransportConnection:245 Transport Connection to: tcp://127.0.0.1:41062 failed: java.io.EOFException
> This exception is harmless but this WARN message appears repeatedly in the logs which is a source of false alarm.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)