From: Ken Raeburn Date: Mon, 22 Dec 2008 04:40:39 +0000 (+0000) Subject: Collect ticket-request logging calls together in one place for easier X-Git-Tag: krb5-1.7-alpha1~139 X-Git-Url: http://git.tremily.us/?a=commitdiff_plain;h=51ea86b7519d3ed5c10135529726a37c1b5d9709;p=krb5.git Collect ticket-request logging calls together in one place for easier customization. git-svn-id: svn://anonsvn.mit.edu/krb5/trunk@21564 dc483132-0cff-0310-8789-dd5450dbe970 --- diff --git a/src/kdc/do_as_req.c b/src/kdc/do_as_req.c index 1fbe56fb0..8c65a637b 100644 --- a/src/kdc/do_as_req.c +++ b/src/kdc/do_as_req.c @@ -84,11 +84,9 @@ process_as_req(krb5_kdc_req *request, krb5_data *req_pkt, register int i; krb5_timestamp until, rtime; char *cname = 0, *sname = 0; - const char *fromstring = 0; - char ktypestr[128]; - char rep_etypestr[128]; - char fromstringbuf[70]; void *pa_context = NULL; + int did_log = 0; + const char *emsg = 0; #if APPLE_PKINIT asReqDebug("process_as_req top realm %s name %s\n", @@ -102,15 +100,6 @@ process_as_req(krb5_kdc_req *request, krb5_data *req_pkt, session_key.contents = 0; enc_tkt_reply.authorization_data = NULL; - ktypes2str(ktypestr, sizeof(ktypestr), - request->nktypes, request->ktype); - - fromstring = inet_ntop(ADDRTYPE2FAMILY (from->address->addrtype), - from->address->contents, - fromstringbuf, sizeof(fromstringbuf)); - if (!fromstring) - fromstring = ""; - if (!request->client) { status = "NULL_CLIENT"; errcode = KRB5KDC_ERR_C_PRINCIPAL_UNKNOWN; @@ -436,14 +425,8 @@ process_as_req(krb5_kdc_req *request, krb5_data *req_pkt, memset(reply.enc_part.ciphertext.data, 0, reply.enc_part.ciphertext.length); free(reply.enc_part.ciphertext.data); - rep_etypes2str(rep_etypestr, sizeof(rep_etypestr), &reply); - krb5_klog_syslog(LOG_INFO, - "AS_REQ (%s) %s: ISSUE: authtime %d, " - "%s, %s for %s", - ktypestr, - fromstring, authtime, - rep_etypestr, - cname, sname); + log_as_req(from, request, &reply, cname, sname, authtime, 0, 0, 0); + did_log = 1; #ifdef KRBCONF_KDC_MODIFIES_KDB /* @@ -454,30 +437,27 @@ process_as_req(krb5_kdc_req *request, krb5_data *req_pkt, update_client = 1; #endif /* KRBCONF_KDC_MODIFIES_KDB */ + goto egress; + errout: + assert (status != 0); + /* fall through */ + +egress: if (pa_context) free_padata_context(kdc_context, &pa_context); + if (errcode) + emsg = krb5_get_error_message(kdc_context, errcode); + if (status) { - const char * emsg = 0; - if (errcode) - emsg = krb5_get_error_message (kdc_context, errcode); - - krb5_klog_syslog(LOG_INFO, "AS_REQ (%s) %s: %s: %s for %s%s%s", - ktypestr, - fromstring, status, - cname ? cname : "", - sname ? sname : "", - errcode ? ", " : "", - errcode ? emsg : ""); - if (errcode) - krb5_free_error_message (kdc_context, emsg); + log_as_req(from, request, &reply, cname, sname, 0, + status, errcode, emsg); + did_log = 1; } if (errcode) { - int got_err = 0; if (status == 0) { - status = krb5_get_error_message (kdc_context, errcode); - got_err = 1; + status = emsg; } errcode -= ERROR_TABLE_BASE_krb5; if (errcode < 0 || errcode > 128) @@ -485,11 +465,10 @@ errout: errcode = prepare_error_as(request, errcode, &e_data, response, status); - if (got_err) { - krb5_free_error_message (kdc_context, status); - status = 0; - } + status = 0; } + if (emsg) + krb5_free_error_message(kdc_context, emsg); if (enc_tkt_reply.authorization_data != NULL) krb5_free_authdata(kdc_context, enc_tkt_reply.authorization_data); @@ -531,7 +510,7 @@ errout: } krb5_free_data_contents(kdc_context, &e_data); - + assert(did_log != 0); return errcode; } diff --git a/src/kdc/do_tgs_req.c b/src/kdc/do_tgs_req.c index fd862722e..3af539feb 100644 --- a/src/kdc/do_tgs_req.c +++ b/src/kdc/do_tgs_req.c @@ -1,7 +1,7 @@ /* * kdc/do_tgs_req.c * - * Copyright 1990,1991,2001,2007 by the Massachusetts Institute of Technology. + * Copyright 1990,1991,2001,2007,2008 by the Massachusetts Institute of Technology. * All Rights Reserved. * * Export of this software from the United States of America may @@ -49,7 +49,7 @@ static void find_alternate_tgs (krb5_kdc_req *, krb5_db_entry *, krb5_boolean *, int *); static krb5_error_code prepare_error_tgs (krb5_kdc_req *, krb5_ticket *, - int, const char *, krb5_data **, + int, krb5_data **, const char *); /*ARGSUSED*/ @@ -75,8 +75,7 @@ process_tgs_req(krb5_data *pkt, const krb5_fulladdr *from, krb5_timestamp until, rtime; krb5_keyblock encrypting_key; krb5_key_data *server_key; - char *cname = 0, *sname = 0, *tmp = 0; - const char *fromstring = 0; + char *cname = 0, *sname = 0, *altcname = 0; krb5_last_req_entry *nolrarray[2], nolrentry; /* krb5_address *noaddrarray[1]; */ krb5_enctype useenctype; @@ -84,9 +83,7 @@ process_tgs_req(krb5_data *pkt, const krb5_fulladdr *from, register int i; int firstpass = 1; const char *status = 0; - char ktypestr[128]; - char rep_etypestr[128]; - char fromstringbuf[70]; + const char *emsg = NULL; session_key.contents = 0; @@ -94,8 +91,6 @@ process_tgs_req(krb5_data *pkt, const krb5_fulladdr *from, if (retval) return retval; - ktypes2str(ktypestr, sizeof(ktypestr), - request->nktypes, request->ktype); /* * setup_server_realm() sets up the global realm-specific data pointer. */ @@ -104,12 +99,6 @@ process_tgs_req(krb5_data *pkt, const krb5_fulladdr *from, return retval; } - fromstring = inet_ntop(ADDRTYPE2FAMILY(from->address->addrtype), - from->address->contents, - fromstringbuf, sizeof(fromstringbuf)); - if (!fromstring) - fromstring = ""; - if ((errcode = krb5_unparse_name(kdc_context, request->server, &sname))) { status = "UNPARSING SERVER"; goto cleanup; @@ -423,8 +412,8 @@ tgt_again: KRB5_KEYUSAGE_TGS_REQ_AD_SESSKEY, 0, &request->authorization_data, &scratch))) { - status = "AUTH_ENCRYPT_FAIL"; free(scratch.data); + status = "AUTH_ENCRYPT_FAIL"; goto cleanup; } @@ -515,7 +504,7 @@ tgt_again: enc_tkt_reply.transited.tr_contents.data, tdots); else { - const char *emsg = krb5_get_error_message(kdc_context, errcode); + emsg = krb5_get_error_message(kdc_context, errcode); krb5_klog_syslog (LOG_ERR, "unexpected error checking transit from " "'%s' to '%s' via '%.*s%s': %s", @@ -525,6 +514,7 @@ tgt_again: enc_tkt_reply.transited.tr_contents.data, tdots, emsg); krb5_free_error_message(kdc_context, emsg); + emsg = NULL; } } else krb5_klog_syslog (LOG_INFO, "not checking transit path"); @@ -551,19 +541,13 @@ tgt_again: krb5_enc_tkt_part *t2enc = request->second_ticket[st_idx]->enc_part2; krb5_principal client2 = t2enc->client; if (!krb5_principal_compare(kdc_context, request->server, client2)) { - if ((errcode = krb5_unparse_name(kdc_context, client2, &tmp))) - tmp = 0; - if (tmp != NULL) - limit_string(tmp); - - krb5_klog_syslog(LOG_INFO, - "TGS_REQ %s: 2ND_TKT_MISMATCH: " - "authtime %d, %s for %s, 2nd tkt client %s", - fromstring, authtime, - cname ? cname : "", - sname ? sname : "", - tmp ? tmp : ""); + if ((errcode = krb5_unparse_name(kdc_context, client2, &altcname))) + altcname = 0; + if (altcname != NULL) + limit_string(altcname); + errcode = KRB5KDC_ERR_SERVER_NOMATCH; + status = "2ND_TKT_MISMATCH"; goto cleanup; } @@ -661,27 +645,16 @@ tgt_again: free(reply.enc_part.ciphertext.data); cleanup: - if (status) { - const char * emsg = NULL; - if (!errcode) - rep_etypes2str(rep_etypestr, sizeof(rep_etypestr), &reply); - if (errcode) - emsg = krb5_get_error_message (kdc_context, errcode); - krb5_klog_syslog(LOG_INFO, - "TGS_REQ (%s) %s: %s: authtime %d, " - "%s%s %s for %s%s%s", - ktypestr, - fromstring, status, authtime, - !errcode ? rep_etypestr : "", - !errcode ? "," : "", - cname ? cname : "", - sname ? sname : "", - errcode ? ", " : "", - errcode ? emsg : ""); - if (errcode) - krb5_free_error_message (kdc_context, emsg); + assert(status != NULL); + if (errcode) + emsg = krb5_get_error_message (kdc_context, errcode); + log_tgs_req(from, request, &reply, cname, sname, altcname, authtime, + status, errcode, emsg); + if (errcode) { + krb5_free_error_message (kdc_context, emsg); + emsg = NULL; } - + if (errcode) { int got_err = 0; if (status == 0) { @@ -693,7 +666,7 @@ cleanup: errcode = KRB_ERR_GENERIC; retval = prepare_error_tgs(request, header_ticket, errcode, - fromstring, response, status); + response, status); if (got_err) { krb5_free_error_message (kdc_context, status); status = 0; @@ -722,7 +695,7 @@ cleanup: static krb5_error_code prepare_error_tgs (krb5_kdc_req *request, krb5_ticket *ticket, int error, - const char *ident, krb5_data **response, const char *status) + krb5_data **response, const char *status) { krb5_error errpkt; krb5_error_code retval; @@ -813,7 +786,6 @@ find_alternate_tgs(krb5_kdc_req *request, krb5_db_entry *server, } else if (*nprincs == 1) { /* Found it! */ krb5_principal tmpprinc; - char *sname; tmp = *krb5_princ_realm(kdc_context, *pl2); krb5_princ_set_realm(kdc_context, *pl2, @@ -827,15 +799,7 @@ find_alternate_tgs(krb5_kdc_req *request, krb5_db_entry *server, krb5_free_principal(kdc_context, request->server); request->server = tmpprinc; - if (krb5_unparse_name(kdc_context, request->server, &sname)) { - krb5_klog_syslog(LOG_INFO, - "TGS_REQ: issuing alternate TGT"); - } else { - limit_string(sname); - krb5_klog_syslog(LOG_INFO, - "TGS_REQ: issuing TGT %s", sname); - free(sname); - } + log_tgs_alt_tgt(request->server); krb5_free_realm_tree(kdc_context, plist); return; } diff --git a/src/kdc/kdc_util.c b/src/kdc/kdc_util.c index d66832bbe..4068ec622 100644 --- a/src/kdc/kdc_util.c +++ b/src/kdc/kdc_util.c @@ -1602,3 +1602,123 @@ get_principal (krb5_context kcontext, return get_principal_locked (kcontext, search_for, entries, nentries, more); } + +/* Main logging routines for ticket requests. + + There are a few simple cases -- unparseable requests mainly -- + where messages are logged otherwise, but once a ticket request can + be decoded in some basic way, these routines are used for logging + the details. */ + +/* "status" is null to indicate success. */ +/* Someday, pass local address/port as well. */ +void +log_as_req(const krb5_fulladdr *from, + krb5_kdc_req *request, krb5_kdc_rep *reply, + const char *cname, const char *sname, + krb5_timestamp authtime, + const char *status, krb5_error_code errcode, const char *emsg) +{ + const char *fromstring = 0; + char fromstringbuf[70]; + char ktypestr[128]; + const char *cname2 = cname ? cname : ""; + const char *sname2 = sname ? sname : ""; + + fromstring = inet_ntop(ADDRTYPE2FAMILY (from->address->addrtype), + from->address->contents, + fromstringbuf, sizeof(fromstringbuf)); + if (!fromstring) + fromstring = ""; + ktypes2str(ktypestr, sizeof(ktypestr), + request->nktypes, request->ktype); + + if (status == NULL) { + /* success */ + char rep_etypestr[128]; + rep_etypes2str(rep_etypestr, sizeof(rep_etypestr), reply); + krb5_klog_syslog(LOG_INFO, + "AS_REQ (%s) %s: ISSUE: authtime %d, %s, %s for %s", + ktypestr, fromstring, authtime, + rep_etypestr, cname2, sname2); + } else { + /* fail */ + krb5_klog_syslog(LOG_INFO, "AS_REQ (%s) %s: %s: %s for %s%s%s", + ktypestr, fromstring, status, + cname2, sname2, emsg ? ", " : "", emsg ? emsg : ""); + } +#if 0 + /* Sun (OpenSolaris) version would probably something like this. + The client and server names passed can be null, unlike in the + logging routines used above. Note that a struct in_addr is + used, but the real address could be an IPv6 address. */ + audit_krb5kdc_as_req(some in_addr *, (in_port_t)from->port, 0, + cname, sname, errcode); +#endif +} + +/* Here "status" must be non-null. Error code + KRB5KDC_ERR_SERVER_NOMATCH is handled specially. */ +void +log_tgs_req(const krb5_fulladdr *from, + krb5_kdc_req *request, krb5_kdc_rep *reply, + const char *cname, const char *sname, const char *altcname, + krb5_timestamp authtime, + const char *status, krb5_error_code errcode, const char *emsg) +{ + char ktypestr[128]; + const char *fromstring = 0; + char fromstringbuf[70]; + char rep_etypestr[128]; + + fromstring = inet_ntop(ADDRTYPE2FAMILY(from->address->addrtype), + from->address->contents, + fromstringbuf, sizeof(fromstringbuf)); + if (!fromstring) + fromstring = ""; + ktypes2str(ktypestr, sizeof(ktypestr), request->nktypes, request->ktype); + if (!errcode) + rep_etypes2str(rep_etypestr, sizeof(rep_etypestr), reply); + else + rep_etypestr[0] = 0; + + /* Differences: server-nomatch message logs 2nd ticket's client + name (useful), and doesn't log ktypestr (probably not + important). */ + if (errcode != KRB5KDC_ERR_SERVER_NOMATCH) + krb5_klog_syslog(LOG_INFO, + "TGS_REQ (%s) %s: %s: authtime %d, %s%s %s for %s%s%s", + ktypestr, + fromstring, status, authtime, + rep_etypestr, + !errcode ? "," : "", + cname ? cname : "", + sname ? sname : "", + errcode ? ", " : "", + errcode ? emsg : ""); + else + krb5_klog_syslog(LOG_INFO, + "TGS_REQ %s: %s: authtime %d, %s for %s, 2nd tkt client %s", + fromstring, status, authtime, + cname ? cname : "", + sname ? sname : "", + altcname ? altcname : ""); + + /* OpenSolaris: audit_krb5kdc_tgs_req(...) or + audit_krb5kdc_tgs_req_2ndtktmm(...) */ +} + +void +log_tgs_alt_tgt(krb5_principal p) +{ + char *sname; + if (krb5_unparse_name(kdc_context, p, &sname)) { + krb5_klog_syslog(LOG_INFO, + "TGS_REQ: issuing alternate TGT"); + } else { + limit_string(sname); + krb5_klog_syslog(LOG_INFO, "TGS_REQ: issuing TGT %s", sname); + free(sname); + } + /* OpenSolaris: audit_krb5kdc_tgs_req_alt_tgt(...) */ +} diff --git a/src/kdc/kdc_util.h b/src/kdc/kdc_util.h index ca644ac6d..a38995516 100644 --- a/src/kdc/kdc_util.h +++ b/src/kdc/kdc_util.h @@ -188,6 +188,21 @@ get_principal (krb5_context kcontext, krb5_const_principal search_for, krb5_db_entry *entries, int *nentries, krb5_boolean *more); +void +log_as_req(const krb5_fulladdr *from, + krb5_kdc_req *request, krb5_kdc_rep *reply, + const char *cname, const char *sname, + krb5_timestamp authtime, + const char *status, krb5_error_code errcode, const char *emsg); +void +log_tgs_req(const krb5_fulladdr *from, + krb5_kdc_req *request, krb5_kdc_rep *reply, + const char *cname, const char *sname, const char *altcname, + krb5_timestamp authtime, + const char *status, krb5_error_code errcode, const char *emsg); +void log_tgs_alt_tgt(krb5_principal p); + + #define isflagset(flagfield, flag) (flagfield & (flag)) #define setflag(flagfield, flag) (flagfield |= (flag)) #define clear(flagfield, flag) (flagfield &= ~(flag))