Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Clean up connections after connection closed #504

Closed
vikulin opened this issue Jun 15, 2017 · 20 comments
Closed

Clean up connections after connection closed #504

vikulin opened this issue Jun 15, 2017 · 20 comments

Comments

@vikulin
Copy link

vikulin commented Jun 15, 2017

I do believe this method should also clean up connections since its closed. I see only

conn.close( CloseFrame.ABNORMAL_CLOSE );

and nothing about cleaning up.

/**
 * Start the connection lost timer
 */
protected void startConnectionLostTimer() {
    if (this.connectionLostTimeout <= 0) {
        if (WebSocketImpl.DEBUG)
            System.out.println("Connection lost timer deactivated");
        return;
    }
    if (WebSocketImpl.DEBUG)
        System.out.println("Connection lost timer started");
    cancelConnectionLostTimer();
    connectionLostTimer = new Timer();
    connectionLostTimerTask = new TimerTask() {
        @Override
        public void run() {
            Collection<WebSocket> con = connections();
            synchronized ( con ) {
                long current = (System.currentTimeMillis()-(connectionLostTimeout * 1500));
                for( WebSocket conn : con ) {
                    if (conn instanceof WebSocketImpl) {
                        if( ((WebSocketImpl)conn).getLastPong() < current ) {
                            if (WebSocketImpl.DEBUG)
                                System.out.println("Closing connection due to no pong received: " + conn.toString());
                            conn.close( CloseFrame.ABNORMAL_CLOSE );
                        } else {
                            conn.sendPing();
                        }
                    }
                }
            }
        }
    };
    connectionLostTimer.scheduleAtFixedRate( connectionLostTimerTask,connectionLostTimeout * 1000, connectionLostTimeout * 1000 );
}
@marci4
Copy link
Collaborator

marci4 commented Jun 15, 2017

Hello @vikulin,

first of all thank you for your input.

Actually most of the time the connection is actually cleaned up by the IOException (remote closed connection). This is for sure cleaning up the connection!

Apart from this conn.close() should also close the connection and clean everything up! (Tested it with replacing conn.sendPing() with conn.close( CloseFrame.ABNORMAL_CLOSE ); and cleaned it up as well)

Do you have any situation when the connection is not cleaned up?

Greetings
marci4

@vikulin
Copy link
Author

vikulin commented Jun 15, 2017

Yes, I have. My app throws every time:

Closing connection due to no pong received: org.java_websocket.WebSocketImpl

Closing connection due to no pong received: org.java_websocket.WebSocketImpl@22cc90ed
Closing connection due to no pong received: org.java_websocket.WebSocketImpl@1b3ca737
Closing connection due to no pong received: org.java_websocket.WebSocketImpl@6de0c2fd

19:43:34.515 INFO [etherpush] New block: #3877720 (c170ca <~ ee2724) Txs:0, Unc: 0
19:43:37.515 INFO [etherpush] New block: #3877721 (eadfa0 <~ c170ca) Txs:20, Unc: 0
19:43:38.390 INFO [etherpush] New block: #3877722 (5095fb <~ eadfa0) Txs:32, Unc: 0
19:43:43.453 INFO [etherpush] New block: #3877723 (d4c9eb <~ 5095fb) Txs:194, Unc: 0
19:43:47.578 INFO [etherpush] New block: #3877724 (6d629b <~ d4c9eb) Txs:217, Unc: 0
19:43:53.796 INFO [etherpush] New block: #3877725 (17c481 <~ 6d629b) Txs:101, Unc: 0
19:44:07.953 INFO [etherpush] New block: #3877726 (18d0be <~ 17c481) Txs:219, Unc: 0
Closing connection due to no pong received: org.java_websocket.WebSocketImpl@22cc90ed
Closing connection due to no pong received: org.java_websocket.WebSocketImpl@1b3ca737
Closing connection due to no pong received: org.java_websocket.WebSocketImpl@6de0c2fd

19:44:58.031 INFO [etherpush] New block: #3877727 (fecf73 <~ 18d0be) Txs:105, Unc: 0
19:45:00.937 INFO [etherpush] New block: #3877728 (fc2a19 <~ fecf73) Txs:0, Unc: 0
19:45:09.015 INFO [etherpush] New block: #3877729 (fdfb3e <~ fc2a19) Txs:146, Unc: 0
19:45:16.047 INFO [etherpush] New block: #3877730 (90d5b7 <~ fdfb3e) Txs:47, Unc: 0
Closing connection due to no pong received: org.java_websocket.WebSocketImpl@22cc90ed
Closing connection due to no pong received: org.java_websocket.WebSocketImpl@1b3ca737
Closing connection due to no pong received: org.java_websocket.WebSocketImpl@6de0c2fd

