[9] RFR: 8159416: javax/net/ssl/DTLS/CipherSuite.java failed on timeout
Artem Smotrakov
artem.smotrakov at oracle.com
Tue Aug 2 21:42:01 UTC 2016
Hi Xuelei,
Thank you for review. Please see inline. I'll send an updated webrev soon.
On 08/01/2016 09:35 PM, Xuelei Fan wrote:
> DTLSOutputRecord
> ----------------
> 182 int len = destination.remaining();
> 235 int len = destination.remaining();
>
> This variable is only use by debug block. I may try to avoid to define
> it out side of the debug block.
encrypt() changes "destination" buffer, that's why the "len" variable is
defined before it. Probably the length may be calculated some other way.
I don't like it much either, but this way is just the most simple and
straightforward to me.
> I know you want to dump the length in
> the "record" debug option. But I think the epoch/sequence# belong to
> the "packet" debug option. The "record" option does not include the
> header part, so may be, it is not suitable to dump the epoch/seq# here.
>
> I may suggest to remove the update as the "packet" option can help if
> users want to know the epoch/sequence numbers. Please see the comment
> for DTLSOverDatagram.java, too.
If -Djavax.net.debug=packet is set, then it prints something like the
following:
[Raw write]: length = 135
0000: 16 FE FD 00 00 00 00 00 00 00 00 00 7A 01 00 00 ............z...
0010: 6E 00 00 00 00 00 00 00 6E FE FD 18 E3 9C 82 DF n.......n.......
0020: 02 6C 42 FF AB EE 0C 9A 82 1B 78 6A 31 93 DC 6A .lB.......xj1..j
0030: DC 70 9F 5A 91 DB D5 04 E1 99 65 00 00 00 02 00 .p.Z......e.....
0040: 3C 01 00 00 42 00 0D 00 1C 00 1A 06 03 06 01 05 <...B...........
0050: 03 05 01 04 03 04 01 04 02 03 03 03 01 03 02 02 ................
0060: 03 02 01 02 02 00 11 00 10 00 0E 02 00 04 00 00 ................
0070: 00 00 01 00 04 00 00 00 00 00 05 00 05 01 00 00 ................
0080: 00 00 FF 01 00 01 00 .......
Well ... I am sure that such a dump contains everything we need, but ...
it doesn't look really friendly :) If someone is not an expert in
TLS/DTLS like me, than it might be helpful to have some thing more
human-readable in logs :) That's why I wanted to print sequence and
epoch numbers (it helped me while looking into 8161086).
>
> 466-470
> This is a nice update to get the user friendly handshake type
> description. There are still a lot similar debug log that need to get
> similar update. Would you mind to file a new RFE, and make the update
> together with other places (both TLS and DTLS) all together?
Sure, I filed https://bugs.openjdk.java.net/browse/JDK-8162996
I'll revert all changes related to debut output. They may be integrated
in the RFE above.
>
>
> DTLSInputRecord
> ---------------
> 159 long onlySeqNum =
> Authenticator.getDTLSSequenceNumber(recordEnS);
>
> Using getDTLSSequenceNumber(long) may be more effective.
>
> 161-165, if you consider to remove the debug log update in
> DTLSOutputRecord, you may also want to remove the debug log update here
> for similar reasons.
>
> HandshakeMessage
> ----------------
> See comment for DTLSOutputRecord. I may prefer to file a new RFE, and
> make the update all together.
>
>
> Authenticator
> -------------
> May not need the update any more if you consider my suggestions above.
> Otherwise, I think may be only
>
> getDTLSSequenceNumber(long recordEnS)
>
> is actually used. Other two new methods can be removed.
>
>
> InvalidRecords
> --------------
> I like this find!
>
>
> DTLSOverDatagram
> ----------------
>
> 50 System.setProperty("javax.net.debug", "ssl,record");
>
> I may suggest to use "ssl,record,packet" for debugging if you won't dump
> the epoch/seq# in "record" debug option. If the test passed, I may
> prefer to turn the debug log off.
The tests pass now. I don't mind removing this debug output, but it
happens often that we don't have enough info if a test fails
intermittently. Then, we may update the test to use -Djavax.net.debug to
get more info when it fails next time. I think it might be good to
enable debug output for tests by default, so that we have more info to
analyze failures. As far as I know, jtreg may be configured to keep jtr
files only for failed tests, so additional output shouldn't take much
space if someone runs these test often. Is there any other concerns?
> doServerSide()
> I did not get too much about the update:
> 1. Is it necessary to combine handshake and reading client application
> data together?
Final handshake messages to a client may be lost. Client still will be
expecting them, and server needs to re-send them. When server is done
with handshaking, it tries to receive first application data. But if
client didn't receive final handshake messages (because they were lost),
it keeps re-sending handshake messages to server. In this situation,
server needs to re-send final handshake messages to client. Those
messages are easily accessible while we're in handshake() method, so
that's why I added reading first application data there. handshake()
method may return final handshake packets to the caller, so that it can
re-send them if necessary. This is just another way, I don't think any
of them is better that another.
> I think the receiveAppData can be reused.
I don't think it can be re-used "as is" because it needs to re-send
final handshake messages on server side. Okay, I'll update the method,
and re-use it.
>
> 2. Is it necessary to re-send application data?
> I think if application data is not allowed to drop, may not need to
> the re-send code.
You're right. I'll remove those while loops.
>
> Same for the doClientSide() implementation.
>
> disablePacketDrop() is a static method, you may not want to call it
> exception the initialization stage. The following line need to be very
> carefully used:
>
> 162 CustomDatagramSocketImplFactory.disablePacketDrop();
> 334 CustomDatagramSocketImplFactory.disablePacketDrop();
disablePacketDrop() asks CustomDatagramSocketImpl to stop dropping
packets. This method should be called before we start sending
application data. It seems like one of these disablePacketDrop() calls
is redundant, I'll move it to sendAppData() method.
>
> 324-375, may be not necessary, or can be improved to use
> receiveAppData() method instead.
Sure, will do, please see above.
> I think the wrap() and unwrap() impl
> should take care of the retransmission of handshaking messages, but not
> the application. Resending the previous packet does not comply to DTLS
> retransmission specification. If you run into problems, would you mind
> show me the debug log?
I am not sure what logs you are asking about. You can find some logs
attached to https://bugs.openjdk.java.net/browse/JDK-8159416
I am also not sure what you mean by retransmission here. As far as I
understand, wrap() and unwrap() methods produce/consume (D)TLS records,
and client code should take care of sending them over the network to the
remote peer. While expecting first application data, the test re-sends
the same packets which were generated by last wrap() call on server
side. This means that DTLS records with the same sequence numbers are
used again.
Do you think that server should generate records with new sequence numbers?
(I have not tried to call wrap() again to produce final handshake
message after server's SSLEngine has finished handshaking, not sure if
it works)
>
>>> - Updated client and server to use simple threads instead of thread
>>> pools. This way, it's possible to specify meaningful names for
>>> threads
> A more light update may be use Thread.setName(String name) in the
> ServerCallable.call(). I did not test. If you like, you can have a try.
setName() method is not static, so it should be called on an instance of
Thread, but I don't know how to access it in ServerCallable.call() method.
>
>
> CustomDatagramSocketImpl.addPacket()
> I may suggest to check application data here.
>
> 927 private void addPacket(byte[] data) {
> 928 // check if a packet should be dropped
> - 929 if (CustomDatagramSocketImplFactory.losePacket()) {
> + if (ustomDatagramSocketImplFactory.losePacket() &&
> + (data[0] != (byte)0x17)) {
> 930 return;
> 931 }
>
> "data[0] != (byte)0x17" means that it is not application data. As would
> simplify the code a lot. See comments above about the application data
> re-sending issue.
It wouldn't simplify the code to me because "0x17" looks like a magic
number. Of course, we can define it as a constant with some meaningful
name, but to me it is clearer to call a method which just stops dropping
packets. It doesn't make the code too complicated to me. If you don't
mind, and there is no other issues with it, I would prefer to keep it.
>
>
> PacketLossXXX.java
> ------------------
> It should not be the common case to split test cases separated with the
> test code. I would suggest merge them into the PacketLoss.java.
The problem here is that those test take some time for execution. That's
why I splitted them to different files.
As far as I remember, there was a concern from people who run those
tests in CI systems that some tests take too long. Their point was that
tests execution may be faster if we run tests in concurrent mode, and
don't have tests which take too long. And if I recall correctly, there
was an agreement that we split such tests this way.
I am cc'ing Rajan, he may remember more about this.
Artem
> If you
> are worrying about the debug log length, please turn off the debug log.
> Actually, we should turn off the debug log unless we need more detailed
> debug log for problematic test. Or alternatively, we can ask the JTREG
> to consider the behavior more about the debug length restrictions.
>
> Thanks,
> Xuelei
>
> On 8/2/2016 9:25 AM, Artem Smotrakov wrote:
>> Here is an updated webrev which includes a fix for 8161086 (thanks
>> Xuelei for help):
>> - No updates to the problem list
>> - CustomDatagramSocketImplFactory drops 5% of packets by default
>> - Updated DTLSInputRecord and DTLSOutputRecord to print sequence numbers
>> if -Djavax.net.debug=ssl option is specified
>> - Updated InvalidRecords.java tests not to drop packets by default
>> because handshaking unexpectedly succeeds if an invalid packet was dropped
>>
>> http://cr.openjdk.java.net/~asmotrak/8159416/webrev.03/
>>
>> Please take a look.
>>
>> Artem
>>
>> On 07/28/2016 04:36 PM, Artem Smotrakov wrote:
>>> Hi Xuelei,
>>>
>>> I updated CustomDatagramSocketImpl class to be able to drop some
>>> packets randomly or by specified numbers.
>>>
>>> While updating the test, I found
>>> https://bugs.openjdk.java.net/browse/JDK-8161086 which I think is the
>>> root cause of these intermittent failures.
>>>
>>> I added a couple of PacketLoss* tests to reproduce and verify 8161086.
>>> These tests drop different packets while handshaking. They use
>>> different cipher suites and modes, so that they take a while. I didn't
>>> notice they fail with timeout, but I suspect that may happen on slower
>>> machines. That's why I increased timeout value for them. I added the
>>> tests to the problem list since 8161086 is not fixed yet.
>>>
>>> There are a couple of other updates to DTLSOverDatagram.java:
>>> - Server tries to receive first application data when it finishes
>>> handshaking. Server re-sends final handshaking messages if timeout
>>> reached while waiting for application data from client.
>>> - Updated client and server to use simple threads instead of thread
>>> pools. This way, it's possible to specify meaningful names for threads
>>> which makes logs more readable if "-Djavax.net.debug=ssl" specified
>>> - Added more logging
>>> - Made some fields final
>>>
>>> At the moment, CustomDatagramSocketImplFactory doesn't drop packets by
>>> default because it may cause intermittent failures of tests which are
>>> based on DTLSOverDatagram class:
>>>
>>> ...
>>> static class CustomDatagramSocketImplFactory
>>> implements DatagramSocketImplFactory {
>>> ...
>>> // if true, it's going to drop some packets
>>> private static boolean dropPackets = false;
>>> ...
>>>
>>> When 8161086 is fixed, it may be set to true by default. Currently the
>>> packet loss rate is 5% which I think is much more than if we use UDP
>>> sockets on localhost, so that we test DTLS impl in worse conditions.
>>>
>>> Could you please take a look at updated webrev?
>>>
>>> http://cr.openjdk.java.net/~asmotrak/8159416/webrev.02/
>>>
>>> Artem
>>>
>>> On 06/27/2016 06:25 PM, Xuelei Fan wrote:
>>>> On 6/28/2016 9:12 AM, Artem Smotrakov wrote:
>>>>> Hello,
>>>>>
>>>>> Please review this patch for javax/net/ssl/DTLS tests.
>>>>>
>>>>> A couple of DTLS tests fail intermittently on Mac with timeout or "Too
>>>>> many handshake loops ..." error. The tests use UDP to transfer DTLS
>>>>> records. It happens sometimes that server cannot receive UDP packets
>>>>> with DatagramSocket.receive() method even if client tries to re-send
>>>>> them multiple times. Please see logs in the bug.
>>>>>
>>>>> At the moment, it is not clear why UDP packets can't be delivered to
>>>>> server. If someone has seen something similar before, or has some ideas
>>>>> what might be the root cause, please let me know.
>>>>>
>>>> UDP is not reliable. It could happen that the packets get lost.
>>>>
>>>>> I think that the tests and DTLS implementation are fine here. Since the
>>>>> tests are for DTLS, we can workaround this issue by avoiding real UDP
>>>>> connections. To avoid changing test logic much, we can use a custom
>>>>> DatagramSocketImpl and DatagramSocketImplFactory implementations to
>>>>> replace system UDP implementation.
>>>>>
>>>>> The patch below updates the tests with the following:
>>>>> - added custom DatagramSocketImpl and DatagramSocketImplFactory
>>>>> implementations to avoid real UDP connections
>>>> Tests for real connections in practice are needed. If we update this
>>>> test this way, we need to add other tests to test real application
>>>> usage. I don't think this is the right direction to avoid real UDP
>>>> connections.
>>>>
>>>>> - added more test output, so that we can have more info it the tests
>>>>> fail again
>>>>>
>>>> I agree with this point.
>>>>
>>>> Xuelei
>>>>
>>>>> I have run javax/net/ssl/DTLS/CipherSuite.java test in a loop on Mac,
>>>>> and I didn't see it failed. I also have run javax/net/ssl/DTLS tests on
>>>>> all supported generic platforms, and they worked fine.
>>>>>
>>>>> Bug: https://bugs.openjdk.java.net/browse/JDK-8159416
>>>>> http://cr.openjdk.java.net/~asmotrak/8159416/webrev.00/
>>>>>
>>>>> Artem
More information about the security-dev
mailing list