more logging, try harder to not loop

lib/krb5/init_creds_pw.c

@@ -3,6 +3,8 @@
  * (Royal Institute of Technology, Stockholm, Sweden).
  * All rights reserved.
  *
+ * Portions Copyright (c) 2009 Apple Inc. All rights reserved.
+ *
  * Redistribution and use in source and binary forms, with or without
  * modification, are permitted provided that the following conditions
  * are met:
@@ -59,6 +61,12 @@ typedef struct krb5_get_init_creds_ctx {
     krb5_pk_init_ctx pk_init_ctx;
     int ic_flags;
 
+    int used_pa_types;
+#define  USED_PKINIT	1
+#define  USED_PKINIT_W2K	2
+#define  USED_ENC_TS_GUESS	4
+#define  USED_ENC_TS_INFO	8
+
     METHOD_DATA md;
     KRB_ERROR error;
     AS_REP as_rep;
@@ -96,6 +104,8 @@ default_s2k_func(krb5_context context, krb5_enctype type,
     krb5_data password;
     krb5_data opaque;
 
+    _krb5_debug(context, 5, "krb5_get_init_creds: using default_s2k_func");
+
     password.data = rk_UNCONST(keyseed);
     password.length = strlen(keyseed);
     if (s2kparms)
@@ -989,6 +999,8 @@ add_enc_ts_padata(krb5_context context,
     for (i = 0; i < netypes; ++i) {
 	krb5_keyblock *key;
 
+	_krb5_debug(context, 5, "krb5_get_init_creds: using ENC-TS with enctype %d", enctypes[i]);
+
 	ret = (*keyproc)(context, enctypes[i], keyseed,
 			 *salt, s2kparams, &key);
 	if (ret)
@@ -1022,6 +1034,8 @@ pa_data_to_md_ts_enc(krb5_context context,
     } else {
 	krb5_salt salt;
 
+	_krb5_debug(context, 5, "krb5_get_init_creds: pa-info not found, guessing salt");
+
 	/* make a v5 salted pa-data */
 	add_enc_ts_padata(context, md, client,
 			  ctx->keyproc, ctx->keyseed,
@@ -1060,6 +1074,7 @@ static krb5_error_code
 pa_data_to_md_pkinit(krb5_context context,
 		     const AS_REQ *a,
 		     const krb5_principal client,
+		     int win2k,
 		     krb5_get_init_creds_ctx *ctx,
 		     METHOD_DATA *md)
 {
@@ -1067,10 +1082,12 @@ pa_data_to_md_pkinit(krb5_context context,
 	return 0;
 #ifdef PKINIT
     return _krb5_pk_mk_padata(context,
-			     ctx->pk_init_ctx,
+			      ctx->pk_init_ctx,
-			     &a->req_body,
+			      ctx->ic_flags,
-			     ctx->pk_nonce,
+			      win2k,
-			     md);
+			      &a->req_body,
+			      ctx->pk_nonce,
+			      md);
 #else
     krb5_set_error_message(context, EINVAL,
 			   N_("no support for PKINIT compiled in", ""));
@@ -1136,6 +1153,13 @@ process_pa_data_to_md(krb5_context context,
     (*out_md)->len = 0;
     (*out_md)->val = NULL;
 
+    if (_krb5_have_debug(context, 5)) {
+	unsigned i;
+	_krb5_debug(context, 5, "KDC send %d patypes", in_md->len);
+	for (i = 0; i < in_md->len; i++)
+	    _krb5_debug(context, 5, "KDC send PA-DATA type: %d", in_md->val[i].padata_type);
+    }
+
     /*
      * Make sure we don't sent both ENC-TS and PK-INIT pa data, no
      * need to expose our password protecting our PKCS12 key.
@@ -1143,19 +1167,54 @@ process_pa_data_to_md(krb5_context context,
 
     if (ctx->pk_init_ctx) {
 
-	ret = pa_data_to_md_pkinit(context, a, creds->client, ctx, *out_md);
+ 	_krb5_debug(context, 5, "krb5_get_init_creds: "
+		    "prepareing PKINIT padata (%s)",
+ 		    (ctx->used_pa_types & USED_PKINIT_W2K) ? "win2k" : "ietf");
+	
+ 	if (ctx->used_pa_types & USED_PKINIT_W2K) {
+ 	    krb5_set_error_message(context, KRB5_GET_IN_TKT_LOOP,
+ 				   "Already tried pkinit, looping");
+ 	    return KRB5_GET_IN_TKT_LOOP;
+ 	}
+
+	ret = pa_data_to_md_pkinit(context, a, creds->client, 
+				   (ctx->used_pa_types & USED_PKINIT),
+				   ctx, *out_md);
 	if (ret)
 	    return ret;
 
+	if (ctx->used_pa_types & USED_PKINIT)
+	    ctx->used_pa_types |= USED_PKINIT_W2K;
+ 	else
+ 	    ctx->used_pa_types |= USED_PKINIT;
+
     } else if (in_md->len != 0) {
 	struct pa_info_data *paid, *ppaid;
+ 	unsigned flag;
 
 	paid = calloc(1, sizeof(*paid));
 
 	paid->etype = ENCTYPE_NULL;
 	ppaid = process_pa_info(context, creds->client, a, paid, in_md);
 
+ 	if (ppaid)
+ 	    flag = USED_ENC_TS_INFO;
+ 	else
+ 	    flag = USED_ENC_TS_GUESS;
+
+ 	if (ctx->used_pa_types & flag) {
+ 	    if (ppaid)
+ 		free_paid(context, ppaid);
+ 	    krb5_set_error_message(context, KRB5_GET_IN_TKT_LOOP,
+ 				   "Already tried ENC-TS-%s, looping",
+ 				   flag == USED_ENC_TS_INFO ? "info" : "guess");
+ 	    return KRB5_GET_IN_TKT_LOOP;
+ 	}
+
 	pa_data_to_md_ts_enc(context, a, creds->client, ctx, ppaid, *out_md);
+
+	ctx->used_pa_types |= flag;
+
 	if (ppaid) {
 	    if (ctx->ppaid) {
 		free_paid(context, ctx->ppaid);
@@ -1227,6 +1286,8 @@ process_pa_data_to_key(krb5_context context,
     }
     if (pa && ctx->pk_init_ctx) {
 #ifdef PKINIT
+	_krb5_debug(context, 5, "krb5_get_init_creds: using PKINIT");
+
 	ret = _krb5_pk_rd_pa_reply(context,
 				   a->req_body.realm,
 				   ctx->pk_init_ctx,
@@ -1240,10 +1301,11 @@ process_pa_data_to_key(krb5_context context,
 	ret = EINVAL;
 	krb5_set_error_message(context, ret, N_("no support for PKINIT compiled in", ""));
 #endif
-    } else if (ctx->keyseed)
+    } else if (ctx->keyseed) {
+ 	_krb5_debug(context, 5, "krb5_get_init_creds: using keyproc");
 	ret = pa_data_to_key_plain(context, creds->client, ctx,
 				   ppaid->salt, ppaid->s2kparams, etype, key);
-    else {
+    } else {
 	ret = EINVAL;
 	krb5_set_error_message(context, ret, N_("No usable pa data type", ""));
     }
@@ -1585,16 +1647,20 @@ krb5_init_creds_step(krb5_context context,
     }
     ctx->pa_counter++;
 
+    _krb5_debug(context, 5, "krb5_get_init_creds: loop %d", ctx->pa_counter);
+
     /* Lets process the input packet */
     if (in && in->length) {
 	krb5_kdc_rep rep;
 
 	memset(&rep, 0, sizeof(rep));
 
+	_krb5_debug(context, 5, "krb5_get_init_creds: processing input");
+
 	ret = decode_AS_REP(in->data, in->length, &rep.kdc_rep, &size);
 	if (ret == 0) {
 	    krb5_keyblock *key = NULL;
-	    unsigned eflags = EXTRACT_TICKET_AS_REQ;
+	    unsigned eflags = EXTRACT_TICKET_AS_REQ | EXTRACT_TICKET_TIMESYNC;
 
 	    if (ctx->flags.canonicalize) {
 		eflags |= EXTRACT_TICKET_ALLOW_SERVER_MISMATCH;
@@ -1610,6 +1676,8 @@ krb5_init_creds_step(krb5_context context,
 		goto out;
 	    }
 
+	    _krb5_debug(context, 5, "krb5_get_init_creds: extracting ticket");
+
 	    ret = _krb5_extract_ticket(context,
 				       &rep,
 				       &ctx->cred,
@@ -1636,16 +1704,22 @@ krb5_init_creds_step(krb5_context context,
 	} else {
 	    /* let's try to parse it as a KRB-ERROR */
 
+	    _krb5_debug(context, 5, "krb5_get_init_creds: got an error");
+
 	    free_KRB_ERROR(&ctx->error);
 
 	    ret = krb5_rd_error(context, in, &ctx->error);
 	    if(ret && in->length && ((char*)in->data)[0] == 4)
 		ret = KRB5KRB_AP_ERR_V4_REPLY;
-	    if (ret)
+	    if (ret) {
+		_krb5_debug(context, 5, "krb5_get_init_creds: failed to read error");
 		goto out;
+	    }
 
 	    ret = krb5_error_from_rd_error(context, &ctx->error, &ctx->cred);
 
+	    _krb5_debug(context, 5, "krb5_get_init_creds: KRB-ERROR %d", ret);
+
 	    /*
 	     * If no preauth was set and KDC requires it, give it one
 	     * more try.
@@ -1677,16 +1751,29 @@ krb5_init_creds_step(krb5_context context,
 		krb5_set_real_time(context, ctx->error.stime, -1);
 		if (context->kdc_sec_offset)
 		    ret = 0; 
+
+		_krb5_debug(context, 10, "init_creds: err skew updateing kdc offset to %d",
+			    context->kdc_sec_offset);
+
+		ctx->used_pa_types = 0;
+
 	    } else if (ret == KRB5_KDC_ERR_WRONG_REALM && ctx->flags.canonicalize) {
 	        /* client referal to a new realm */
+
 		if (ctx->error.crealm == NULL) {
 		    krb5_set_error_message(context, ret,
 					   N_("Got a client referral, not but no realm", ""));
 		    goto out;
 		}
+		_krb5_debug(context, 5,
+			    "krb5_get_init_creds: got referal to realm %s",
+			    *ctx->error.crealm);
+
 		ret = krb5_principal_set_realm(context, 
 					       ctx->cred.client,
 					       *ctx->error.crealm);
+
+		ctx->used_pa_types = 0;
 	    }
 	    if (ret)
 		goto out;