[krbdev.mit.edu #3277] doubled kerberos logging to stderr

[Denis Vlasenko via RT]

On Wednesday 07 December 2005 02:01, Tom Yu via RT wrote:
> Denis> Looks like krb5-1.4.3/src/lib/kadm5/logger.c:klog_vsyslog(...) routine, which
> Denis> formats these messages, outputs them twice.
> 
> Denis> Next, when I run exactly the same command, "krb5kdc -n", under daemontools,
> Denis> it gets unhappy:
> 
> Denis> 2005-12-04 22:05:34 krb5kdc: cannot parse <STDERR>
> Denis> 2005-12-04 22:05:34 krb5kdc: warning - logging entry syntax error
> Denis> 2005-12-04 22:05:34 krb5kdc: cannot parse <STDERR>
> Denis> 2005-12-04 22:05:34 krb5kdc: warning - logging entry syntax error
> 
> Denis> Replacing "default = STDERR" with "default = FILE:/proc/self/fd/2"
> Denis> helps.
>
...
> 
> While the error message is somewhat unhelpful, I suspect that the
> actual error is that fdopen(fileno(stderr)) is failing for some
> reason.  Fredrik Tolf, in a message to the kerberos mailing list,
> appears to have discovered the actual reason for the doubled logs,
> which is a configuration file being read twice under some
> configurations.  What flags did you pass to configure when you built
> the source?

I instrumented code with a few a bit:

lib/kadm5/logger.c

    /*
     * Look up [logging]-><ename> in the profile.  If that doesn't
     * succeed, then look for [logging]->default.
     */
write(2, ename, strlen(ename));
write(2, "\n", strlen("\n"));
write(2, whoami, strlen(whoami));
write(2, "\n", strlen("\n"));
    logging_profent[0] = "logging";
    logging_profent[1] = ename;
    logging_profent[2] = (char *) NULL;
    logging_defent[0] = "logging";
    logging_defent[1] = "default";
    logging_defent[2] = (char *) NULL;
    logging_specs = (char **) NULL;
    ngood = 0;
    log_control.log_nentries = 0;
    if (/*!profile_get_values(kcontext->profile,
                            logging_profent,
                            &logging_specs) ||*/
        !profile_get_values(kcontext->profile,
                            logging_defent,
                            &logging_specs)) {
        /*
         * We have a match, so we first count the number of elements
         */
        for (log_control.log_nentries = 0;
             logging_specs[log_control.log_nentries];
             log_control.log_nentries++)
{
if(logging_specs[log_control.log_nentries]) write(2, logging_specs[log_control.log_nentries], strlen(logging_specs[log_control.log_nentries]));
write(2, "\n", strlen("\n"));
}
;

This is what my write's print:

kdc
krb5kdc
FILE:/proc/self/fd/2
FILE:/proc/self/fd/2

Obviously profile_get_values(kcontext->profile,
                            logging_defent,
                            &logging_specs) produces duplicates.
--
vda