Code review request: 7013776 Multithreaded JSSE application debug information is hard to read

[Xuelei Fan]

webrev: http://cr.openjdk.java.net/~xuelei/7013776/webrev.01/

At present, Oracle JSSE provider, SunJSSE, uses hard coded System.out to
logger the debug information, with Java option "javax.net.debug".

The benefit of the debug mechanism is that it is simple and
straightforward. The drawback is that it is hard to redirect to other
output stream, hard to parse in multi-threads environment[2], and hard
to customize the output[3].

In this update, I try to reconstruct the output to include more
information, such as thread id, log time, etc.

A typical output looks like:

{
  "logger"      : "javax.net.ssl.handshake",
  "level"       : "FINE",
  "thread id"   : "0A",
  "thread name" : "Thread-1",
  "time"        : "2011-09-20 18:37:19.453 PDT",
  "message"     : "SESSION KEYGEN, PreMaster Secret",
  "specifics"   : [
    0000: 03 02 48 B2 91 B2 0E 63   96 14 ED FA 77 8E EF 67
..H....c....w..g
    0010: 40 42 65 9D C2 5B 37 60   E3 D1 48 BF 42 2B F3 20
@Be..[7`..H.B+.
    0020: 6E 06 27 6C D7 8C E5 FA   77 91 96 EE ED 89 95 AA
n.'l....w.......
  ]
}

Please refer to the attached file for a full SSL/TLS connection log.

Q1: Why not use java.util.logging

It is required the JSSE/SunJSSE component should be independent from
java.util.logging component. So SunJSSE implementation cannot use
java.util.logging APIs.

Q2: Why not use sun.util.logging

At present, System.out is the output stream. We need to be compatible
with it. The default output stream of sun.util.logging is System.err,
there is no flexible approach to reset it to System.out.

Q3: Why not using Weijun's suggested Describle interface?

I tried to define and use Describle interface. But I got type-safe
heterogeneous map and generic programing puzzles, and more, it is too
flexible to determine what's the instance of an object.

For example,
    if (object instanceof Map)

is legal, but

    if (object instanceof Map<String, Object>)

is illegal.

Q4: The output looks like JSON, but not strictly following JSON
specifications.

Yes, the output looks like JSON string, array and object. But for easily
parser the binary data, the binary data are printed with reader friendly
format, like this:

  "specifics"   : [
    0000: 03 02 48 B2 91 B2 0E 63   96 14 ED FA 77 8E EF 67
..H....c....w..g
    0010: 40 42 65 9D C2 5B 37 60   E3 D1 48 BF 42 2B F3 20
@Be..[7`..H.B+.
    0020: 6E 06 27 6C D7 8C E5 FA   77 91 96 EE ED 89 95 AA
n.'l....w.......
  ]

Q5: what about the performance impact.
  The update does not hurt the performance

Q6: compatibility issue
  The update continue to use System.out as the default output stream,
but the output content is changed significantly. But as it only impact
oracle JSSE provider, it should not be significant compatibility issue.

Q7: Why defines Levels?
  I still think about using java/sun.util.logging APIs to make it more
flexible.

Q8: It seems you want to define "javax.net.debug.output" to redirect
output stream, why comment the code out?
  Yes, it's my initial idea to able to redirect out to customized output
stream. But I failed to find a proper approach to close the customized
output stream in JSSE implementation or in application code. I may
modify the code when I find a proper solution.

Q9: What's the map between debug options and Levels?
   If java option "javax.net.debug" is defined, the debug options (see
[1] for the define of the option) are mapped to three loggers:
   logger "javax.net.ssl.handshake" will support the following debug
options: handshake, keygen, session, seesioncache.
   logger "javax.net.ssl.managerment" will support debug options:
keymanager, trustmanager, sslctx, defaultctx.
   logger "javax.net.ssl" will support all other debug options.

Thanks,
Xuelei

[1]: the usage of "javax.net.debug" option:
------------------------
$ java -Djavax.net.debug=help Foo
all            turn on all debugging
ssl            turn on ssl debugging

The following can be used with ssl:
        record       enable per-record tracing
        handshake    print each handshake message
        keygen       print key generation data
        session      print session activity
        defaultctx   print default SSL initialization
        sslctx       print SSLContext tracing
        sessioncache print session cache tracing
        keymanager   print key manager tracing
        trustmanager print trust manager tracing
        pluggability print pluggability tracing

        handshake debugging can be widened with:
        data         hex dump of each handshake message
        verbose      verbose handshake message printing

        record debugging can be widened with:
        plaintext    hex dump of record plaintext
        packet       print raw SSL/TLS packets
------------------------

[2]: http://monaco.us.oracle.com/detail.jsf?cr=7013776
[3]:http://sim.ivi.co/2009/05/these-days-i-was-asked-about-strange.html
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: GenericBlockCipher.jtr
Url: http://mail.openjdk.java.net/pipermail/security-dev/attachments/20110921/056d9472/GenericBlockCipher.jtr