oysteikt/heimdal
0
0
Fork 0
Code Issues 5 Pull Requests Releases Activity

WIP

Browse Source
This commit is contained in:
Oystein Kristoffer Tveit
2026-02-02 08:53:06 +09:00
parent d0b5821e9a
commit 845fb73ad1
10 changed files with 549 additions and 53 deletions
Download Patch File Download Diff File Expand all files Collapse all files

17
kadmin/ext.c
View File

@@ -68,6 +68,12 @@ do_ext_keytab(krb5_principal principal, void *data)
if (ret)
goto out;
/* Debug: record which principal was fetched and some context */
krb5_warnx(context, "do_ext_keytab: fetched principal %s mask=0x%x n_key_data=%d",
unparsed ? unparsed : "<unparsed>",
mask,
(int)princ.n_key_data);
if (!e->random_key_flag) {
if (princ.n_key_data == 0) {
krb5_warnx(context, "principal has no keys, or user lacks "
@@ -111,6 +117,13 @@ do_ext_keytab(krb5_principal principal, void *data)
keys[i].keyblock.keyvalue.data = kd->key_data_contents[0];
keys[i].timestamp = time(NULL);
n_k++;
/* Debug: log each key extracted (kvno/enctype) for the principal */
krb5_warnx(context, "do_ext_keytab: principal=%s key_index=%zu kvno=%d enctype=%d",
unparsed ? unparsed : "<unparsed>",
i,
keys[i].vno,
keys[i].keyblock.keytype);
}
} else if (e->random_key_flag) {
ret = kadm5_randkey_principal_3(e->kadm_handle, principal, e->keep,
@@ -208,6 +221,10 @@ ext_keytab(struct ext_keytab_options *opt, int argc, char **argv)
return ret;
}
/* Debug: record ext_keytab invocation details */
krb5_warnx(context, "ext_keytab: invoking foreach_principal for %zu principals, enctypes=%s",
(size_t)argc, enctypes ? enctypes : "<none>");
for(i = 0; i < argc; i++) {
ret = foreach_principal(argv[i], do_ext_keytab, "ext", &data);
if (ret)

73
kadmin/get.c
View File

@@ -488,12 +488,71 @@ do_get_entry(krb5_principal principal, void *data)
e->upto--;
memset(&princ, 0, sizeof(princ));
ret = kadm5_get_principal(e->kadm_handle, principal,
&princ,
e->mask | e->extra_mask);
/* Loud tracing: record which principal we are about to request from kadmind.
*
* Guard the unparse call: don't call into unparse with a NULL principal
* and only use the unparsed string if the call succeeds.
*/
{
char *want = NULL;
if (principal != NULL && krb5_unparse_name(context, principal, &want) == 0 && want != NULL) {
krb5_warnx(context, "kadmin:get: do_get_entry: requesting principal lookup for %s (mask=0x%x extra_mask=0x%x) (pid=%d)",
want, e->mask, e->extra_mask, (int)getpid());
} else {
krb5_warnx(context, "kadmin:get: do_get_entry: requesting principal lookup for <unparsed> (mask=0x%x extra_mask=0x%x) (pid=%d)",
e->mask, e->extra_mask, (int)getpid());
}
free(want);
}
/* Always request the principal field so we can safely unparse/format
* the returned entry. Some callers request only TL_DATA (eg aliases),
* and the kadm5 backend may return successful results without filling
* the principal pointer which leads to crashes when we try to use it.
*/
{
uint32_t want_mask = e->mask | e->extra_mask | KADM5_PRINCIPAL;
ret = kadm5_get_principal(e->kadm_handle, principal,
&princ,
want_mask);
}
if (ret == 0) {
/* Success: log the fact we received a principal record and some basic info */
{
char *got = NULL;
if (krb5_unparse_name(context, princ.principal, &got) == 0) {
krb5_warnx(context, "kadmin:get: do_get_entry: kadm5_get_principal succeeded: principal=%s kvno=%d n_key_data=%d (pid=%d)",
got ? got : "<unparsed>",
princ.kvno,
princ.n_key_data,
(int)getpid());
} else {
krb5_warnx(context, "kadmin:get: do_get_entry: kadm5_get_principal succeeded: <unparsed principal> kvno=%d n_key_data=%d (pid=%d)",
princ.kvno, princ.n_key_data, (int)getpid());
}
free(got);
}
(e->format)(e, &princ);
kadm5_free_principal_ent(e->kadm_handle, &princ);
} else {
/* Failure: log explicit error so we can trace failing lookups.
*
* Guard the unparse call similarly to above.
*/
{
char *want2 = NULL;
if (principal != NULL && krb5_unparse_name(context, principal, &want2) == 0 && want2 != NULL) {
krb5_warn(context, ret, "kadmin:get: do_get_entry: kadm5_get_principal(%s) failed (pid=%d)",
want2, (int)getpid());
} else {
krb5_warn(context, ret, "kadmin:get: do_get_entry: kadm5_get_principal(<unparsed>) failed (pid=%d)",
(int)getpid());
}
free(want2);
}
}
e->n++;
@@ -627,8 +686,14 @@ getit(struct get_options *opt, const char *name, int argc, char **argv)
return 0;
}
for(i = 0; i < argc; i++)
for(i = 0; i < argc; i++) {
/* Loud tracing: announce each foreach_principal invocation */
krb5_warnx(context, "kadmin:get: getit: invoking foreach_principal for arg[%d]=%s (call %d of %d) (pid=%d)",
i, argv[i] ? argv[i] : "<null>", i+1, argc, (int)getpid());
ret = foreach_principal(argv[i], do_get_entry, name, &data);
if (ret)
krb5_warn(context, ret, "kadmin:get: getit: foreach_principal(%s) returned error", argv[i] ? argv[i] : "<null>");
}
kadm5_destroy(data.kadm_handle);

24
kadmin/rpc.c
View File

@@ -624,7 +624,31 @@ proc_get_principal(kadm5_server_context *contextp,
if(ret)
goto fail;
/* Loud tracing: log which client requested this GET and what principal is being looked up */
{
char *want = NULL;
(void) krb5_unparse_name(contextp->context, princ, &want);
krb5_warnx(contextp->context,
"proc_get_principal: received GET request for principal=%s mask=0x%x (pid=%d ppid=%d uid=%d)",
want ? want : "<unparsed>",
mask,
(int)getpid(),
(int)getppid(),
(int)getuid());
free(want);
}
ret = kadm5_get_principal(contextp, princ, &ent, mask);
if (ret) {
/* Extra log to make failures obvious at the call site */
char *want2 = NULL;
(void) krb5_unparse_name(contextp->context, princ, &want2);
krb5_warn(contextp->context, ret,
"proc_get_principal: kadm5_get_principal failed for principal=%s (pid=%d)",
want2 ? want2 : "<unparsed>",
(int)getpid());
free(want2);
}
fail:
krb5_warn(contextp->context, ret, "get principal principal");

5
kadmin/server.c
View File

@@ -226,6 +226,8 @@ kadmind_dispatch_int(void *kadm_handlep, krb5_boolean initial,
ret_sp = krb5_store_int32(rsp, KADM5_FAILURE);
goto fail;
}
/* Debug: record which client and numeric command we received */
krb5_warnx(contextp->context, "kadmind_dispatch: received request from client=%s cmd=%d", client, cmd);
switch(cmd){
case kadm_nop:{
@@ -268,6 +270,8 @@ kadmind_dispatch_int(void *kadm_handlep, krb5_boolean initial,
mask |= KADM5_PRINCIPAL;
krb5_unparse_name_fixed(contextp->context, princ, name, sizeof(name));
krb5_warnx(contextp->context, "%s: %s %s", client, op, name);
/* Debug: include mask/keys_ok context so we can correlate admin requests to keytab lookups */
krb5_warnx(contextp->context, "kadmind_dispatch: GET invoked by %s for %s (mask=0x%x, keys_ok=%d)", client, name, mask, keys_ok);
/* If the caller doesn't have KADM5_PRIV_GET, we're done. */
ret = _kadm5_acl_check_permission(contextp, KADM5_PRIV_GET, princ);
@@ -307,6 +311,7 @@ kadmind_dispatch_int(void *kadm_handlep, krb5_boolean initial,
}
}
krb5_warnx(contextp->context, "kadmind_dispatch: calling kadm5_get_principal for %s (mask=0x%x, keys_ok=%d)", name, mask, keys_ok);
ret = kadm5_get_principal(kadm_handlep, princ, &ent, mask);
ret_sp = krb5_store_int32(rsp, ret);
if (ret == 0) {

45
lib/hdb/hdb-keytab.c
View File

@@ -149,10 +149,55 @@ hkt_fetch_kvno(krb5_context context, HDB * db, krb5_const_principal principal,
* enctypes should work.
*/
/* Debug: record the requested principal and keytab context */
{
char *princ_name = NULL;
if (krb5_unparse_name(context, principal, &princ_name) == 0) {
krb5_warnx(context, "hkt_fetch_kvno: looking up principal=%s in keytab=%s kvno=%u flags=0x%x",
princ_name ? princ_name : "<unparsed>",
k->path ? k->path : "<unknown>",
(unsigned)kvno,
(unsigned)flags);
} else {
krb5_warnx(context, "hkt_fetch_kvno: looking up <unparsed principal> in keytab=%s kvno=%u flags=0x%x",
k->path ? k->path : "<unknown>",
(unsigned)kvno,
(unsigned)flags);
}
free(princ_name);
}
ret = krb5_kt_get_entry(context, k->keytab, principal, kvno, 0, &ktentry);
if (ret) {
char *princ_name2 = NULL;
if (krb5_unparse_name(context, principal, &princ_name2) == 0) {
krb5_warnx(context, "hkt_fetch_kvno: krb5_kt_get_entry returned %d for principal=%s keytab=%s",
ret, princ_name2 ? princ_name2 : "<unparsed>", k->path ? k->path : "<unknown>");
} else {
krb5_warnx(context, "hkt_fetch_kvno: krb5_kt_get_entry returned %d for <unparsed principal> keytab=%s",
ret, k->path ? k->path : "<unknown>");
}
free(princ_name2);
ret = HDB_ERR_NOENTRY;
goto out;
} else {
/* Success: record what the keytab returned for inspection */
{
char *entry_princ = NULL;
if (krb5_unparse_name(context, ktentry.principal, &entry_princ) == 0) {
krb5_warnx(context, "hkt_fetch_kvno: krb5_kt_get_entry succeeded: entry_principal=%s vno=%d enctype=%d keytab=%s",
entry_princ ? entry_princ : "<unparsed>",
ktentry.vno,
ktentry.keyblock.keytype,
k->path ? k->path : "<unknown>");
} else {
krb5_warnx(context, "hkt_fetch_kvno: krb5_kt_get_entry succeeded: entry_principal=<unparsed> vno=%d enctype=%d keytab=%s",
ktentry.vno,
ktentry.keyblock.keytype,
k->path ? k->path : "<unknown>");
}
free(entry_princ);
}
}
ret = krb5_copy_principal(context, principal, &entry->principal);

148
lib/kadm5/init_c.c
View File

@@ -191,6 +191,20 @@ _kadm5_c_init_context(kadm5_client_context **ctx,
}
if ((*ctx)->readonly_kadmind_port == 0)
(*ctx)->readonly_kadmind_port = (*ctx)->kadmind_port;
/*
* Extra debug: emit context-level info to help trace client init-time
* decisions in test logs.
*/
krb5_warnx(context,
"_kadm5_c_init_context: realm=%s admin_server=%s readonly_admin_server=%s kadmind_port=%u readonly_port=%u (pid=%d)",
(*ctx)->realm ? (*ctx)->realm : "<null>",
(*ctx)->admin_server ? (*ctx)->admin_server : "<null>",
(*ctx)->readonly_admin_server ? (*ctx)->readonly_admin_server : "<null>",
(unsigned)ntohs((*ctx)->kadmind_port),
(unsigned)ntohs((*ctx)->readonly_kadmind_port),
(int)getpid());
return 0;
}
@@ -226,6 +240,16 @@ kadm5_c_dup_context(void *vin, void **out)
if (in->readonly_admin_server &&
(ctx->readonly_admin_server = strdup(in->readonly_admin_server)) == NULL)
ret = krb5_enomem(context);
/* Preserve client identity and prompter behavior in duplicated context */
if (in->client_name && (ctx->client_name = strdup(in->client_name)) == NULL)
ret = krb5_enomem(context);
if (in->service_name && (ctx->service_name = strdup(in->service_name)) == NULL)
ret = krb5_enomem(context);
/* Copy the prompter pointer so duplicated contexts behave the same
with respect to prompting vs keytab-based auth. */
ctx->prompter = in->prompter;
if (in->keytab && (ctx->keytab = strdup(in->keytab)) == NULL)
ret = krb5_enomem(context);
if (in->ccache) {
@@ -292,7 +316,24 @@ get_new_cache(krb5_context context,
krb5_get_init_creds_opt_set_forwardable (opt, FALSE);
krb5_get_init_creds_opt_set_proxiable (opt, FALSE);
/*
* Extra debug: record the inputs to credential selection so tests can
* observe why keytab vs password paths were chosen.
*/
krb5_warnx(context,
"get_new_cache: entry client=%s password_provided=%d prompter=%p keytab=%s server_name=%s (pid=%d)",
client ? krb5_principal_get_comp_string(context, client, 0) : "<null>",
password ? 1 : 0,
(void *)prompter,
keytab ? keytab : "<default>",
server_name ? server_name : "<null>",
(int)getpid());
if(password == NULL && prompter == NULL) {
/* Debug: choosing keytab-based initial credentials */
krb5_warnx(context, "get_new_cache: choosing keytab auth (keytab=%s, client=%s)",
keytab ? keytab : "<default>",
client ? krb5_principal_get_comp_string(context, client, 0) : "<null>");
krb5_keytab kt;
if(keytab == NULL)
ret = krb5_kt_default(context, &kt);
@@ -309,8 +350,21 @@ get_new_cache(krb5_context context,
0,
server_name,
opt);
/* Log success/failure of keytab credential attempt for diagnostics */
if (ret == 0) {
krb5_warnx(context, "get_new_cache: krb5_get_init_creds_keytab succeeded for principal=%s using keytab=%s",
client ? krb5_principal_get_comp_string(context, client, 0) : "<null>",
keytab ? keytab : "<default>");
} else {
krb5_warn(context, ret, "get_new_cache: krb5_get_init_creds_keytab failed (keytab=%s)", keytab ? keytab : "<default>");
}
krb5_kt_close(context, kt);
} else {
/* Debug: choosing password-based initial credentials */
krb5_warnx(context, "get_new_cache: choosing password auth (password_provided=%d prompter=%p client=%s)",
password ? 1 : 0,
(void *)prompter,
client ? krb5_principal_get_comp_string(context, client, 0) : "<null>");
ret = krb5_get_init_creds_password (context,
&cred,
client,
@@ -320,6 +374,13 @@ get_new_cache(krb5_context context,
0,
server_name,
opt);
if (ret == 0) {
krb5_warnx(context, "get_new_cache: krb5_get_init_creds_password succeeded for principal=%s",
client ? krb5_principal_get_comp_string(context, client, 0) : "<null>");
} else {
krb5_warn(context, ret, "get_new_cache: krb5_get_init_creds_password failed for principal=%s",
client ? krb5_principal_get_comp_string(context, client, 0) : "<null>");
}
}
krb5_get_init_creds_opt_free(context, opt);
switch(ret){
@@ -448,6 +509,27 @@ _kadm5_c_get_cred_cache(krb5_context context,
if(server_name == NULL)
server_name = KADM5_ADMIN_SERVICE;
/*
* Extra debug: log the invocation and environment so we can correlate
* with test harness behavior (e.g. whether KRB5_KTNAME / KRB5CCNAME
* were set).
*/
{
const char *env_kt = secure_getenv ? secure_getenv("KRB5_KTNAME") : getenv("KRB5_KTNAME");
const char *env_cc = secure_getenv ? secure_getenv("KRB5CCNAME") : getenv("KRB5CCNAME");
krb5_warnx(context,
"_kadm5_c_get_cred_cache: called client_name=%s server_name=%s password_provided=%d prompter=%p keytab=%s ccache=%p env.KRB5_KTNAME=%s env.KRB5CCNAME=%s (pid=%d)",
client_name ? client_name : "<null>",
server_name ? server_name : "<null>",
password ? 1 : 0,
(void *)prompter,
keytab ? keytab : "<null>",
(void *)ccache,
env_kt ? env_kt : "<unset>",
env_cc ? env_cc : "<unset>",
(int)getpid());
}
if(client_name != NULL) {
ret = krb5_parse_name(context, client_name, &client);
if(ret)
@@ -502,14 +584,20 @@ _kadm5_c_get_cred_cache(krb5_context context,
if(id && client && (default_client == NULL ||
krb5_principal_compare(context, client, default_client) != 0)) {
/* Debug: attempting to obtain kadmin ticket from existing credential cache */
krb5_warnx(context, "_kadm5_c_get_cred_cache: trying credential cache to get kadmin ticket (client=%s)",
client ? krb5_principal_get_comp_string(context, client, 0) : "<null>");
ret = get_kadm_ticket(context, id, client, server_name);
if(ret == 0) {
krb5_warnx(context, "_kadm5_c_get_cred_cache: got kadmin ticket from cache for client=%s",
client ? krb5_principal_get_comp_string(context, client, 0) : "<null>");
*ret_cache = id;
krb5_free_principal(context, default_client);
if (default_client != client)
krb5_free_principal(context, client);
return 0;
}
krb5_warn(context, ret, "_kadm5_c_get_cred_cache: get_kadm_ticket from cache failed for client=%s", client ? krb5_principal_get_comp_string(context, client, 0) : "<null>");
if(ccache != NULL)
/* couldn't get ticket from cache */
return -1;
@@ -522,6 +610,21 @@ _kadm5_c_get_cred_cache(krb5_context context,
ret = get_new_cache(context, client, password, prompter, keytab,
server_name, ret_cache);
/*
* Extra debug: report the result of get_new_cache so caller logs
* can show why auth succeeded/failed.
*/
if (ret == 0) {
krb5_warnx(context, "_kadm5_c_get_cred_cache: get_new_cache succeeded for client=%s (pid=%d)",
client ? krb5_principal_get_comp_string(context, client, 0) : "<null>",
(int)getpid());
} else {
krb5_warn(context, ret, "_kadm5_c_get_cred_cache: get_new_cache failed for client=%s (pid=%d)",
client ? krb5_principal_get_comp_string(context, client, 0) : "<null>",
(int)getpid());
}
krb5_free_principal(context, client);
return ret;
}
@@ -545,6 +648,17 @@ kadm_connect(kadm5_client_context *ctx)
krb5_context context = ctx->context;
int writable = 0;
/*
* Extra debug: record connect intent and client context pointers
* to help correlate kadmin network activity with credential selection.
*/
krb5_warnx(context, "kadm_connect: entering (client_name=%s prompter=%p keytab=%s ccache=%p pid=%d)",
ctx->client_name ? ctx->client_name : "<null>",
(void *)ctx->prompter,
ctx->keytab ? ctx->keytab : "<null>",
(void *)ctx->ccache,
(int)getpid());
if (ctx->ac)
krb5_auth_con_free(context, ctx->ac);
ctx->ac = NULL;
@@ -658,6 +772,12 @@ out:
rk_closesocket(s);
krb5_auth_con_free(context, ctx->ac);
ctx->ac = NULL;
} else {
/* Extra debug: successful connect and auth */
krb5_warnx(context, "kadm_connect: success connected_to_writable=%d sock=%d (pid=%d)",
(int)ctx->connected_to_writable,
(int)ctx->sock,
(int)getpid());
}
return ret;
}
@@ -704,6 +824,20 @@ kadm5_c_init_with_context(krb5_context context,
kadm5_client_context *ctx = NULL;
krb5_ccache cc;
/*
* Extra debug: record initialization flags and pointers so we can later
* understand whether a prompter was provided (which affects keytab vs
* password selection) and whether a keytab or ccache was requested.
*/
krb5_warnx(context, "kadm5_c_init_with_context: client_name=%s password_provided=%d prompter=%p keytab=%s ccache=%p service_name=%s (pid=%d)",
client_name ? client_name : "<null>",
password ? 1 : 0,
(void *)prompter,
keytab ? keytab : "<null>",
(void *)ccache,
service_name ? service_name : "<null>",
(int)getpid());
ret = _kadm5_c_init_context(&ctx, realm_params, context);
if (ret)
return ret;
@@ -736,6 +870,19 @@ kadm5_c_init_with_context(krb5_context context,
ctx->sock = -1;
*server_handle = ctx;
/*
* Extra debug: final context values after init so logs show what the
* kadm client will carry into subsequent connect attempts.
*/
krb5_warnx(context, "kadm5_c_init_with_context: done ctx=%p client_name=%s prompter=%p keytab=%s ccache=%p (pid=%d)",
(void *)ctx,
ctx->client_name ? ctx->client_name : "<null>",
(void *)ctx->prompter,
ctx->keytab ? ctx->keytab : "<null>",
(void *)ctx->ccache,
(int)getpid());
return 0;
}
@@ -922,4 +1069,3 @@ kadm5_init(char *client_name, char *pass,
{
}
#endif

21
lib/krb5/expand_hostname.c
View File

@@ -69,17 +69,22 @@ krb5_expand_hostname (krb5_context context,
int error;
if ((context->flags & KRB5_CTX_F_DNS_CANONICALIZE_HOSTNAME) == 0 ||
krb5_config_get_bool(context, NULL, "libdefaults", "block_dns", NULL))
krb5_config_get_bool(context, NULL, "libdefaults", "block_dns", NULL)) {
krb5_warnx(context, "krb5_expand_hostname: DNS canonicalization disabled or blocked for hostname %s", orig_hostname);
return copy_hostname (context, orig_hostname, new_hostname);
}
memset (&hints, 0, sizeof(hints));
hints.ai_flags = AI_CANONNAME;
error = getaddrinfo (orig_hostname, NULL, &hints, &ai);
if (error)
if (error) {
krb5_warnx(context, "krb5_expand_hostname: getaddrinfo(%s) failed: %s", orig_hostname, gai_strerror(error));
return copy_hostname (context, orig_hostname, new_hostname);
}
for (a = ai; a != NULL; a = a->ai_next) {
if (a->ai_canonname != NULL) {
krb5_warnx(context, "krb5_expand_hostname: canonical name for %s -> %s", orig_hostname, a->ai_canonname);
*new_hostname = strdup (a->ai_canonname);
freeaddrinfo (ai);
if (*new_hostname == NULL)
@@ -89,6 +94,7 @@ krb5_expand_hostname (krb5_context context,
}
}
freeaddrinfo (ai);
krb5_warnx(context, "krb5_expand_hostname: no canonical name found for %s, falling back to copy_hostname", orig_hostname);
return copy_hostname (context, orig_hostname, new_hostname);
}
@@ -145,20 +151,25 @@ krb5_expand_hostname_realms (krb5_context context,
int error;
krb5_error_code ret = 0;
if ((context->flags & KRB5_CTX_F_DNS_CANONICALIZE_HOSTNAME) == 0)
if ((context->flags & KRB5_CTX_F_DNS_CANONICALIZE_HOSTNAME) == 0) {
krb5_warnx(context, "krb5_expand_hostname_realms: DNS canonicalization disabled for hostname %s", orig_hostname);
return vanilla_hostname (context, orig_hostname, new_hostname,
realms);
}
memset (&hints, 0, sizeof(hints));
hints.ai_flags = AI_CANONNAME;
error = getaddrinfo (orig_hostname, NULL, &hints, &ai);
if (error)
if (error) {
krb5_warnx(context, "krb5_expand_hostname_realms: getaddrinfo(%s) failed: %s", orig_hostname, gai_strerror(error));
return vanilla_hostname (context, orig_hostname, new_hostname,
realms);
}
for (a = ai; a != NULL; a = a->ai_next) {
if (a->ai_canonname != NULL) {
krb5_warnx(context, "krb5_expand_hostname_realms: canonical name for %s -> %s", orig_hostname, a->ai_canonname);
ret = copy_hostname (context, a->ai_canonname, new_hostname);
if (ret) {
freeaddrinfo (ai);
@@ -168,11 +179,13 @@ krb5_expand_hostname_realms (krb5_context context,
ret = krb5_get_host_realm (context, *new_hostname, realms);
if (ret == 0) {
freeaddrinfo (ai);
krb5_warnx(context, "krb5_expand_hostname_realms: host %s mapped to realm %s", *new_hostname, realms && *realms ? (*realms)[0] : "<unknown>");
return 0;
}
free (*new_hostname);
}
}
freeaddrinfo(ai);
krb5_warnx(context, "krb5_expand_hostname_realms: no canonical name/realm found for %s, falling back to vanilla_hostname", orig_hostname);
return vanilla_hostname (context, orig_hostname, new_hostname, realms);
}

116
lib/krb5/keytab.c
View File

@@ -217,6 +217,31 @@ krb5_kt_resolve(krb5_context context,
residual = keytab_name(name, &type, &type_len);
/*
* Aggressive process-context logging:
* Print pid/ppid/uid/gid and the raw name string being resolved
* so test captures show which process attempted to resolve which
* keytab and with what parsed type/residual.
*
* We intentionally always emit this via krb5_warnx to make sure it
* appears in stderr/journal during tests.
*/
{
pid_t pid = getpid();
pid_t ppid = getppid();
uid_t uid = getuid();
gid_t gid = getgid();
krb5_warnx(context,
"krb5_kt_resolve: pid=%d ppid=%d uid=%d gid=%d resolving name=\"%s\" parsed_type=\"%.*s\" residual=\"%s\"",
(int)pid,
(int)ppid,
(int)uid,
(int)gid,
name ? name : "<null>",
(int)type_len, type ? type : "<null>",
residual ? residual : "<null>");
}
for(i = 0; i < context->num_kt_types; i++) {
if(strncasecmp(type, context->kt_types[i].prefix, type_len) == 0)
break;
@@ -251,8 +276,15 @@ static const char *default_ktname(krb5_context context)
const char *tmp = NULL;
tmp = secure_getenv("KRB5_KTNAME");
if(tmp != NULL)
if(tmp != NULL) {
/* Aggressive logging: record environment override */
krb5_warnx(context, "default_ktname: using KRB5_KTNAME from env: \"%s\" (pid=%d)", tmp, (int)getpid());
return tmp;
}
/* Aggressive logging: record context default choice as well */
krb5_warnx(context, "default_ktname: using context->default_keytab: \"%s\" (pid=%d)",
context->default_keytab ? context->default_keytab : "<null>",
(int)getpid());
return context->default_keytab;
}
@@ -597,6 +629,13 @@ _krb5_kt_principal_not_found(krb5_context context,
else
kvno_str[0] = '\0';
/* Provide a concise debug line so tests can see what principal/keytab/enctype failed */
krb5_warnx(context, "kt_principal_not_found: principal=%s kvno=%s keytab=%s enctype=%s",
princ ? princ : "<unknown>",
kvno_str[0] ? kvno_str : "<none>",
kt_name ? kt_name : "unknown keytab",
enctype_str ? enctype_str : "unknown enctype");
krb5_set_error_message(context, ret,
N_("Failed to find %s%s in keytab %s (%s)",
"principal, kvno, keytab file, enctype"),
@@ -636,27 +675,81 @@ krb5_kt_get_entry_wrapped(krb5_context context,
entry->vno = 0;
while (krb5_kt_next_entry(context, id, &tmp, &cursor) == 0) {
/* Always-log the entry we're inspecting and what is being requested */
{
char *entry_unp = NULL;
char *want_unp = NULL;
(void) krb5_unparse_name(context, tmp.principal, &entry_unp);
(void) krb5_unparse_name(context, principal, &want_unp);
krb5_warnx(context, "krb5_kt_get_entry_wrapped: inspecting entry=%s vno=%d enctype=%d against requested=%s kvno=%u enctype=%d",
entry_unp ? entry_unp : "<unparsed>",
tmp.vno,
tmp.keyblock.keytype,
want_unp ? want_unp : "<unparsed>",
(unsigned)kvno,
(int)enctype);
free(entry_unp);
free(want_unp);
}
if (krb5_kt_compare(context, &tmp, principal, 0, enctype)) {
/* the file keytab might only store the lower 8 bits of
the kvno, so only compare those bits */
if (kvno == tmp.vno
|| (tmp.vno < 256 && kvno % 256 == tmp.vno)) {
/* Matched principal and kvno -> return this entry */
{
char *matched = NULL;
(void) krb5_unparse_name(context, tmp.principal, &matched);
krb5_warnx(context, "krb5_kt_get_entry_wrapped: matched entry=%s vno=%d enctype=%d -- returning",
matched ? matched : "<unparsed>",
tmp.vno,
tmp.keyblock.keytype);
free(matched);
}
krb5_kt_copy_entry_contents (context, &tmp, entry);
krb5_kt_free_entry (context, &tmp);
krb5_kt_end_seq_get(context, id, &cursor);
return 0;
} else if (kvno == 0 && tmp.vno > entry->vno) {
/* Matched principal but kvno selection logic prefers a higher vno */
{
char *matched = NULL;
(void) krb5_unparse_name(context, tmp.principal, &matched);
krb5_warnx(context, "krb5_kt_get_entry_wrapped: matched principal %s but kvno differs (entry.vno=%d tmp.vno=%d); selecting higher vno for now",
matched ? matched : "<unparsed>",
entry->vno,
tmp.vno);
free(matched);
}
if (entry->vno)
krb5_kt_free_entry (context, entry);
krb5_kt_copy_entry_contents (context, &tmp, entry);
} else {
/* Matched name but kvno didn't match and we are not in kvno-selection mode; log it. */
char *matched = NULL;
(void) krb5_unparse_name(context, tmp.principal, &matched);
krb5_warnx(context, "krb5_kt_get_entry_wrapped: matched principal %s but kvno mismatch (tmp.vno=%d requested_kvno=%u); continuing iteration",
matched ? matched : "<unparsed>",
tmp.vno,
(unsigned)kvno);
free(matched);
}
}
krb5_kt_free_entry(context, &tmp);
}
krb5_kt_end_seq_get (context, id, &cursor);
if (entry->vno == 0)
if (entry->vno == 0) {
/* No matching kvno was found in the keytab iteration; log and return */
krb5_warnx(context, "krb5_kt_get_entry_wrapped: no matching entry found -> invoking _krb5_kt_principal_not_found");
return _krb5_kt_principal_not_found(context, KRB5_KT_NOTFOUND,
id, principal, enctype, kvno);
}
krb5_warnx(context, "krb5_kt_get_entry_wrapped: returning selected entry vno=%d enctype=%d",
entry->vno, entry->keyblock.keytype);
return 0;
}
@@ -688,6 +781,25 @@ krb5_kt_get_entry(krb5_context context,
krb5_const_principal try_princ;
krb5_name_canon_iterator name_canon_iter;
/* Debug: record incoming keytab lookup request (always emitted) */
{
char *want_unp = NULL;
char *kt_full = NULL;
if (principal && krb5_unparse_name(context, principal, &want_unp) != 0)
want_unp = NULL;
(void) krb5_kt_get_full_name(context, id, &kt_full);
krb5_warnx(context, "krb5_kt_get_entry: requested principal=%s keytab=%s kvno=%u enctype=%d",
want_unp ? want_unp : "<null>",
kt_full ? kt_full : "<unknown>",
(unsigned)kvno,
(int)enctype);
free(want_unp);
free(kt_full);
}
if (!principal)
/* Use `NULL' instead of `principal' to quiet static analizers */
return krb5_kt_get_entry_wrapped(context, id, NULL, kvno, enctype,

63
lib/krb5/keytab_file.c
View File

@@ -380,9 +380,19 @@ fkt_start_seq_get_int(krb5_context context,
d->filename, strerror(ret));
return ret;
}
/* Loud logging: record that we opened the keytab file and process info */
krb5_warnx(context, "fkt_start_seq_get_int: opened keytab \"%s\" fd=%d flags=0x%x pid=%d uid=%d",
d->filename ? d->filename : "<null>",
c->fd,
(unsigned)flags,
(int)getpid(),
(int)getuid());
rk_cloexec(c->fd);
ret = _krb5_xlock(context, c->fd, exclusive, d->filename);
if (ret) {
krb5_warnx(context, "fkt_start_seq_get_int: failed to lock keytab \"%s\": ret=%d", d->filename ? d->filename : "<null>", ret);
close(c->fd);
return ret;
}
@@ -394,6 +404,7 @@ fkt_start_seq_get_int(krb5_context context,
stdio_mode = "wb";
c->sp = krb5_storage_stdio_from_fd(c->fd, stdio_mode);
if (c->sp == NULL) {
krb5_warnx(context, "fkt_start_seq_get_int: krb5_storage_stdio_from_fd returned NULL for \"%s\"", d->filename ? d->filename : "<null>");
close(c->fd);
return krb5_enomem(context);
}
@@ -403,12 +414,17 @@ fkt_start_seq_get_int(krb5_context context,
krb5_storage_free(c->sp);
close(c->fd);
krb5_clear_error_message(context);
krb5_warnx(context, "fkt_start_seq_get_int: failed reading pvno from \"%s\": ret=%d", d->filename ? d->filename : "<null>", ret);
return ret;
}
/* Log the pvno read */
krb5_warnx(context, "fkt_start_seq_get_int: keytab \"%s\" pvno=%d", d->filename ? d->filename : "<null>", (int)pvno);
if(pvno != 5) {
krb5_storage_free(c->sp);
close(c->fd);
krb5_clear_error_message (context);
krb5_warnx(context, "fkt_start_seq_get_int: keytab \"%s\" has bad vno (%d)", d->filename ? d->filename : "<null>", (int)pvno);
return KRB5_KEYTAB_BADVNO;
}
ret = krb5_ret_int8(c->sp, &tag);
@@ -416,10 +432,19 @@ fkt_start_seq_get_int(krb5_context context,
krb5_storage_free(c->sp);
close(c->fd);
krb5_clear_error_message(context);
krb5_warnx(context, "fkt_start_seq_get_int: failed reading tag from \"%s\": ret=%d", d->filename ? d->filename : "<null>", ret);
return ret;
}
/* Log the tag/version we read */
krb5_warnx(context, "fkt_start_seq_get_int: keytab \"%s\" header tag=%d", d->filename ? d->filename : "<null>", (int)tag);
id->version = tag;
storage_set_flags(context, c->sp, id->version);
/* Final confirmation log */
krb5_warnx(context, "fkt_start_seq_get_int: keytab \"%s\" opened successfully (fd=%d, version=%d)", d->filename ? d->filename : "<null>", c->fd, (int)id->version);
return 0;
}
@@ -450,26 +475,50 @@ fkt_next_entry_int(krb5_context context,
pos = krb5_storage_seek(cursor->sp, 0, SEEK_CUR);
loop:
ret = krb5_ret_int32(cursor->sp, &len);
if (ret)
if (ret) {
krb5_warnx(context, "fkt_next_entry_int: krb5_ret_int32 returned %d for keytab \"%s\" at pos=%lld", ret, d->filename ? d->filename : "<null>", (long long)pos);
return ret;
}
if(len < 0) {
pos = krb5_storage_seek(cursor->sp, -len, SEEK_CUR);
goto loop;
}
ret = krb5_kt_ret_principal (context, d, cursor->sp, &entry->principal);
if (ret)
if (ret) {
krb5_warnx(context, "fkt_next_entry_int: krb5_kt_ret_principal failed for keytab \"%s\" at pos=%lld: ret=%d", d->filename ? d->filename : "<null>", (long long)pos, ret);
goto out;
}
ret = krb5_ret_uint32(cursor->sp, &utmp32);
entry->timestamp = utmp32;
if (ret)
if (ret) {
krb5_warnx(context, "fkt_next_entry_int: failed reading timestamp for keytab \"%s\" at pos=%lld: ret=%d", d->filename ? d->filename : "<null>", (long long)pos, ret);
goto out;
}
ret = krb5_ret_int8(cursor->sp, &tmp8);
if (ret)
if (ret) {
krb5_warnx(context, "fkt_next_entry_int: failed reading vno (8bit) for keytab \"%s\" at pos=%lld: ret=%d", d->filename ? d->filename : "<null>", (long long)pos, ret);
goto out;
}
entry->vno = tmp8;
ret = krb5_kt_ret_keyblock (context, d, cursor->sp, &entry->keyblock);
if (ret)
if (ret) {
krb5_warnx(context, "fkt_next_entry_int: krb5_kt_ret_keyblock failed for keytab \"%s\" at pos=%lld: ret=%d", d->filename ? d->filename : "<null>", (long long)pos, ret);
goto out;
}
/* Log the entry we just read (principal, vno, enctype, timestamp) */
{
char *princname = NULL;
(void) krb5_unparse_name(context, entry->principal, &princname);
krb5_warnx(context, "fkt_next_entry_int: read entry principal=%s pos=%lld timestamp=%u vno=%d enctype=%d",
princname ? princname : "<unparsed>",
(long long)pos,
(unsigned)entry->timestamp,
entry->vno,
entry->keyblock.keytype);
free(princname);
}
/* there might be a 32 bit kvno here
* if it's zero, assume that the 8bit one was right,
* otherwise trust the new value */
@@ -492,8 +541,10 @@ loop:
if(start) *start = pos;
if(end) *end = pos + 4 + len;
out:
if (ret)
if (ret) {
krb5_warnx(context, "fkt_next_entry_int: error reading keytab \"%s\" at pos=%lld: ret=%d", d->filename ? d->filename : "<null>", (long long)pos, ret);
krb5_kt_free_entry(context, entry);
}
krb5_storage_seek(cursor->sp, pos + 4 + len, SEEK_SET);
return ret;
}

90
lib/krb5/principal.c
View File

@@ -1466,18 +1466,23 @@ krb5_sname_to_principal(krb5_context context,
for (cp = remote_host; *cp; cp++)
if (isupper((unsigned char) (*cp)))
*cp = tolower((unsigned char) (*cp));
/* Debug-ish: record the input/normalized hostname and service for tracing. */
krb5_warnx(context, "krb5_sname_to_principal: remote_host=%s sname=%s type=%d",
remote_host ? remote_host : "<null>",
sname ? sname : "<null>",
(int)type);
/*
* If there is only one name canon rule and it says to
* canonicalize the old way, do that now, as we used to.
*/
ret = _krb5_get_name_canon_rules(context, &rules);
if (ret) {
_krb5_debug(context, 5, "Failed to get name canon rules: ret = %d",
ret);
free(remote_host);
return ret;
}
ret = _krb5_get_name_canon_rules(context, &rules);
if (ret) {
krb5_warnx(context, "Failed to get name canon rules: ret = %d",
ret);
free(remote_host);
return ret;
}
if (rules[0].type == KRB5_NCRT_NSS &&
rules[1].type == KRB5_NCRT_BOGUS) {
_krb5_debug(context, 5, "Using nss for name canon immediately");
@@ -1895,6 +1900,17 @@ apply_name_canon_rule(krb5_context context, krb5_name_canon_rule rules,
_krb5_debug(context, 5, N_("Applying a name rule (type %d) to %s", ""),
rule->type, orig_hostname);
/* Extra debug: print rule details to help trace name canonicalization. */
krb5_warnx(context, "name_canon: rule_idx=%zu type=%d mindots=%u maxdots=%u match_domain=%s match_realm=%s realm=%s domain=%s options=0x%x",
rule_idx,
(int)rule->type,
(unsigned)rule->mindots,
(unsigned)rule->maxdots,
rule->match_domain ? rule->match_domain : "<null>",
rule->match_realm ? rule->match_realm : "<null>",
rule->realm ? rule->realm : "<null>",
rule->domain ? rule->domain : "<null>",
(int)rule->options);
if (rule->mindots > 0 || rule->maxdots > 0) {
for (cp = strchr(orig_hostname, '.'); cp && *cp; cp = strchr(cp + 1, '.'))
@@ -1929,36 +1945,38 @@ apply_name_canon_rule(krb5_context context, krb5_name_canon_rule rules,
new_hostname = tmp_hostname;
break;
case KRB5_NCRT_NSS:
if ((rule->options & KRB5_NCRO_USE_DNSSEC)) {
ret = KRB5KDC_ERR_S_PRINCIPAL_UNKNOWN;
krb5_set_error_message(context, ret,
"Secure hostname resolution not supported");
goto out;
}
_krb5_debug(context, 5, "Using name service lookups");
ret = krb5_sname_to_principal_old(context, rule->realm,
orig_hostname, sname,
KRB5_NT_SRV_HST,
&nss);
if (rules[rule_idx + 1].type != KRB5_NCRT_BOGUS &&
(ret == KRB5_ERR_BAD_HOSTNAME ||
ret == KRB5_ERR_HOST_REALM_UNKNOWN)) {
/*
* Bad hostname / realm unknown -> rule inapplicable if
* there's more rules. If it's the last rule then we want
* to return all errors from krb5_sname_to_principal_old()
* here.
*/
ret = 0;
goto out;
}
if (ret)
goto out;
case KRB5_NCRT_NSS:
if ((rule->options & KRB5_NCRO_USE_DNSSEC)) {
ret = KRB5KDC_ERR_S_PRINCIPAL_UNKNOWN;
krb5_set_error_message(context, ret,
"Secure hostname resolution not supported");
goto out;
}
_krb5_debug(context, 5, "Using name service lookups");
ret = krb5_sname_to_principal_old(context, rule->realm,
orig_hostname, sname,
KRB5_NT_SRV_HST,
&nss);
/* If subsequent rule exists and we got a hostname/realm error,
* treat this rule as inapplicable (unless last rule). */
if (rules[rule_idx + 1].type != KRB5_NCRT_BOGUS &&
(ret == KRB5_ERR_BAD_HOSTNAME ||
ret == KRB5_ERR_HOST_REALM_UNKNOWN)) {
ret = 0;
goto out;
}
if (ret) {
_krb5_debug(context, 3, "krb5_sname_to_principal_old failed for %s: ret=%d", orig_hostname, ret);
goto out;
}
new_hostname = krb5_principal_get_comp_string(context, nss, 1);
new_realm = krb5_principal_get_realm(context, nss);
break;
new_hostname = krb5_principal_get_comp_string(context, nss, 1);
new_realm = krb5_principal_get_realm(context, nss);
/* Log what nss resolution produced for inspection in tests */
_krb5_debug(context, 3, "krb5_sname_to_principal_old: resolved %s -> canonical=%s realm=%s", orig_hostname,
new_hostname ? new_hostname : "<null>",
new_realm ? new_realm : "<null>");
break;
default:
/* Can't happen */