[Freeipa-devel] [PATCH 0112] Make log messages related to Kerberos more verbose

[Adam Tkac]

On Wed, Feb 27, 2013 at 04:21:16PM +0100, Petr Spacek wrote:
> On 12.2.2013 13:58, Petr Spacek wrote:
> >Hello,
> >
> >     Make log messages related to Kerberos more verbose.
> >
> >This change should help people supporting bind-dyndb-ldap to figure out what
> >is happening under covers.
> 
> Added explanatory error message for case where Kerberos context
> initialization failed.

Ack

> From 467a5d405f57e2277808c0b33b22480a3167abe4 Mon Sep 17 00:00:00 2001
> From: Petr Spacek <pspacek at redhat.com>
> Date: Tue, 12 Feb 2013 13:49:32 +0100
> Subject: [PATCH] Make log messages related to Kerberos more verbose.
> 
> Signed-off-by: Petr Spacek <pspacek at redhat.com>
> ---
>  src/krb5_helper.c | 38 +++++++++++++++++++++++---------------
>  1 file changed, 23 insertions(+), 15 deletions(-)
> 
> diff --git a/src/krb5_helper.c b/src/krb5_helper.c
> index ffa6938d08a37d3470dd9184be2d8ab5c604afdf..25de7f80ee56a6a2c6c6591266edf621914a10b9 100644
> --- a/src/krb5_helper.c
> +++ b/src/krb5_helper.c
> @@ -60,15 +60,15 @@ check_credentials(krb5_context context,
>  	krberr = krb5_build_principal(context, &mcreds.server,
>  				      strlen(realm), realm,
>  				      "krbtgt", realm, NULL);
> -	CHECK_KRB5(context, krberr, "Failed to build tgt principal");
> +	CHECK_KRB5(context, krberr, "Failed to build 'krbtgt/REALM' principal");
>  
>  	/* krb5_cc_retrieve_cred filters on both server and client */
>  	mcreds.client = service;
>  
>  	krberr = krb5_cc_retrieve_cred(context, ccache, 0, &mcreds, &creds);
>  	if (krberr) {
>  		const char * errmsg = krb5_get_error_message(context, krberr);
> -		log_debug(2, "Principal not found in cred cache (%s)",
> +		log_debug(2, "Credentials are not present in cache (%s)",
>  			  errmsg);
>  		krb5_free_error_message(context, errmsg);
>  		result = ISC_R_FAILURE;
> @@ -79,7 +79,7 @@ check_credentials(krb5_context context,
>  	CHECK_KRB5(context, krberr, "Failed to get timeofday");
>  
>  	if (now > (creds.times.endtime + MIN_TIME)) {
> -		log_debug(2, "Credentials expired");
> +		log_debug(2, "Credentials in cache expired");
>  		result = ISC_R_FAILURE;
>  		goto cleanup;
>  	}
> @@ -123,42 +123,46 @@ get_krb5_tgt(isc_mem_t *mctx, const char *principal, const char *keyfile)
>  	}
>  
>  	krberr = krb5_init_context(&context);
> -	if (krberr) {
> -		log_error("Failed to init kerberos context");
> -		return ISC_R_FAILURE;
> -	}
> +	/* This will blow up with older versions of Heimdal Kerberos, but
> +	 * this kind of errors are not debuggable without any error message.
> +	 * http://mailman.mit.edu/pipermail/kerberos/2013-February/018720.html */
> +	CHECK_KRB5(NULL, krberr, "Kerberos context initialization failed");
>  
>  	/* get credentials cache */
>  	CHECK(str_new(mctx, &ccname));
>  	CHECK(str_sprintf(ccname, "MEMORY:_ld_krb5_cc_%s", principal));
>  
>  	ret = setenv("KRB5CCNAME", str_buf(ccname), 1);
>  	if (ret == -1) {
> -		log_error("Failed to set KRB5CCNAME environment variable");
> +		log_error("Failed to set KRB5CCNAME environment variable to "
> +			  "'%s'", str_buf(ccname));
>  		result = ISC_R_FAILURE;
>  		goto cleanup;
>  	}
>  
>  	krberr = krb5_cc_resolve(context, str_buf(ccname), &ccache);
>  	CHECK_KRB5(context, krberr,
> -		   "Failed to resolve ccache name %s", str_buf(ccname));
> +		   "Failed to resolve credentials cache name '%s'",
> +		   str_buf(ccname));
>  
>  	/* get krb5_principal from string */
>  	krberr = krb5_parse_name(context, principal, &kprincpw);
>  	CHECK_KRB5(context, krberr,
> -		   "Failed to parse the principal name %s", principal);
> +		   "Failed to parse the principal name '%s'", principal);
>  
>  	/* check if we already have valid credentials */
>  	result = check_credentials(context, ccache, kprincpw);
>  	if (result == ISC_R_SUCCESS) {
> -		log_debug(2, "Found valid cached credentials");
> +		log_debug(2, "Found valid Kerberos credentials in cache");
>  		goto cleanup;
> +	} else {
> +		log_debug(2, "Attempting to acquire new Kerberos credentials");
>  	}
>  
>  	/* open keytab */
>  	krberr = krb5_kt_resolve(context, keyfile, &keytab);
>  	CHECK_KRB5(context, krberr,
> -		   "Failed to resolve keytab file %s", keyfile);
> +		   "Failed to resolve keytab file '%s'", keyfile);
>  
>  	memset(&my_creds, 0, sizeof(my_creds));
>  	memset(&options, 0, sizeof(options));
> @@ -170,15 +174,19 @@ get_krb5_tgt(isc_mem_t *mctx, const char *principal, const char *keyfile)
>  	/* get tgt */
>  	krberr = krb5_get_init_creds_keytab(context, &my_creds, kprincpw,
>  					    keytab, 0, NULL, &options);
> -	CHECK_KRB5(context, krberr, "Failed to init credentials");
> +	CHECK_KRB5(context, krberr, "Failed to get initial credentials (TGT) "
> +				    "using principal '%s' and keytab '%s'",
> +				    principal, keyfile);
>  	my_creds_ptr = &my_creds;
>  
>  	/* store credentials in cache */
>  	krberr = krb5_cc_initialize(context, ccache, kprincpw);
> -	CHECK_KRB5(context, krberr, "Failed to initialize ccache");
> +	CHECK_KRB5(context, krberr, "Failed to initialize credentials cache "
> +				    "'%s'", str_buf(ccname));
>  
>  	krberr = krb5_cc_store_cred(context, ccache, &my_creds);
> -	CHECK_KRB5(context, krberr, "Failed to store ccache");
> +	CHECK_KRB5(context, krberr, "Failed to store credentials "
> +				    "in credentials cache '%s'", str_buf(ccname));
>  
>  	result = ISC_R_SUCCESS;
>  
> -- 
> 1.7.11.7
> 


-- 
Adam Tkac, Red Hat, Inc.