Received: from biscayne-one-station.mit.edu (BISCAYNE-ONE-STATION.MIT.EDU [18.7.7.80]) by krbdev.mit.edu (8.9.3p2) with ESMTP id TAA22336; Tue, 6 Dec 2005 19:01:14 -0500 (EST)
Received: from outgoing.mit.edu (OUTGOING-AUTH.MIT.EDU [18.7.22.103]) by biscayne-one-station.mit.edu (8.12.4/8.9.2) with ESMTP id jB701Cxb002437 for <rt@krbdev.MIT.EDU>; Tue, 6 Dec 2005 19:01:13 -0500 (EST)
Received: from cathode-dark-space.mit.edu (CATHODE-DARK-SPACE.MIT.EDU [18.18.1.96]) (authenticated bits=56) (User authenticated as tlyu@ATHENA.MIT.EDU) by outgoing.mit.edu (8.13.1/8.12.4) with ESMTP id jB7015wN015077 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NOT) for <rt@krbdev.MIT.EDU>; Tue, 6 Dec 2005 19:01:06 -0500 (EST)
Received: (from tlyu@localhost) by cathode-dark-space.mit.edu (8.12.9) id jB7015x1006016; Tue, 6 Dec 2005 19:01:05 -0500 (EST)
To: rt@krbdev.mit.edu
Subject: Re: [krbdev.mit.edu #3277] doubled kerberos logging to stderr
References: <rt-3277-15210.6.69231221605493@krbdev.mit.edu>
From: Tom Yu <tlyu@MIT.EDU>
Date: Tue, 06 Dec 2005 19:01:05 -0500
In-Reply-To: <rt-3277-15210.6.69231221605493@krbdev.mit.edu> (Denis Vlasenko via's message of "Tue, 6 Dec 2005 18:08:48 -0500 (EST)")
Message-Id: <ldvvey1u666.fsf@cathode-dark-space.mit.edu>
Lines: 49
MIME-Version: 1.0
Content-Type: text/plain; charset=iso-8859-1
X-Spam-Score: 1.217
X-Spam-Level: * (1.217)
X-Spam-Flag: NO
X-Scanned-BY: MIMEDefang 2.42
Content-Transfer-Encoding: 8bit
X-MIME-Autoconverted: from quoted-printable to 8bit by krbdev.mit.edu id TAA22336
RT-Send-Cc: 
X-RT-Original-Encoding: iso-8859-1
Content-Length: 2409

>>>>> "Denis" == Denis Vlasenko via RT <rt-comment@krbdev.mit.edu> writes:

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.

Denis> Fragment of strace output where it happens:

[...]

Denis> fcntl64(2, F_GETFL)                     = 0x1 (flags O_WRONLY)
Denis> write(2, "krb5kdc: cannot parse <STDERR>\n", 31) = 31
Denis> write(2, "krb5kdc: warning - logging entry"..., 46) = 46
Denis> fcntl64(2, F_GETFL)                     = 0x1 (flags O_WRONLY)
Denis> write(2, "krb5kdc: cannot parse <STDERR>\n", 31) = 31
Denis> write(2, "krb5kdc: warning - logging entry"..., 46) = 46

Denis> Looks like something fails here:

Denis> krb5-1.4.3/src/lib/kadm5/logger.c
Denis> ...
Denis>                 else if (!strcasecmp(cp, "STDERR")) {
Denis>                     log_control.log_entries[i].lfu_filep =
Denis>                         fdopen(fileno(stderr), "a+");
Denis>                     if (log_control.log_entries[i].lfu_filep) {
Denis> is not set somehow ===> log_control.log_entries[i].log_type = K_LOG_STDERR;
Denis>                         log_control.log_entries[i].lfu_fname =
Denis>                             "standard error";
Denis>                     }

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?

---Tom