Improving logging in Krb5LoginModule

[Seán Coffey]

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