MINA
  1. MINA
  2. DIRMINA-650

Mina server does not recieve all data sent by client using SSLSocketFactory

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Critical Critical
    • Resolution: Fixed
    • Affects Version/s: 1.1.7
    • Fix Version/s: 2.0.0
    • Component/s: Filter
    • Labels:
      None

      Description

      Using mina on the server with SSLFilter, and a client using SSLSocketFactory the server does not recieve all
      data sent by the client.

      The client creates a socket, sends data to the server and waits for a response then closes the socket.
      The first connection works fine, if the client then repeats on the same thread the second attempt almost always
      fails. The server never gets all the data the client sent, and so never sends a response.

      A similar problem seems to be described in DIRMINA-580, and in fact the fix described in [1] seems to fix the problem. However the fix that was accepted into the 1.1 branch does not correct the problem for me.

      Attached is a test case that almost always fails (on some systems I've tried it fails every time, others it fails 5 out of 6 times)

      [1] http://issues.apache.org/jira/browse/DIRMINA-580?focusedCommentId=12595789#action_12595789

      1. SSLTestMultiClients.java
        7 kB
        Cedric Lucas
      2. SSLTest.zip
        4 kB
        Cedric Lucas
      3. ssltest.zip
        5 kB
        Kevin Koltzau
      4. SslHandler.java
        24 kB
        Cedric Lucas

        Activity

        Hide
        Kevin Koltzau added a comment -

        run with 'mvn test'

        Show
        Kevin Koltzau added a comment - run with 'mvn test'
        Hide
        Emmanuel Lecharny added a comment -

        Hmmm... Strange. I have tested your program, with slight modifications (basically, adding logs and using KeyManagerFactory.getDefaultAlgorithm() instead of the static "SunX509" string - a good habit, not all of us are running with a sun VM). Here are the logs I get :

        Client sending: hello
        >>> Session /127.0.0.1:59476 created
        +++ Session /127.0.0.1:59476 opened
        Client sending: send
        Server got: 'hello', waiting for 'send'
        Server got: 'send', sending 'data'
        ... Sending data to Session /127.0.0.1:59476 created
        Client got: data
        >>> Session /127.0.0.1:59477 created
        +++ Session /127.0.0.1:59477 opened
        Client sending: hello
        Client sending: send
        <<< Session /127.0.0.1:59476 closed
        Server got: 'hello', waiting for 'send'
        .......

        As you can see, it blocks on the second send, the server never receives the second hello.

        Have you tried MINA 2.0.0-M4 ?

        Show
        Emmanuel Lecharny added a comment - Hmmm... Strange. I have tested your program, with slight modifications (basically, adding logs and using KeyManagerFactory.getDefaultAlgorithm() instead of the static "SunX509" string - a good habit, not all of us are running with a sun VM). Here are the logs I get : Client sending: hello >>> Session /127.0.0.1:59476 created +++ Session /127.0.0.1:59476 opened Client sending: send Server got: 'hello', waiting for 'send' Server got: 'send', sending 'data' ... Sending data to Session /127.0.0.1:59476 created Client got: data >>> Session /127.0.0.1:59477 created +++ Session /127.0.0.1:59477 opened Client sending: hello Client sending: send <<< Session /127.0.0.1:59476 closed Server got: 'hello', waiting for 'send' ....... As you can see, it blocks on the second send, the server never receives the second hello. Have you tried MINA 2.0.0-M4 ?
        Hide
        Kevin Koltzau added a comment -

        It doesn't block on the send, the send succeeds. If a 3rd send is done by the client the server will receive all the data, or if the server responds to the first send everything will also work correctly. If the SSLSession is not reused (eg, the server calls SSLSession.invalidate()) the problem also goes away.

        I haven't tried 2.0.0-M4 yet, I didn't have time to rework the code to the new API. My primary concern is with 1.1 as this affects production code.

        Show
        Kevin Koltzau added a comment - It doesn't block on the send, the send succeeds. If a 3rd send is done by the client the server will receive all the data, or if the server responds to the first send everything will also work correctly. If the SSLSession is not reused (eg, the server calls SSLSession.invalidate()) the problem also goes away. I haven't tried 2.0.0-M4 yet, I didn't have time to rework the code to the new API. My primary concern is with 1.1 as this affects production code.
        Hide
        Emmanuel Lecharny added a comment -

        In the test I have done with your code, the second 'send' never make it through the chain up to the messageReceived() method, this is what I wanted to say. Sorry if it wasn't clear.

        There is something wrong, obviously. I will try to investigate tomorrow...

        Show
        Emmanuel Lecharny added a comment - In the test I have done with your code, the second 'send' never make it through the chain up to the messageReceived() method, this is what I wanted to say. Sorry if it wasn't clear. There is something wrong, obviously. I will try to investigate tomorrow...
        Hide
        Cedric Lucas added a comment -

        Hi,

        I just wanted to tell you that this problem also occurs within the version 2.0.0-RC-1
        Here are the attached sources modified for 2.x.

        Regards

        Show
        Cedric Lucas added a comment - Hi, I just wanted to tell you that this problem also occurs within the version 2.0.0-RC-1 Here are the attached sources modified for 2.x. Regards
        Hide
        Cedric Lucas added a comment -

        Hi again,

        I sent a mail in the mailing list, http://old.nabble.com/SSL-and-mina-ts26680309.html .
        I think I found the problem:
        As I said, the problem is when Mina is processing 1 message that contains 3 parts (or more) containing first the end of the handshake and then 2 different messages to process.

        Calls are the following:
        SslHandler.unwrapHandshake
        calls
        res = unwrap0()
        if (handshakeStatus == SSLEngineResult.HandshakeStatus.FINISHED
        && res.getStatus() == SSLEngineResult.Status.OK
        && inNetBuffer.hasRemaining());

        Now, inside unwrap0, the condition of the do while is:
        ((res.getStatus() == SSLEngineResult.Status.OK || res.getStatus() == SSLEngineResult.Status.BUFFER_OVERFLOW) &&
        (handshakeComplete && res.getHandshakeStatus() == SSLEngineResult.HandshakeStatus.NOT_HANDSHAKING ||
        res.getHandshakeStatus() == SSLEngineResult.HandshakeStatus.NEED_UNWRAP));

        but the problem is that handshakeComplete has not been set to true (it will be just after). So, thanks to do while, first message is processed but not the second one!

        I attached a modification of the SslHandler to resolve this.
        I have just created a new method unwrap0(boolean finished), calling it when doing hanshake, and checking (finished || handshakeComplete) inside of just handshake.

        Maybe you want to change it another way (I didn't watch carefully to all the remaining part).

        Hope it would help

        Regards

        Show
        Cedric Lucas added a comment - Hi again, I sent a mail in the mailing list, http://old.nabble.com/SSL-and-mina-ts26680309.html . I think I found the problem: As I said, the problem is when Mina is processing 1 message that contains 3 parts (or more) containing first the end of the handshake and then 2 different messages to process. Calls are the following: SslHandler.unwrapHandshake calls res = unwrap0() if (handshakeStatus == SSLEngineResult.HandshakeStatus.FINISHED && res.getStatus() == SSLEngineResult.Status.OK && inNetBuffer.hasRemaining()); Now, inside unwrap0, the condition of the do while is: ((res.getStatus() == SSLEngineResult.Status.OK || res.getStatus() == SSLEngineResult.Status.BUFFER_OVERFLOW) && (handshakeComplete && res.getHandshakeStatus() == SSLEngineResult.HandshakeStatus.NOT_HANDSHAKING || res.getHandshakeStatus() == SSLEngineResult.HandshakeStatus.NEED_UNWRAP)); but the problem is that handshakeComplete has not been set to true (it will be just after). So, thanks to do while, first message is processed but not the second one! I attached a modification of the SslHandler to resolve this. I have just created a new method unwrap0(boolean finished), calling it when doing hanshake, and checking (finished || handshakeComplete) inside of just handshake. Maybe you want to change it another way (I didn't watch carefully to all the remaining part). Hope it would help Regards
        Hide
        Emmanuel Lecharny added a comment -

        I can't believe we let such a crappy test get into the code ...

        ((res.getStatus() == SSLEngineResult.Status.OK || res.getStatus() == SSLEngineResult.Status.BUFFER_OVERFLOW) &&
        (handshakeComplete && res.getHandshakeStatus() == SSLEngineResult.HandshakeStatus.NOT_HANDSHAKING ||
        res.getHandshakeStatus() == SSLEngineResult.HandshakeStatus.NEED_UNWRAP));

        Yuk !

        Show
        Emmanuel Lecharny added a comment - I can't believe we let such a crappy test get into the code ... ((res.getStatus() == SSLEngineResult.Status.OK || res.getStatus() == SSLEngineResult.Status.BUFFER_OVERFLOW) && (handshakeComplete && res.getHandshakeStatus() == SSLEngineResult.HandshakeStatus.NOT_HANDSHAKING || res.getHandshakeStatus() == SSLEngineResult.HandshakeStatus.NEED_UNWRAP)); Yuk !
        Hide
        Emmanuel Lecharny added a comment -

        Seems to work with your patch.

        Honnestly, all this part of the code must be heavily reviewed, it's a serious crap.

        Thanks for the report and the proposed solution, I'm currently investigating it.

        Show
        Emmanuel Lecharny added a comment - Seems to work with your patch. Honnestly, all this part of the code must be heavily reviewed, it's a serious crap. Thanks for the report and the proposed solution, I'm currently investigating it.
        Hide
        Emmanuel Lecharny added a comment -

        Question :

        Cédric, may I inject the test you have created in the base code ? You have to check the 'Grant license to ASF for inclusion in ASF works (as per the Apache License §5) " checkbox for this file.

        thanks !

        Show
        Emmanuel Lecharny added a comment - Question : Cédric, may I inject the test you have created in the base code ? You have to check the 'Grant license to ASF for inclusion in ASF works (as per the Apache License §5) " checkbox for this file. thanks !
        Hide
        Emmanuel Lecharny added a comment -

        Fixed in 2.0.0-RC1 :
        http://svn.apache.org/viewvc?rev=889025&view=rev

        Thanks for the report Kevin, many thanks for the proposed solution Cedric !

        If any of you want to review this pile of sh*t^H^H^H^Hcode, you are welcome !

        Show
        Emmanuel Lecharny added a comment - Fixed in 2.0.0-RC1 : http://svn.apache.org/viewvc?rev=889025&view=rev Thanks for the report Kevin, many thanks for the proposed solution Cedric ! If any of you want to review this pile of sh*t^H^H^H^Hcode, you are welcome !
        Hide
        Cedric Lucas added a comment -

        Sorry, I didn't know what it meant first time I posted it. Sure you can use it. This is just an up-to-date from Kevin's test so I have absolutly no right for this.
        By the way, I don't find any checkbox :s.
        So I delete and add again

        Tell me if there was another way (for future)

        And thanks for correcting this . I hope it will be in next release

        Show
        Cedric Lucas added a comment - Sorry, I didn't know what it meant first time I posted it. Sure you can use it. This is just an up-to-date from Kevin's test so I have absolutly no right for this. By the way, I don't find any checkbox :s. So I delete and add again Tell me if there was another way (for future) And thanks for correcting this . I hope it will be in next release
        Hide
        Emmanuel Lecharny added a comment -

        Ok, thanks !

        I have added the test in MINA. :
        http://svn.apache.org/viewvc?rev=889151&view=rev

        Show
        Emmanuel Lecharny added a comment - Ok, thanks ! I have added the test in MINA. : http://svn.apache.org/viewvc?rev=889151&view=rev
        Hide
        Cedric Lucas added a comment -

        I tried with multiple clients (by threading all of them) and I had some connection reset with this piece of code.
        The problem was from the creation of the socket client. So if you don't want to get into this problem in the SSLTest.java (sometimes, it can happen), you should change the line:
        factory.createSocket(parent, address.getCanonicalHostName(), "5555", true);
        with
        factory.createSocket(parent, address.getCanonicalHostName(), "5555", false);

        which is the auto-close parameter

        Now the test works perfectly

        Show
        Cedric Lucas added a comment - I tried with multiple clients (by threading all of them) and I had some connection reset with this piece of code. The problem was from the creation of the socket client. So if you don't want to get into this problem in the SSLTest.java (sometimes, it can happen), you should change the line: factory.createSocket(parent, address.getCanonicalHostName(), "5555", true); with factory.createSocket(parent, address.getCanonicalHostName(), "5555", false); which is the auto-close parameter Now the test works perfectly
        Hide
        Emmanuel Lecharny added a comment -

        Well, I think the problem is that the socket is created with a port 5555, when the server pick a non used pot starting at 5555, so if this port is already used, it will pick an higher pott (5556, for instance). In this case, with a client trying to open the 5555 port won't be connected to the correct server.

        Show
        Emmanuel Lecharny added a comment - Well, I think the problem is that the socket is created with a port 5555, when the server pick a non used pot starting at 5555, so if this port is already used, it will pick an higher pott (5556, for instance). In this case, with a client trying to open the 5555 port won't be connected to the correct server.
        Hide
        Cedric Lucas added a comment -

        Here is the test client with some threads.
        The server port is always the same so there is no problem.
        If you launch it and try to set auto-close to true, you will see that it fails (around once out of 100 connections).

        Show
        Cedric Lucas added a comment - Here is the test client with some threads. The server port is always the same so there is no problem. If you launch it and try to set auto-close to true, you will see that it fails (around once out of 100 connections).
        Hide
        Emmanuel Lecharny added a comment -

        Agreed. I get the same pb.

        Fixed in : http://svn.apache.org/viewvc?rev=889248&view=rev

        Many thanks !

        Show
        Emmanuel Lecharny added a comment - Agreed. I get the same pb. Fixed in : http://svn.apache.org/viewvc?rev=889248&view=rev Many thanks !
        Hide
        Cedric Lucas added a comment -

        You're welcome!

        I think this is over for this bug. Then, I'll stop spamming

        Show
        Cedric Lucas added a comment - You're welcome! I think this is over for this bug. Then, I'll stop spamming
        Hide
        Emmanuel Lecharny added a comment -

        I committed a patch in trunk, I confirm that the test is now passing with the patch.

        Show
        Emmanuel Lecharny added a comment - I committed a patch in trunk, I confirm that the test is now passing with the patch.

          People

          • Assignee:
            Emmanuel Lecharny
            Reporter:
            Kevin Koltzau
          • Votes:
            1 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development