Ticket History #63: krb5kdc and kadmind don't syslog properly

From jhawk@MIT.EDU Sat Oct 5 19:13:04 1996
Received: from MIT.EDU (SOUTH-STATION-ANNEX.MIT.EDU [18.72.1.2]) by rt-11.MIT.EDU (8.7.5/8.7.3) with SMTP id TAA29387 for <bugs@RT-11.MIT.EDU>; Sat, 5 Oct 1996 19:13:03 -0400
Received: from STEVE-DALLAS.MIT.EDU by MIT.EDU with SMTP
id AA22631; Sat, 5 Oct 96 19:13:03 EDT
Received: by steve-dallas.MIT.EDU (940816.SGI.8.6.9/4.7) id TAA15374; Sat, 5 Oct 1996 19:13:02 -0400
Message-Id: <199610052313.TAA15374@steve-dallas.MIT.EDU>
Date: Sat, 5 Oct 1996 19:13:02 -0400
From: John Hawkinson <jhawk@bbnplanet.com>
To: krb5-bugs@MIT.EDU
Subject: Re: krb5kdc and kadmind don't syslog properly

BBN Planet
System: SunOS all-purpo 4.1.4 4 sun4m
Architecture: sun4

krb5kdc and kadmind syslog incorrectly. They syslog to a bogus
facility, and fail to include their pid and process name.


Stumble through setting up kerberos. Check your syslog
file. Observe something like:

Oct 5 15:11:36 liam-gw krb5kdc[88]: PROCESS_V4:UNKNOWN "jhawk/test" ""
Oct 5 15:49:29 liam-gw syslog: Cannot find/read stored master key - while fetching master key K/M for realm BBNPLANET.NET

The first line is from beta 5. The second is from beta 7. See the difference?

Also, "trace" a process while trying to figure out how
it is losing. Observe that the strings it hands to sendto()
start with <13> and <14>. Surprise, that's LOG_USER:
at LOG_KWARNING or LOG_NOTICE.

#define LOG_USER (1<<3) /* random user-level messages */
#define LOG_WARNING 4 /* warning conditions */
#define LOG_NOTICE 5 /* normal but signification condition */

<how to correct or work around the problem, if known (multiple lines)>

From: "Barry Jaspan" <bjaspan@MIT.EDU>
To: jhawk@bbnplanet.com
Cc: krb5-bugs@MIT.EDU
Subject: Re: krb5-kdc/63: krb5kdc and kadmind don't syslog properly
Date: Tue, 15 Oct 1996 17:34:31 -0400

John,

I am trying to figure out what is going on with kdc and kadmind
logging. Please send me the krb5.conf [logging] stanza you were using
that was not doing what you expect.

Here's what I have found so far. With beta 7, when I set up kadmind
(for example) to log via syslog, I get entries like

Oct 15 17:14:11 DUN-DUN-NOODLES kadmind[4437]: Request: kadm5_init,
admin@SECURE-TEST.OV.COM, success, client=admin@SECURE-TEST.OV.COM,
service=kadmin/admin@SECURE-TEST.OV.COM, addr=18.177.1.44

but when I set it up to log to anything other than syslog, I get
entries like

Oct 15 17:12:56 Request: kadm5_init, admin@SECURE-TEST.OV.COM,
success, client=admin@SECURE-TEST.OV.COM,
service=kadmin/admin@SECURE-TEST.OV.COM, addr=18.177.1.44

So, non-syslog entries do not contain the hostname, process name, and
pid. I have found the cause of this problem (a simple #define
controlling which format should be used), and I'll change it for the
next release.

I have also figured out just what it means you specify something like:

[logging]
admin_server = SYSLOG=ERR:LOCAL6

kadmind (and presumably krb5kdc too) can log messages in two ways: via
krb5_klog_syslog(), and via com_err(). When it logs via
krb5_klog_syslog(), the message will use whatever severity is
specified in the function call, and the facility in the logging
relation (in this case, LOCAL6). When it logs via com_err, it will
log to both the facility and the severity in the logging stanza.

Naturally, this all needs to be documented better, and probably
kadmind and krb5kdc need to be checked to make sure they are using
syslog and com_err in a consistent fashion. However, none of what
I've said complete explains the behavior you reported, so I want to
make sure I understand your problem before moving on with it.

Barry


From: John Hawkinson <jhawk@bbnplanet.com>
To: krb5-bugs@MIT.EDU
Cc: bjaspan@MIT.EDU
Subject: Re: krb5-kdc/63: krb5kdc and kadmind don't syslog properly
Date: Tue, 15 Oct 1996 17:46:24 -0400 (EDT)

Just to keep the continuity of the PR log when the convesation
moved to zephyr:

Me: I was using no logging stanza whatsoever
Barry: Ah. Gee, that does look wrong...

State-Changed-From-To: open-closed
State-Changed-By: bjaspan
State-Changed-When: Tue Oct 15 18:04:24 1996
State-Changed-Why:

Fixed. Files:

lib/kadm5/ChangeLog:1.14
lib/kadm5/logger.c:1.3