Collect ticket-request logging calls together in one place for easier
authorKen Raeburn <raeburn@mit.edu>
Mon, 22 Dec 2008 04:40:39 +0000 (04:40 +0000)
committerKen Raeburn <raeburn@mit.edu>
Mon, 22 Dec 2008 04:40:39 +0000 (04:40 +0000)
customization.

git-svn-id: svn://anonsvn.mit.edu/krb5/trunk@21564 dc483132-0cff-0310-8789-dd5450dbe970

src/kdc/do_as_req.c
src/kdc/do_tgs_req.c
src/kdc/kdc_util.c
src/kdc/kdc_util.h

index 1fbe56fb07179ae461dd36b4c785cec6fcdc64a1..8c65a637bdb59a9778992d873ea511d45ff4ebc3 100644 (file)
@@ -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 = "<unknown>";
-
     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 : "<unknown client>",
-              sname ? sname : "<unknown server>",
-              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;
 }
 
index fd862722ecd207a85fd63632eb920422d0dd0337..3af539feb62c417bedca7b0d8bb4e49d4a986031 100644 (file)
@@ -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 = "<unknown>";
-
     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 : "<unknown client>",
-                                sname ? sname : "<unknown server>",
-                                tmp ? tmp : "<unknown>");
+               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 : "<unknown client>",
-                        sname ? sname : "<unknown server>",
-                        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 <un-unparseable> 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;
        }
index d66832bbe4186c489b05ca1acc70a5f5a523459a..4068ec622fd1af2192fe603d814711251fc88848 100644 (file)
@@ -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 : "<unknown client>";
+    const char *sname2 = sname ? sname : "<unknown server>";
+
+    fromstring = inet_ntop(ADDRTYPE2FAMILY (from->address->addrtype),
+                          from->address->contents,
+                          fromstringbuf, sizeof(fromstringbuf));
+    if (!fromstring)
+       fromstring = "<unknown>";
+    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 = "<unknown>";
+    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 : "<unknown client>",
+                        sname ? sname : "<unknown server>",
+                        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 : "<unknown client>",
+                        sname ? sname : "<unknown server>",
+                        altcname ? altcname : "<unknown>");
+
+    /* 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 <un-unparseable> 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(...) */
+}
index ca644ac6d1cee40aa1c5ce0a64b1658e4d0cd14e..a389955168569cabdffda68dd99cff383b6b40d7 100644 (file)
@@ -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))