-
Bug
-
Resolution: Unresolved
-
P3
-
None
-
11
-
None
The debugging in general is generating confusing debug info:
javax.net.ssl|ALL|01|main|2018-09-06 14:29:55.891 PDT|SSLEngineImpl.java:743|Closing outbound of SSLEngine
javax.net.ssl|DEBUG|01|main|2018-09-06 14:22:14.368 PDT|SSLEngineOutputRecord.java:507|WRITE: TLS13 alert, length = 2
javax.net.ssl|DEBUG|01|main|2018-09-06 14:22:14.384 PDT|SSLCipher.java:2020|Plaintext before ENCRYPTION (
0000: 01 00 15 ...
)
...deleted...
javax.net.ssl|DEBUG|01|main|2018-09-06 15:30:19.251 PDT|SSLEngineInputRecord.java:177|Raw read (
0000: 17 03 03 00 13 11 97 FA B6 F2 47 51 37 80 B7 93 ..........GQ7...
0010: FC 8F C8 25 24 7F 79 B6 ...%$.y.
)
javax.net.ssl|DEBUG|01|main|2018-09-06 15:30:19.251 PDT|SSLEngineInputRecord.java:214|READ: TLSv1.2 application_data, length = 19
javax.net.ssl|DEBUG|01|main|2018-09-06 15:30:19.252 PDT|SSLCipher.java:1915|Plaintext after DECRYPTION (
0000: 01 00 ..
)
javax.net.ssl|DEBUG|01|main|2018-09-06 15:30:19.261 PDT|Alert.java:232|Received alert message (
"Alert": {
"level" : "warning",
"description": "close_notify"
}
)
Note that:
1. The outbound TLS13 alert is 2 bytes, but doesn't say what it is. No warning/fatal level and alert number/description
2. The Plaintext before Encryption is 3 bytes. I figured out that it's because of the way plaintext is enciphered, but as someone debugging, this is very hard to follow why we suddenly have 3 bytes here.
3. The inbound plaintext message has 2 bytes, which doesn't match the three bytes above.
More generally, we used to have the following style for debugging crypto/handshake/etc. problems. Can we please have it back?
Handshake message
full plaintext message before encryption
raw/full write generated
e.g.
*** Finished
verify_data: { 119, 217, 11, 203, 185, 129, 21, 215, 87, 28, 118, 121 }
***
main, WRITE: TLSv1.2 Handshake, length = 16
Padded plaintext before ENCRYPTION: len = 16
0000: 14 00 00 0C 77 D9 0B CB B9 81 15 D7 57 1C 76 79 ....w.......W.vy
[Raw write]: length = 45
0000: 16 03 03 00 28 00 00 00 00 00 00 00 00 C4 82 50 ....(..........P
0010: 2F D4 BA A9 81 38 4A AC DA 14 F8 2E 88 E0 14 ED /....8J.........
0020: 64 84 E2 6B 68 F2 D6 C5 8C 11 A2 D1 0D d..kh........
...and...
raw/full read generated
full plaintext message after decryption
parsed Handshake message
e.g.
[Raw read]: length = 45
0000: 16 03 03 00 28 00 00 00 00 00 00 00 00 C4 82 50 ....(..........P
0010: 2F D4 BA A9 81 38 4A AC DA 14 F8 2E 88 E0 14 ED /....8J.........
0020: 64 84 E2 6B 68 F2 D6 C5 8C 11 A2 D1 0D d..kh........
main, READ: TLSv1.2 Handshake, length = 40
Padded plaintext after DECRYPTION: len = 16
0000: 14 00 00 0C 77 D9 0B CB B9 81 15 D7 57 1C 76 79 ....w.......W.vy
*** Finished
verify_data: { 119, 217, 11, 203, 185, 129, 21, 215, 87, 28, 118, 121 }
***
javax.net.ssl|ALL|01|main|2018-09-06 14:29:55.891 PDT|SSLEngineImpl.java:743|Closing outbound of SSLEngine
javax.net.ssl|DEBUG|01|main|2018-09-06 14:22:14.368 PDT|SSLEngineOutputRecord.java:507|WRITE: TLS13 alert, length = 2
javax.net.ssl|DEBUG|01|main|2018-09-06 14:22:14.384 PDT|SSLCipher.java:2020|Plaintext before ENCRYPTION (
0000: 01 00 15 ...
)
...deleted...
javax.net.ssl|DEBUG|01|main|2018-09-06 15:30:19.251 PDT|SSLEngineInputRecord.java:177|Raw read (
0000: 17 03 03 00 13 11 97 FA B6 F2 47 51 37 80 B7 93 ..........GQ7...
0010: FC 8F C8 25 24 7F 79 B6 ...%$.y.
)
javax.net.ssl|DEBUG|01|main|2018-09-06 15:30:19.251 PDT|SSLEngineInputRecord.java:214|READ: TLSv1.2 application_data, length = 19
javax.net.ssl|DEBUG|01|main|2018-09-06 15:30:19.252 PDT|SSLCipher.java:1915|Plaintext after DECRYPTION (
0000: 01 00 ..
)
javax.net.ssl|DEBUG|01|main|2018-09-06 15:30:19.261 PDT|Alert.java:232|Received alert message (
"Alert": {
"level" : "warning",
"description": "close_notify"
}
)
Note that:
1. The outbound TLS13 alert is 2 bytes, but doesn't say what it is. No warning/fatal level and alert number/description
2. The Plaintext before Encryption is 3 bytes. I figured out that it's because of the way plaintext is enciphered, but as someone debugging, this is very hard to follow why we suddenly have 3 bytes here.
3. The inbound plaintext message has 2 bytes, which doesn't match the three bytes above.
More generally, we used to have the following style for debugging crypto/handshake/etc. problems. Can we please have it back?
Handshake message
full plaintext message before encryption
raw/full write generated
e.g.
*** Finished
verify_data: { 119, 217, 11, 203, 185, 129, 21, 215, 87, 28, 118, 121 }
***
main, WRITE: TLSv1.2 Handshake, length = 16
Padded plaintext before ENCRYPTION: len = 16
0000: 14 00 00 0C 77 D9 0B CB B9 81 15 D7 57 1C 76 79 ....w.......W.vy
[Raw write]: length = 45
0000: 16 03 03 00 28 00 00 00 00 00 00 00 00 C4 82 50 ....(..........P
0010: 2F D4 BA A9 81 38 4A AC DA 14 F8 2E 88 E0 14 ED /....8J.........
0020: 64 84 E2 6B 68 F2 D6 C5 8C 11 A2 D1 0D d..kh........
...and...
raw/full read generated
full plaintext message after decryption
parsed Handshake message
e.g.
[Raw read]: length = 45
0000: 16 03 03 00 28 00 00 00 00 00 00 00 00 C4 82 50 ....(..........P
0010: 2F D4 BA A9 81 38 4A AC DA 14 F8 2E 88 E0 14 ED /....8J.........
0020: 64 84 E2 6B 68 F2 D6 C5 8C 11 A2 D1 0D d..kh........
main, READ: TLSv1.2 Handshake, length = 40
Padded plaintext after DECRYPTION: len = 16
0000: 14 00 00 0C 77 D9 0B CB B9 81 15 D7 57 1C 76 79 ....w.......W.vy
*** Finished
verify_data: { 119, 217, 11, 203, 185, 129, 21, 215, 87, 28, 118, 121 }
***
1.
|
Update the section "Debugging TLS Connections" once debugging output has changed | Closed | Unassigned |