Translate

2018년 11월 7일 수요일

[Java] SSL/TLS 디버깅 방법 및 로그분석





일반 Java Application 이나 WAS에서의 SSL/TLS (https) 디버깅을 위해 Java 기동 명령에 -Djavax.net.debug 옵션을 넣어준다.


옵션에 넣을 수 있는 값은 아래와 같다.

 1. all - 모든 디버깅 설정

 2. ssl - SSL 관련 디버깅 설정

 3. ssl 옵션과 같이 사용가능한 옵션
  1) record - enable per-record tracing
  2) handshake - print each handshake message
  3) keygen - print key generation data
  4) session - print session activity
  5) defaultctx - print default SSL initialization
  6) sslctx - print SSLContext tracing
  7) sessioncache - print session cache tracing
  8) keymanager - print key manager tracing
  9) trustmanager - print trust manager tracing

 4. record 옵션과 같이 사용가능한 옵션
  1) plaintext - hex dump of record plaintext
  2) packet - print raw SSL or TLS packets

 5. handshake 옵션과 같이 사용가능한 옵션
  1) data - hex dump of each handshake message
  2) verbose - verbose handshake message printing




사용방법은 아래와 같이 단일옵션이나 구분자로 콤마(,) 또는 콜론(:)을 이용해 여러개의 옵션을 넣을 수 있다.

 java -Djavax.net.debug=all

 java -Djavax.net.debug=ssl

 java -Djavax.net.debug=ssl:record:plaintext

 java -Djavax.net.debug=ssl,record,plaintext

 java -Djavax.net.debug=ssl:handshake:data:verbose:trustmanager

 java -Djavax.net.debug=ssl,handshake,data,verbose,trustmanager








옵션을 넣은채로 Java를 구동 후 https 호출 시 아래와 같은 로그가 보여진다.
(TLS동작개념 링크 - 알고있어야 아래 로그를 제대로 볼 수 있다.)

테스트환경
 - WAS: WebLogic v10.3.6 (-Djavax.net.debug=all 옵션 추가)
 - Browser: Chrome


Using SSLEngineImpl.
Using SSLEngineImpl.
Allow unsafe renegotiation: false
Allow legacy hello messages: true
Is initial handshake: true
Is secure renegotiation: false
[Raw read]: length = 5
0000: 16 03 01 02 00                                     .....
[Raw read]: length = 512
0000: 01 00 01 FC 03 03 A0 5A   00 75 9C 6D C9 5E 03 E1  .......Z.u.m.^..

 ... (생략)

01F0: 00 00 00 00 00 00 00 00   00 00 00 00 00 00 00 00  ................
ExecuteThread: '0' for queue: 'weblogic.socket.Muxer', READ: TLSv1 Handshake, length = 512
*** ClientHello, Unknown-3.3
RandomCookie:  GMT: -1604714379 bytes = { 156, 109, 201, 94, 3, 225, 63, 73, 153, 17, 151, 135, 210, 113, 250, 3, 154, 197, 104, 53, 99, 226, 201, 194, 117, 162, 238, 252 }
Session ID:  {187, 60, 89, 212, 171, 218, 61, 231, 49, 86, 29, 95, 208, 199, 21, 202, 207, 241, 134, 115, 208, 143, 51, 44, 233, 111, 4, 227, 89, 185, 76, 90}
Cipher Suites: [Unknown 0xea:0xea, Unknown 0x13:0x1, Unknown 0x13:0x2, Unknown 0x13:0x3, Unknown 0xc0:0x2b, Unknown 0xc0:0x2f, Unknown 0xc0:0x2c, Unknown 0xc0:0x30, Unknown 0xcc:0xa9, Unknown 0xcc:0xa8, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, Unknown 0x0:0x9c, Unknown 0x0:0x9d, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA]
Compression Methods:  { 0 }1004lucifer
Unsupported extension type_10794, data:
Extension renegotiation_info, renegotiated_connection: <empty>
Unsupported extension type_23, data:
Unsupported extension type_35, data:
Unsupported extension signature_algorithms, data: 00:12:04:03:08:04:04:01:05:03:08:05:05:01:08:06:06:01:02:01
Unsupported extension status_request, data: 01:00:00:00:00
Unsupported extension type_18, data:
Unsupported extension type_16, data: 00:0c:02:68:32:08:68:74:74:70:2f:31:2e:31
Unsupported extension type_30032, data:
Extension ec_point_formats, formats: [uncompressed]
Unsupported extension type_51, data: 00:29:2a:2a:00:01:00:00:1d:00:20:06:f0:ca:25:17:1c:50:6e:de:31:28:37:04:3b:fb:2e:da:48:a8:a0:c6:bf:c7:aa:2e:df:88:8c:71:1f:28:3e
Unsupported extension type_45, data: 01:01
Unsupported extension type_43, data: 0a:fa:fa:03:04:03:03:03:02:03:01
Extension elliptic_curves, curve names: {unknown curve 10794, unknown curve 29, secp256r1, secp384r1}
Unsupported extension type_27, data: 02:00:02
Unsupported extension type_19018, data: 00
Unsupported extension type_21, data: 00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00
***
[read] MD5 and SHA1 hashes:  len = 512
0000: 01 00 01 FC 03 03 A0 5A   00 75 9C 6D C9 5E 03 E1  .......Z.u.m.^..
0010: 3F 49 99 11 97 87 D2 71   FA 03 9A C5 68 35 63 E2  ?I.....q....h5c.

 ... (생략)