19:45:38.578 INFO [etherpush] New block: #3877731 (92c453 <~ 90d5b7) Txs:139, Unc: 0
19:45:40.234 INFO [etherpush] New block: #3877731 (11a58d <~ 90d5b7) Txs:200, Unc: 0
19:46:06.406 INFO [etherpush] New block: #3877732 (2a889c <~ 92c453) Txs:174, Unc: 1
19:46:25.765 INFO [etherpush] New block: #3877733 (d4a26c <~ 2a889c) Txs:140, Unc: 0

@marci4
Copy link
Collaborator

marci4 commented Jun 15, 2017

Hello @vikulin,

Well that should not happen oO.

I suppose you use Android. With which versions do you have this problem?
Are you using wss? or normal ws?

Greetings
marci4

@vikulin
Copy link
Author

vikulin commented Jun 15, 2017

No, I'm using your lib in desktop app under windows deployed into Apache tomcat servlet container.

JDK 1.8, Windows 10 x86_64,

I save your connection into a Map for a further broadcast in Ethereum messenger. This is a server side part of the messenger.

Here is a client side where I receive these messages:
https://play.google.com/store/apps/details?id=org.vikulin.etherwallet

@marci4 marci4 removed the Android label Jun 15, 2017
@vikulin
Copy link
Author

vikulin commented Jun 15, 2017

Can you please point out where exactly you clean up connections Collection?

@marci4
Copy link
Collaborator

marci4 commented Jun 15, 2017

Hello @vikulin,

tested it with java 1.8.0_131 and its working...

The connection is getting cleaned up in the WebSocketServer onWebsocketClose() which is called by closeConnection().

Do you have a simple test application where I can reproduce it for sure?

Theoretically we could just use closeConnection() instead of close().

Greetings
marci4

@vikulin
Copy link
Author

vikulin commented Jun 16, 2017 via email

@vikulin
Copy link
Author

vikulin commented Jun 16, 2017

