Improving logging in Krb5LoginModule

[Wei-Jun Wang]

I've filed https://bugs.openjdk.org/browse/JDK-8327818.

But first, in order to make sure the debug option in Krb5LoginModule and other JGSS/krb5-related system properties still work, there needs a way to instantiate a Debug object without providing the `-Djava.security.debug` system property.

For example, in Krb5LoginModule, currently we have

       boolean debug = "true".equalsIgnoreCase((String)options.get("debug"));

And I'm thinking of

       Debug debug = Debug.of("krb5loginmodule", (String)options.get("debug"));

Hopefully this .of() method can automatically support thread info or timestamp if the "debug" option has it.

Also, I am wondering if even without he "debug" option, user can set -Djava.security.debug=krb5loginmodule to show debug info there. However, some krb5 debug info might contain sensitive information like passwords or secret keys, so maybe there is a little danger to cover them with `-Djava.security.debug=all`.

Thanks,
Weijun


> On Mar 11, 2024, at 5:43 AM, Sean Coffey <sean.coffey at oracle.com> wrote:
> 
> 
> On 10/03/2024 16:01, Wei-Jun Wang wrote:
>> Hi Seán,
>> 
>> I know you are working on enhancing the security debug output with timestamps and thread info now. Do you think it can also cover Kerberos?
> I'd love to see Kerberos fall under the same debug implementation used by other JDK security libraries. I suspect it was a standalone product a long time back and had its own debug impl as a result. I'd like to see it worked separate to the ongoing decorator work that's taking place via JDK-8051959. The debug stack for krb5 is different and managed via a Map currently. Maybe Peter could start out by moving the debug output from System.out calls to the sun.security.util.Debug calls as suggested.
> 
> Using a Logger should be on the radar also. We'd have to use the System.Logger interface since that's the only one guaranteed to be present in the runtime. Maybe the Logger work can be done as a follow on task. I'm also examining the potential for wider use of Logger in security libs. The TLS javax.net.debug option already offers use of a Logger but the configuration in both the calling code and backend remains a blocker to adoption IMO. (e.g. no option to configure Level correctly and static backend configuration options may not be set up correctly at the time logger output becomes necessary to debug an issue)
> 
> regards,
> Sean.
> 
>> 
>> Traditionally, Kerberos debugging is independent of other security areas and itself is quite complicated. It includes the "debug" label in JAAS LoginModule (as Peter pointed out below) and separate system properties like sun.security.krb5.debug, sun.security.jgss.debug, sun.security.nativegss.debug, and sun.security.spnego.debug. It will be definitely great if they can enjoy the enhancement of sun.security.util.Debug.
>> 
>> BTW, Peter also mentioned a JUL logger. IIUC, our current debug messages are only sent to System.err, right?
>> 
>> Thanks,
>> Weijun
>> 
>> 
>> 
>>> On Mar 9, 2024, at 4:15 PM, Horváth Péter Gergely <horvath.peter.gergely at gmail.com> wrote:
>>> 
>>> Dear All,
>>> 
>>> In the past, I had issues with debug logging in Krb5LoginModule: if debug is enabled,
>>> messages are simply written to the stdout. It is relatively hard to correlate these
>>> messages with application logs, as there are no timestamps for Krb5LoginModule output messages.
>>> 
>>> Imagine a server fails to service a request, due to its failure to communicate with
>>> another Kerberized server. The failure itself will be logged properly, but there is no way
>>> for an operator to easily find and correlate Krb5LoginModule debug output.
>>> (We are talking about servers unders heavy load)
>>> 
>>> I think debug logging in Krb5LoginModule should be improved; e.g. at least, messages
>>> should be sent to both stdout and a JUL logger maybe?
>>> 
>>> I would be happy to implement the code change if someone is willing to sponsor this issue.
>>> 
>>> Could someone please help here?
>>> 
>>> Thanks,
>>> Peter