01E0: 00 00 00 00 00 00 00 00   00 00 00 00 00 00 00 00  ................
01F0: 00 00 00 00 00 00 00 00   00 00 00 00 00 00 00 00  ................
%% Created:  [Session-7, TLS_RSA_WITH_AES_128_CBC_SHA]
*** ServerHello, TLSv1
RandomCookie:  GMT: 1524735920 bytes = { 9, 76, 209, 227, 25, 103, 244, 70, 88, 21, 251, 61, 166, 58, 205, 105, 11, 162, 10, 194, 197, 150, 141, 56, 20, 249, 253, 225 }
Session ID:  {91, 226, 160, 176, 184, 206, 91, 215, 68, 249, 89, 109, 144, 215, 240, 108, 140, 87, 22, 10, 147, 64, 211, 83, 239, 191, 23, 24, 235, 211, 130, 158}
Cipher Suite: TLS_RSA_WITH_AES_128_CBC_SHA
Compression Method: 0
Extension renegotiation_info, renegotiated_connection: <empty>
***
Cipher suite:  TLS_RSA_WITH_AES_128_CBC_SHA
*** Certificate chain
chain [0] = [
[1004lucifer
  Version: V3
  Subject: CN=1004lucifer.co.kr, OU=EssentialSSL, OU=Domain Control Validated
  Signature Algorithm: SHA256withRSA, OID = 1.2.840.113549.1.1.11

  Key:  Sun RSA public key, 2048 bits
  modulus: 19319582615916585659242504168620425718645805827542544076367519867696185914255069380391761611176711763236138015178105913610261666808872857200056763482936155569643030949239457411028215201921515321255031124246934902745856049360960670836525338369519121654874032318461670026264305484084598428913822501539221068776613953044504654851115864964367308713844772369157117624745722953692816540566398064822652451732109298212767353851785781635913505536564496201813943378891319017249826847579583045980923164684260313066681015718006951059405090156338883534361341902284360952736550062700032127303539038935239709551420745512789576784293
  public exponent: 65537
  Validity: [From: Tue Apr 03 09:00:00 KST 2018,
               To: Sat May 04 08:59:59 KST 2019]
  Issuer: CN=COMODO RSA Domain Validation Secure Server CA, O=COMODO CA Limited, L=Salford, ST=Greater Manchester, C=GB
  SerialNumber: [    c6307bba f5e77272 74358350 93316fc5]

Certificate Extensions: 10
[1]: ObjectId: 1.3.6.1.4.1.11129.2.4.2 Criticality=false
Extension unknown: DER encoded OCTET string =

 ... (생략)

00D0: F1 44 4C C6 04 73 49 76   60 0F C7 F8 BD 17 80 6B  .DL..sIv`......k
00E0: 2E E9 CC 4C 0E 5A 9A 79   0F 20 0A 2E D5 9E 63 26  ...L.Z.y. ....c&
00F0: 1E 55 92 94 D8 82 17 5A   7B D0 BC C7 8F 4E 86 04  .U.....Z.....N..

]
***
*** ServerHelloDone
[write] MD5 and SHA1 hashes:  len = 5768
0000: 02 00 00 4D 03 01 5B E2   A0 B0 09 4C D1 E3 19 67  ...M..[....L...g
0010: F4 46 58 15 FB 3D A6 3A   CD 69 0B A2 0A C2 C5 96  .FX..=.:.i......
0020: 8D 38 14 F9 FD E1 20 5B   E2 A0 B0 B8 CE 5B D7 44  .8.... [.....[.D
0030: F9 59 6D 90 D7 F0 6C 8C   57 16 0A 93 40 D3 53 EF  .Ym...l.W...@.S.
0040: BF 17 18 EB D3 82 9E 00   2F 00 00 05 FF 01 00 01  ......../.......
0050: 00 0B 00 16 2F 00 16 2C   00 06 62 30 82 06 5E 30  ..../..,..b0..^0
0060: 82 05 46 A0 03 02 01 02   02 11 00 C6 30 7B BA F5  ..F.........0...
0070: E7 72 72 74 35 83 50 93   31 6F C5 30 0D 06 09 2A  .rrt5.P.1o.0...*
1004lucifer
 ... (생략)

00A0: 6E 58 12 7E 70 8E 8F 15   91 16 6E 73 00 BE 56 74  nX..p.....ns..Vt
00B0: 6B 8A DC 1B 03 ED 84 6C   0B 1B 04 5A 4A 9E 4C E9  k......l...ZJ.L.
00C0: 93 71 5A 64 0F 80 8C F8   FD AC C0 0D 10 E6 E0 FB  .qZd............
00D0: BB 70 77 E3 64 78 55 46   25 DE 28 9B 2C 8C 3A 57  .pw.dxUF%.(.,.:W
00E0: AC 9B 37 54 DA 75 61 82   70 3B F9 6A 94 C1 40 FD  ..7T.ua.p;.j..@.
00F0: 1B 70 13 74 EA 18 49 3E   37 D7 FF 8F 0C 79 FF 3F  .p.t..I>7....y.?
0100: 4B 03 B8 C4 76 88                                  K...v.
ExecuteThread: '2' for queue: 'weblogic.socket.Muxer', READ: TLSv1 Handshake, length = 262
*** ClientKeyExchange, RSA PreMasterSecret, TLSv1
SESSION KEYGEN:
PreMaster Secret:
0000: 03 03 CD A9 64 4D 64 7A   8A 5C 85 5B 17 51 E0 C8  ....dMdz.\.[.Q..
0010: A8 53 45 F0 F1 41 0E DA   34 A8 1D C0 3B F8 C4 9F  .SE..A..4...;...
0020: 4C 58 BA 69 3E 48 B5 EC   F1 F8 93 C6 44 50 72 4E  LX.i>H......DPrN
1004lucifer
 ... (생략)

0000: 14 03 01 00 01                                     .....
[Raw read]: length = 1
0000: 01                                                 .
ExecuteThread: '2' for queue: 'weblogic.socket.Muxer', READ: TLSv1 Change Cipher Spec, length = 1
[Raw read]: length = 5
0000: 16 03 01 00 30                                     ....0
[Raw read]: length = 48
0000: BD 9A FD 56 62 93 0F D4   73 FC A2 2A A7 33 11 CB  ...Vb...s..*.3..
0010: 57 A8 C7 29 68 71 D6 9F   3A ED A5 3A BF 58 AF F9  W..)hq..:..:.X..
0020: DD 1C 39 B3 3F 8D E0 0D   3D 6C 6C 52 AF D8 01 84  ..9.?...=llR....
ExecuteThread: '2' for queue: 'weblogic.socket.Muxer', READ: TLSv1 Handshake, length = 48
Padded plaintext after DECRYPTION:  len = 48
0000: 14 00 00 0C 43 E2 9C 2B   46 5D 79 35 47 01 6C 41  ....C..+F]y5G.lA
0010: E8 C5 56 60 E7 31 4C 98   AD 2A FD EF D1 24 F4 CA  ..V`.1L..*...$..
0020: AB A6 77 1D 0B 0B 0B 0B   0B 0B 0B 0B 0B 0B 0B 0B  ..w.............
*** Finished
verify_data:  { 67, 226, 156, 43, 70, 93, 121, 53, 71, 1, 108, 65 }
***
[read] MD5 and SHA1 hashes:  len = 16
0000: 14 00 00 0C 43 E2 9C 2B   46 5D 79 35 47 01 6C 41  ....C..+F]y5G.lA
ExecuteThread: '2' for queue: 'weblogic.socket.Muxer', WRITE: TLSv1 Change Cipher Spec, length = 1
*** Finished
verify_data:  { 192, 232, 219, 79, 38, 8, 16, 9, 216, 119, 248, 145 }
***
[write] MD5 and SHA1 hashes:  len = 16
0000: 14 00 00 0C C0 E8 DB 4F   26 08 10 09 D8 77 F8 91  .......O&....w..
Padded plaintext before ENCRYPTION:  len = 48
0000: 14 00 00 0C C0 E8 DB 4F   26 08 10 09 D8 77 F8 91  .......O&....w..
0010: 02 72 D8 02 70 D0 74 1D   DC 80 21 20 5D EB 5F 0E  .r..p.t...! ]._.
0020: F1 F6 DC 5E 0B 0B 0B 0B   0B 0B 0B 0B 0B 0B 0B 0B  ...^............
ExecuteThread: '2' for queue: 'weblogic.socket.Muxer', WRITE: TLSv1 Handshake, length = 48
%% Cached server session: [Session-7, TLS_RSA_WITH_AES_128_CBC_SHA]
[Raw write]: length = 6
0000: 14 03 01 00 01 01                                  ......
[Raw write]: length = 53
0000: 16 03 01 00 30 2F 73 F6   0E B7 DD 21 BC D7 D9 BE  ....0/s....!....
0010: 02 77 E6 96 7C 4D 4C 89   A5 1B C9 A5 78 2C 8F D8  .w...ML.....x,..

 ... (생략)




위의 로그와 같이 TLS 통신의 항목과 순서에 대해서 찾아가다보면 어느지점에 문제가 있는지 디버깅이 가능하다.





참조
 - https://docs.oracle.com/javase/7/docs/technotes/guides/security/jsse/ReadDebug.html
 - https://www.ibm.com/support/knowledgecenter/en/SSYKE2_6.0.0/com.ibm.java.security.component.60.doc/security-component/jsse2Docs/debug.html
 - https://b.luavis.kr/server/tls-101
 - https://rsec.kr/?p=455

댓글 없음 :

댓글 쓰기