xref: /freebsd/crypto/krb5/src/kdc/kdc_log.c (revision 7f2fe78b9dd5f51c821d771b63d2e096f6fd49e9)
1*7f2fe78bSCy Schubert /* -*- mode: c; c-basic-offset: 4; indent-tabs-mode: nil -*- */
2*7f2fe78bSCy Schubert /* kdc/kdc_log.c - Logging functions for KDC requests */
3*7f2fe78bSCy Schubert /*
4*7f2fe78bSCy Schubert  * Copyright 2008,2009 by the Massachusetts Institute of Technology.
5*7f2fe78bSCy Schubert  * All Rights Reserved.
6*7f2fe78bSCy Schubert  *
7*7f2fe78bSCy Schubert  * Export of this software from the United States of America may
8*7f2fe78bSCy Schubert  *   require a specific license from the United States Government.
9*7f2fe78bSCy Schubert  *   It is the responsibility of any person or organization contemplating
10*7f2fe78bSCy Schubert  *   export to obtain such a license before exporting.
11*7f2fe78bSCy Schubert  *
12*7f2fe78bSCy Schubert  * WITHIN THAT CONSTRAINT, permission to use, copy, modify, and
13*7f2fe78bSCy Schubert  * distribute this software and its documentation for any purpose and
14*7f2fe78bSCy Schubert  * without fee is hereby granted, provided that the above copyright
15*7f2fe78bSCy Schubert  * notice appear in all copies and that both that copyright notice and
16*7f2fe78bSCy Schubert  * this permission notice appear in supporting documentation, and that
17*7f2fe78bSCy Schubert  * the name of M.I.T. not be used in advertising or publicity pertaining
18*7f2fe78bSCy Schubert  * to distribution of the software without specific, written prior
19*7f2fe78bSCy Schubert  * permission.  Furthermore if you modify this software you must label
20*7f2fe78bSCy Schubert  * your software as modified software and not distribute it in such a
21*7f2fe78bSCy Schubert  * fashion that it might be confused with the original M.I.T. software.
22*7f2fe78bSCy Schubert  * M.I.T. makes no representations about the suitability of
23*7f2fe78bSCy Schubert  * this software for any purpose.  It is provided "as is" without express
24*7f2fe78bSCy Schubert  * or implied warranty.
25*7f2fe78bSCy Schubert  */
26*7f2fe78bSCy Schubert 
27*7f2fe78bSCy Schubert #include "k5-int.h"
28*7f2fe78bSCy Schubert #include "kdc_util.h"
29*7f2fe78bSCy Schubert #include <syslog.h>
30*7f2fe78bSCy Schubert #include "adm_proto.h"
31*7f2fe78bSCy Schubert 
32*7f2fe78bSCy Schubert /*
33*7f2fe78bSCy Schubert  * A note on KDC-status string format.
34*7f2fe78bSCy Schubert  *
35*7f2fe78bSCy Schubert  * - All letters in the status string should be capitalized;
36*7f2fe78bSCy Schubert  * - the words in the status phrase are separated by underscores;
37*7f2fe78bSCy Schubert  * - abbreviations should be avoided.  Some acceptable "standard" acronyms
38*7f2fe78bSCy Schubert  *   are AS_REQ, TGS_REP etc.
39*7f2fe78bSCy Schubert  * - since in almost all cases KDC status string is set on error, no need
40*7f2fe78bSCy Schubert  *   to state this fact as part of the status string;
41*7f2fe78bSCy Schubert  * - KDC status string should be an imperative phrase.
42*7f2fe78bSCy Schubert  *
43*7f2fe78bSCy Schubert  * Example: "MAKE_RANDOM_KEY"
44*7f2fe78bSCy Schubert  */
45*7f2fe78bSCy Schubert 
46*7f2fe78bSCy Schubert /* Main logging routines for ticket requests.
47*7f2fe78bSCy Schubert 
48*7f2fe78bSCy Schubert    There are a few simple cases -- unparseable requests mainly --
49*7f2fe78bSCy Schubert    where messages are logged otherwise, but once a ticket request can
50*7f2fe78bSCy Schubert    be decoded in some basic way, these routines are used for logging
51*7f2fe78bSCy Schubert    the details.  */
52*7f2fe78bSCy Schubert 
53*7f2fe78bSCy Schubert /* "status" is null to indicate success.  */
54*7f2fe78bSCy Schubert /* Someday, pass local address/port as well.  */
55*7f2fe78bSCy Schubert /* Currently no info about name canonicalization is logged.  */
56*7f2fe78bSCy Schubert void
log_as_req(krb5_context context,const krb5_fulladdr * local_addr,const krb5_fulladdr * remote_addr,krb5_kdc_req * request,krb5_kdc_rep * reply,krb5_db_entry * client,const char * cname,krb5_db_entry * server,const char * sname,krb5_timestamp authtime,const char * status,krb5_error_code errcode,const char * emsg)57*7f2fe78bSCy Schubert log_as_req(krb5_context context,
58*7f2fe78bSCy Schubert            const krb5_fulladdr *local_addr,
59*7f2fe78bSCy Schubert            const krb5_fulladdr *remote_addr,
60*7f2fe78bSCy Schubert            krb5_kdc_req *request, krb5_kdc_rep *reply,
61*7f2fe78bSCy Schubert            krb5_db_entry *client, const char *cname,
62*7f2fe78bSCy Schubert            krb5_db_entry *server, const char *sname,
63*7f2fe78bSCy Schubert            krb5_timestamp authtime,
64*7f2fe78bSCy Schubert            const char *status, krb5_error_code errcode, const char *emsg)
65*7f2fe78bSCy Schubert {
66*7f2fe78bSCy Schubert     const char *fromstring = 0;
67*7f2fe78bSCy Schubert     char fromstringbuf[70];
68*7f2fe78bSCy Schubert     char *ktypestr = NULL;
69*7f2fe78bSCy Schubert     const char *cname2 = cname ? cname : "<unknown client>";
70*7f2fe78bSCy Schubert     const char *sname2 = sname ? sname : "<unknown server>";
71*7f2fe78bSCy Schubert 
72*7f2fe78bSCy Schubert     fromstring = inet_ntop(ADDRTYPE2FAMILY(remote_addr->address->addrtype),
73*7f2fe78bSCy Schubert                            remote_addr->address->contents,
74*7f2fe78bSCy Schubert                            fromstringbuf, sizeof(fromstringbuf));
75*7f2fe78bSCy Schubert     if (!fromstring)
76*7f2fe78bSCy Schubert         fromstring = "<unknown>";
77*7f2fe78bSCy Schubert 
78*7f2fe78bSCy Schubert     ktypestr = ktypes2str(request->ktype, request->nktypes);
79*7f2fe78bSCy Schubert 
80*7f2fe78bSCy Schubert     if (status == NULL) {
81*7f2fe78bSCy Schubert         /* success */
82*7f2fe78bSCy Schubert         char *rep_etypestr = rep_etypes2str(reply);
83*7f2fe78bSCy Schubert         krb5_klog_syslog(LOG_INFO, _("AS_REQ (%s) %s: ISSUE: authtime %u, %s, "
84*7f2fe78bSCy Schubert                                      "%s for %s"),
85*7f2fe78bSCy Schubert                          ktypestr ? ktypestr : "", fromstring,
86*7f2fe78bSCy Schubert                          (unsigned int)authtime,
87*7f2fe78bSCy Schubert                          rep_etypestr ? rep_etypestr : "", cname2, sname2);
88*7f2fe78bSCy Schubert         free(rep_etypestr);
89*7f2fe78bSCy Schubert     } else {
90*7f2fe78bSCy Schubert         /* fail */
91*7f2fe78bSCy Schubert         krb5_klog_syslog(LOG_INFO, _("AS_REQ (%s) %s: %s: %s for %s%s%s"),
92*7f2fe78bSCy Schubert                          ktypestr ? ktypestr : "", fromstring, status, cname2,
93*7f2fe78bSCy Schubert                          sname2, emsg ? ", " : "", emsg ? emsg : "");
94*7f2fe78bSCy Schubert     }
95*7f2fe78bSCy Schubert     krb5_db_audit_as_req(context, request,
96*7f2fe78bSCy Schubert                          local_addr->address, remote_addr->address,
97*7f2fe78bSCy Schubert                          client, server, authtime, errcode);
98*7f2fe78bSCy Schubert 
99*7f2fe78bSCy Schubert     free(ktypestr);
100*7f2fe78bSCy Schubert }
101*7f2fe78bSCy Schubert 
102*7f2fe78bSCy Schubert /*
103*7f2fe78bSCy Schubert  * Unparse a principal for logging purposes and limit the string length.
104*7f2fe78bSCy Schubert  * Ignore errors because the most likely errors are memory exhaustion, and many
105*7f2fe78bSCy Schubert  * other things will fail in the logging functions in that case.
106*7f2fe78bSCy Schubert  */
107*7f2fe78bSCy Schubert static void
unparse_and_limit(krb5_context ctx,krb5_principal princ,char ** str)108*7f2fe78bSCy Schubert unparse_and_limit(krb5_context ctx, krb5_principal princ, char **str)
109*7f2fe78bSCy Schubert {
110*7f2fe78bSCy Schubert     /* Ignore errors */
111*7f2fe78bSCy Schubert     krb5_unparse_name(ctx, princ, str);
112*7f2fe78bSCy Schubert     limit_string(*str);
113*7f2fe78bSCy Schubert }
114*7f2fe78bSCy Schubert 
115*7f2fe78bSCy Schubert /* Here "status" must be non-null.  Error code
116*7f2fe78bSCy Schubert    KRB5KDC_ERR_SERVER_NOMATCH is handled specially.
117*7f2fe78bSCy Schubert 
118*7f2fe78bSCy Schubert    Currently no info about name canonicalization is logged.  */
119*7f2fe78bSCy Schubert void
log_tgs_req(krb5_context ctx,const krb5_fulladdr * from,krb5_kdc_req * request,krb5_kdc_rep * reply,krb5_principal cprinc,krb5_principal sprinc,krb5_principal altcprinc,krb5_timestamp authtime,unsigned int c_flags,const char * status,krb5_error_code errcode,const char * emsg)120*7f2fe78bSCy Schubert log_tgs_req(krb5_context ctx, const krb5_fulladdr *from,
121*7f2fe78bSCy Schubert             krb5_kdc_req *request, krb5_kdc_rep *reply,
122*7f2fe78bSCy Schubert             krb5_principal cprinc, krb5_principal sprinc,
123*7f2fe78bSCy Schubert             krb5_principal altcprinc,
124*7f2fe78bSCy Schubert             krb5_timestamp authtime,
125*7f2fe78bSCy Schubert             unsigned int c_flags,
126*7f2fe78bSCy Schubert             const char *status, krb5_error_code errcode, const char *emsg)
127*7f2fe78bSCy Schubert {
128*7f2fe78bSCy Schubert     char *ktypestr = NULL, *rep_etypestr = NULL;
129*7f2fe78bSCy Schubert     const char *fromstring = 0;
130*7f2fe78bSCy Schubert     char fromstringbuf[70];
131*7f2fe78bSCy Schubert     char *cname = NULL, *sname = NULL, *altcname = NULL;
132*7f2fe78bSCy Schubert     char *logcname = NULL, *logsname = NULL, *logaltcname = NULL;
133*7f2fe78bSCy Schubert 
134*7f2fe78bSCy Schubert     fromstring = inet_ntop(ADDRTYPE2FAMILY(from->address->addrtype),
135*7f2fe78bSCy Schubert                            from->address->contents,
136*7f2fe78bSCy Schubert                            fromstringbuf, sizeof(fromstringbuf));
137*7f2fe78bSCy Schubert     if (!fromstring)
138*7f2fe78bSCy Schubert         fromstring = "<unknown>";
139*7f2fe78bSCy Schubert 
140*7f2fe78bSCy Schubert     unparse_and_limit(ctx, cprinc, &cname);
141*7f2fe78bSCy Schubert     logcname = (cname != NULL) ? cname : "<unknown client>";
142*7f2fe78bSCy Schubert     unparse_and_limit(ctx, sprinc, &sname);
143*7f2fe78bSCy Schubert     logsname = (sname != NULL) ? sname : "<unknown server>";
144*7f2fe78bSCy Schubert     unparse_and_limit(ctx, altcprinc, &altcname);
145*7f2fe78bSCy Schubert     logaltcname = (altcname != NULL) ? altcname : "<unknown>";
146*7f2fe78bSCy Schubert 
147*7f2fe78bSCy Schubert     /* Differences: server-nomatch message logs 2nd ticket's client
148*7f2fe78bSCy Schubert        name (useful), and doesn't log ktypestr (probably not
149*7f2fe78bSCy Schubert        important).  */
150*7f2fe78bSCy Schubert     if (errcode != KRB5KDC_ERR_SERVER_NOMATCH) {
151*7f2fe78bSCy Schubert         ktypestr = ktypes2str(request->ktype, request->nktypes);
152*7f2fe78bSCy Schubert         if (reply != NULL)
153*7f2fe78bSCy Schubert             rep_etypestr = rep_etypes2str(reply);
154*7f2fe78bSCy Schubert         krb5_klog_syslog(LOG_INFO, _("TGS_REQ (%s) %s: %s: authtime %u, %s%s "
155*7f2fe78bSCy Schubert                                      "%s for %s%s%s"),
156*7f2fe78bSCy Schubert                          ktypestr ? ktypestr : "", fromstring, status,
157*7f2fe78bSCy Schubert                          (unsigned int)authtime,
158*7f2fe78bSCy Schubert                          rep_etypestr ? rep_etypestr : "",
159*7f2fe78bSCy Schubert                          !errcode ? "," : "", logcname, logsname,
160*7f2fe78bSCy Schubert                          errcode ? ", " : "", errcode ? emsg : "");
161*7f2fe78bSCy Schubert         if (isflagset(c_flags, KRB5_KDB_FLAG_PROTOCOL_TRANSITION))
162*7f2fe78bSCy Schubert             krb5_klog_syslog(LOG_INFO,
163*7f2fe78bSCy Schubert                              _("... PROTOCOL-TRANSITION s4u-client=%s"),
164*7f2fe78bSCy Schubert                              logaltcname);
165*7f2fe78bSCy Schubert         else if (isflagset(c_flags, KRB5_KDB_FLAG_CONSTRAINED_DELEGATION))
166*7f2fe78bSCy Schubert             krb5_klog_syslog(LOG_INFO,
167*7f2fe78bSCy Schubert                              _("... CONSTRAINED-DELEGATION s4u-client=%s"),
168*7f2fe78bSCy Schubert                              logaltcname);
169*7f2fe78bSCy Schubert 
170*7f2fe78bSCy Schubert     } else
171*7f2fe78bSCy Schubert         krb5_klog_syslog(LOG_INFO, _("TGS_REQ %s: %s: authtime %u, %s for %s, "
172*7f2fe78bSCy Schubert                                      "2nd tkt client %s"),
173*7f2fe78bSCy Schubert                          fromstring, status, (unsigned int)authtime,
174*7f2fe78bSCy Schubert                          logcname, logsname, logaltcname);
175*7f2fe78bSCy Schubert 
176*7f2fe78bSCy Schubert     free(rep_etypestr);
177*7f2fe78bSCy Schubert     free(ktypestr);
178*7f2fe78bSCy Schubert     krb5_free_unparsed_name(ctx, cname);
179*7f2fe78bSCy Schubert     krb5_free_unparsed_name(ctx, sname);
180*7f2fe78bSCy Schubert     krb5_free_unparsed_name(ctx, altcname);
181*7f2fe78bSCy Schubert }
182*7f2fe78bSCy Schubert 
183*7f2fe78bSCy Schubert void
log_tgs_badtrans(krb5_context ctx,krb5_principal cprinc,krb5_principal sprinc,krb5_data * trcont,krb5_error_code errcode)184*7f2fe78bSCy Schubert log_tgs_badtrans(krb5_context ctx, krb5_principal cprinc,
185*7f2fe78bSCy Schubert                  krb5_principal sprinc, krb5_data *trcont,
186*7f2fe78bSCy Schubert                  krb5_error_code errcode)
187*7f2fe78bSCy Schubert {
188*7f2fe78bSCy Schubert     unsigned int tlen;
189*7f2fe78bSCy Schubert     char *tdots;
190*7f2fe78bSCy Schubert     const char *emsg = NULL;
191*7f2fe78bSCy Schubert     char *cname = NULL, *sname = NULL;
192*7f2fe78bSCy Schubert     char *logcname = NULL, *logsname = NULL;
193*7f2fe78bSCy Schubert 
194*7f2fe78bSCy Schubert     unparse_and_limit(ctx, cprinc, &cname);
195*7f2fe78bSCy Schubert     logcname = (cname != NULL) ? cname : "<unknown client>";
196*7f2fe78bSCy Schubert     unparse_and_limit(ctx, sprinc, &sname);
197*7f2fe78bSCy Schubert     logsname = (sname != NULL) ? sname : "<unknown server>";
198*7f2fe78bSCy Schubert 
199*7f2fe78bSCy Schubert     tlen = trcont->length;
200*7f2fe78bSCy Schubert     tdots = tlen > 125 ? "..." : "";
201*7f2fe78bSCy Schubert     tlen = tlen > 125 ? 125 : tlen;
202*7f2fe78bSCy Schubert 
203*7f2fe78bSCy Schubert     if (errcode == KRB5KRB_AP_ERR_ILL_CR_TKT)
204*7f2fe78bSCy Schubert         krb5_klog_syslog(LOG_INFO, _("bad realm transit path from '%s' "
205*7f2fe78bSCy Schubert                                      "to '%s' via '%.*s%s'"),
206*7f2fe78bSCy Schubert                          logcname, logsname, tlen,
207*7f2fe78bSCy Schubert                          trcont->data, tdots);
208*7f2fe78bSCy Schubert     else {
209*7f2fe78bSCy Schubert         emsg = krb5_get_error_message(ctx, errcode);
210*7f2fe78bSCy Schubert         krb5_klog_syslog(LOG_ERR, _("unexpected error checking transit "
211*7f2fe78bSCy Schubert                                     "from '%s' to '%s' via '%.*s%s': %s"),
212*7f2fe78bSCy Schubert                          logcname, logsname, tlen,
213*7f2fe78bSCy Schubert                          trcont->data, tdots,
214*7f2fe78bSCy Schubert                          emsg);
215*7f2fe78bSCy Schubert         krb5_free_error_message(ctx, emsg);
216*7f2fe78bSCy Schubert         emsg = NULL;
217*7f2fe78bSCy Schubert     }
218*7f2fe78bSCy Schubert     krb5_free_unparsed_name(ctx, cname);
219*7f2fe78bSCy Schubert     krb5_free_unparsed_name(ctx, sname);
220*7f2fe78bSCy Schubert }
221*7f2fe78bSCy Schubert 
222*7f2fe78bSCy Schubert void
log_tgs_alt_tgt(krb5_context context,krb5_principal p)223*7f2fe78bSCy Schubert log_tgs_alt_tgt(krb5_context context, krb5_principal p)
224*7f2fe78bSCy Schubert {
225*7f2fe78bSCy Schubert     char *sname;
226*7f2fe78bSCy Schubert     if (krb5_unparse_name(context, p, &sname)) {
227*7f2fe78bSCy Schubert         krb5_klog_syslog(LOG_INFO,
228*7f2fe78bSCy Schubert                          _("TGS_REQ: issuing alternate <un-unparsable> TGT"));
229*7f2fe78bSCy Schubert     } else {
230*7f2fe78bSCy Schubert         limit_string(sname);
231*7f2fe78bSCy Schubert         krb5_klog_syslog(LOG_INFO, _("TGS_REQ: issuing TGT %s"), sname);
232*7f2fe78bSCy Schubert         free(sname);
233*7f2fe78bSCy Schubert     }
234*7f2fe78bSCy Schubert     /* OpenSolaris: audit_krb5kdc_tgs_req_alt_tgt(...) */
235*7f2fe78bSCy Schubert }
236