No need to run app. Let see on close sequence:

  1. class AbstractWebSocket: if( ((WebSocketImpl)conn).getLastPong() < current ) {
    if (WebSocketImpl.DEBUG)
    System.out.println("Closing connection due to no pong received: " + conn.toString());
    conn.close( CloseFrame.ABNORMAL_CLOSE );
    } else {
    conn.sendPing();
    }

  2. class WebSocketImpl private void close( int code, String message, boolean remote ) {
    if( readystate != READYSTATE.CLOSING && readystate != READYSTATE.CLOSED ) {
    if( readystate == READYSTATE.OPEN ) {
    if( code == CloseFrame.ABNORMAL_CLOSE ) {
    assert ( !remote );
    readystate = READYSTATE.CLOSING;
    flushAndClose( code, message, false );
    return;
    }...

  3. protected synchronized void flushAndClose( int code, String message, boolean remote ) {
    if( flushandclosestate ) {
    return;
    }
    closecode = code;
    closemessage = message;
    closedremotely = remote;

     flushandclosestate = true;
    
     wsl.onWriteDemand( this );
     try {
     	wsl.onWebsocketClosing( this, code, message, remote );
     } catch ( RuntimeException e ) {
     	wsl.onWebsocketError( this, e );
     }
     if( draft != null )
     	draft.reset();
     handshakerequest = null;
    

    }

Actually flushAndClose method does not contain Collections clean up as you mentioned.

@marci4
Copy link
Collaborator

marci4 commented Jun 16, 2017

Well for me it is still very interesting why the selector is not waking up and we get no IOException in the runnable...

@vikulin
Copy link
Author

vikulin commented Jun 16, 2017 via email

@marci4
Copy link
Collaborator

marci4 commented Jun 16, 2017

Well there are things which are out of my power e.g. when I have to rely on the IOException telling me that the remote endpoint was closed.

Nethertheless I would really like to understand why this is working in my development enviroment but not in yours! That is why I am asking for your code.

@vikulin
Copy link
Author

vikulin commented Jun 16, 2017 via email

@vikulin
Copy link
Author

vikulin commented Jun 16, 2017

Accordingly to this article http://www.javaworld.com/article/2076498/core-java/simple-handling-of-network-timeouts.html
you have to handle not only IOException but:
InterruptedIOException

Java throws IOException when destination address is unavailable and network returns appropriate response. But this case does not cover scenario when remote host does not respond.

Are you handling both cases?

I will try t fix it by my self adding InterruptedIOException try-catch block.

Can you please send me a code line where to put it?

@marci4
Copy link
Collaborator

marci4 commented Jun 16, 2017

Well then the source code is not an option ;)
Don't wanna make you a lot of work!

Let's try this a different way!
Could you send me an example handshake? (Client request and server response)
What is your exact java version on the server?
What is the Android version on the client side? What are you using on the client side to connect to the server?

To your question about InterruptedIOException: it extends from IOException so this is fine!

The easiest workaround right now is change the code you posted earlier startConnectionLostTimer() and replace conn.close( CloseFrame.ABNORMAL_CLOSE ); with conn.closeConnection( CloseFrame.ABNORMAL_CLOSE );

@vikulin
Copy link
Author

vikulin commented Jun 16, 2017

Handshake:
process(314): {GET / HTTP/1.1
Authentication: b80c3a39edc0421fe637bd47f28288e0e781bca7ee28565cd54cc1ed8e3a6d96c3c796558786a11aeacae44f1732daf7d48c628fabc23c7ce9b9c70bded325db
Connection: Upgrade
Host: messenger.hyperborian.org:443
Sec-WebSocket-Key: ZdcjgAAlVOu7+cjDK8+ZQg==
Sec-WebSocket-Version: 13
Upgrade: websocket

}
write(212): {HTTP/1.1 101 Web Socket Protocol Handshake
Connection: Upgrade
Date: Fri, 16 Jun 2017 08:13:13 GMT
Sec-WebSocket-Accept: QRtV6WdCnN/IY2xJMkxxUvoKt/4=
Server: TooTallNate Java-WebSocket
Upgrade: websocket

}
open using draft: Draft_6455

Java:

java -version
java version "1.8.0_131"
Java(TM) SE Runtime Environment (build 1.8.0_131-b11)
Java HotSpot(TM) 64-Bit Server VM (build 25.131-b11, mixed mode)

Client side: Android 6.0 using the same lib: Java-WebSocket v1.3.4

@marci4
Copy link
Collaborator

marci4 commented Jun 16, 2017

Hello @vikulin,

I was still not able to reproduce your issue in my development enviroment!

Nethertheless I build you a new version of the jar in which I switched out the conn.close call with conn.closeConnection.

https://www.dropbox.com/s/g46yhov8igq77es/java_websocket-1.3.5-SNAPSHOT.jar?dl=0

Greetings
marci4

@vikulin
Copy link
Author

vikulin commented Jun 16, 2017

The issue was fixed by your change. App showed it once and no other such messages in log:

Closing connection due to no pong received: org.java_websocket.WebSocketImpl@43305ffd
org.java_websocket.WebSocketImpl@43305ffd has left the room!

Thanks a lot!

@vikulin
Copy link
Author

vikulin commented Jun 16, 2017

Found only once:
Closing connection due to no pong received: org.java_websocket.WebSocketImpl@7dc75151
org.java_websocket.WebSocketImpl@7dc75151 has left the room!
21:46:52.710 ERROR [general] Uncaught exception
java.util.ConcurrentModificationException: null
at java.util.HashMap$HashIterator.nextNode(HashMap.java:1437)
at java.util.HashMap$KeyIterator.next(HashMap.java:1461)
at org.java_websocket.AbstractWebSocket$1.run(AbstractWebSocket.java:112)
at java.util.TimerThread.mainLoop(Timer.java:555)
at java.util.TimerThread.run(Timer.java:505)

Do you synchronize HashMap?

@marci4
Copy link
Collaborator

marci4 commented Jun 17, 2017

Never do a hotfix I quess!

Well here is the fixed version which should not cause CurrentModificationException as well as deadlocks.

https://www.dropbox.com/s/g46yhov8igq77es/java_websocket-1.3.5-SNAPSHOT.jar?dl=0

Sorry again :(

Greetings
marci4

@marci4 marci4 added this to the Release 1.3.5 milestone Jun 17, 2017
@marci4
Copy link
Collaborator

marci4 commented Jun 17, 2017

Bugfix merged.

Closing issue!
If there are still problems, feel free to open this issue again!

Greetings
marci4

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants