#include "k5-int.h"
#include "pkinit_crypto_openssl.h"
#include "k5-buf.h"
+#include "k5-err.h"
#include "k5-hex.h"
#include <unistd.h>
#include <dirent.h>
CK_TOKEN_INFO *tip, const char *password);
static krb5_error_code pkinit_open_session
(krb5_context context, pkinit_identity_crypto_context id_cryptoctx);
-static struct plugin_file_handle *pkinit_C_LoadModule
-(const char *modname, CK_FUNCTION_LIST_PTR_PTR p11p);
#ifdef SILLYDECRYPT
CK_RV pkinit_C_Decrypt
(pkinit_identity_crypto_context id_cryptoctx,
wrap_signeddata(unsigned char *data, unsigned int data_len,
unsigned char **out, unsigned int *out_len);
-static char *
-pkinit_pkcs11_code_to_text(int err);
+static const char *
+pkcs11err(int err);
#ifdef HAVE_OPENSSL_CMS
}
certstack = X509_STORE_CTX_get1_chain(certctx);
size = sk_X509_num(certstack);
- pkiDebug("size of certificate chain = %d\n", size);
for(i = 0; i < size - 1; i++) {
X509 *x = sk_X509_value(certstack, i);
X509_NAME_oneline(X509_get_subject_name(x), buf, sizeof(buf));
- pkiDebug("cert #%d: %s\n", i, buf);
+ TRACE_PKINIT_CERT_CHAIN_NAME(context, (int)i, buf);
sk_X509_push(cert_stack, X509_dup(x));
}
X509_STORE_CTX_free(certctx);
X509_NAME_oneline(X509_get_subject_name(cert),
buf, sizeof(buf));
- pkiDebug("%s: looking for SANs in cert = %s\n", __FUNCTION__, buf);
l = X509_get_ext_by_NID(cert, NID_subject_alt_name, -1);
if (l < 0)
return 0;
if (!(ext = X509_get_ext(cert, l)) || !(ialt = X509V3_EXT_d2i(ext))) {
- pkiDebug("%s: found no subject alt name extensions\n", __FUNCTION__);
+ TRACE_PKINIT_SAN_CERT_NONE(context, buf);
goto cleanup;
}
num_sans = sk_GENERAL_NAME_num(ialt);
- pkiDebug("%s: found %d subject alt name extension(s)\n", __FUNCTION__,
- num_sans);
-
/* OK, we're likely returning something. Allocate return values */
if (princs_ret != NULL) {
princs = calloc(num_sans + 1, sizeof(krb5_principal));
}
sk_GENERAL_NAME_pop_free(ialt, GENERAL_NAME_free);
+ TRACE_PKINIT_SAN_CERT_COUNT(context, (int)num_sans, p, u, d, buf);
+
retval = 0;
if (princs != NULL && *princs != NULL) {
*princs_ret = princs;
#ifndef WITHOUT_PKCS11
static struct plugin_file_handle *
-pkinit_C_LoadModule(const char *modname, CK_FUNCTION_LIST_PTR_PTR p11p)
+load_pkcs11_module(krb5_context context, const char *modname,
+ CK_FUNCTION_LIST_PTR_PTR p11p)
{
- struct plugin_file_handle *handle;
+ struct plugin_file_handle *handle = NULL;
CK_RV (*getflist)(CK_FUNCTION_LIST_PTR_PTR);
struct errinfo einfo = EMPTY_ERRINFO;
+ const char *errmsg = NULL;
void (*sym)();
long err;
CK_RV rv;
- pkiDebug("loading module \"%s\"... ", modname);
- if (krb5int_open_plugin(modname, &handle, &einfo) != 0) {
- pkiDebug("not found\n");
- return NULL;
+ TRACE_PKINIT_PKCS11_OPEN(context, modname);
+ err = krb5int_open_plugin(modname, &handle, &einfo);
+ if (err) {
+ errmsg = k5_get_error(&einfo, err);
+ TRACE_PKINIT_PKCS11_OPEN_FAILED(context, errmsg);
+ goto error;
}
err = krb5int_get_plugin_func(handle, "C_GetFunctionList", &sym, &einfo);
- k5_clear_error(&einfo);
- if (!err) {
- getflist = (CK_RV (*)())sym;
- rv = (*getflist)(p11p);
+ if (err) {
+ errmsg = k5_get_error(&einfo, err);
+ TRACE_PKINIT_PKCS11_GETSYM_FAILED(context, errmsg);
+ goto error;
}
- if (err || rv != CKR_OK) {
- krb5int_close_plugin(handle);
- pkiDebug("failed\n");
- return NULL;
+
+ getflist = (CK_RV (*)())sym;
+ rv = (*getflist)(p11p);
+ if (rv != CKR_OK) {
+ TRACE_PKINIT_PKCS11_GETFLIST_FAILED(context, pkcs11err(rv));
+ goto error;
}
- pkiDebug("ok\n");
+
return handle;
+
+error:
+ k5_free_error(&einfo, errmsg);
+ k5_clear_error(&einfo);
+ if (handle != NULL)
+ krb5int_close_plugin(handle);
+ return NULL;
}
static krb5_error_code
(u_char *) rdat.data, rdat.length);
if (r != CKR_OK) {
- pkiDebug("C_Login: %s\n", pkinit_pkcs11_code_to_text(r));
+ TRACE_PKINIT_PKCS11_LOGIN_FAILED(context, pkcs11err(r));
r = KRB5KDC_ERR_PREAUTH_FAILED;
}
}
return 0; /* session already open */
/* Load module */
- cctx->p11_module =
- pkinit_C_LoadModule(cctx->p11_module_name, &cctx->p11);
+ cctx->p11_module = load_pkcs11_module(context, cctx->p11_module_name,
+ &cctx->p11);
if (cctx->p11_module == NULL)
return KRB5KDC_ERR_PREAUTH_FAILED;
/* Init */
if ((r = cctx->p11->C_Initialize(NULL)) != CKR_OK) {
- pkiDebug("C_Initialize: %s\n", pkinit_pkcs11_code_to_text(r));
+ pkiDebug("C_Initialize: %s\n", pkcs11err(r));
return KRB5KDC_ERR_PREAUTH_FAILED;
}
/* Get the list of available slots */
if (cctx->p11->C_GetSlotList(TRUE, NULL, &count) != CKR_OK)
return KRB5KDC_ERR_PREAUTH_FAILED;
- if (count == 0)
+ if (count == 0) {
+ TRACE_PKINIT_PKCS11_NO_TOKEN(context);
return KRB5KDC_ERR_PREAUTH_FAILED;
+ }
slotlist = calloc(count, sizeof(CK_SLOT_ID));
if (slotlist == NULL)
return ENOMEM;
/* Open session */
if ((r = cctx->p11->C_OpenSession(slotlist[i], CKF_SERIAL_SESSION,
NULL, NULL, &cctx->session)) != CKR_OK) {
- pkiDebug("C_OpenSession: %s\n", pkinit_pkcs11_code_to_text(r));
+ pkiDebug("C_OpenSession: %s\n", pkcs11err(r));
return KRB5KDC_ERR_PREAUTH_FAILED;
}
/* Get token info */
if ((r = cctx->p11->C_GetTokenInfo(slotlist[i], &tinfo)) != CKR_OK) {
- pkiDebug("C_GetTokenInfo: %s\n", pkinit_pkcs11_code_to_text(r));
+ pkiDebug("C_GetTokenInfo: %s\n", pkcs11err(r));
return KRB5KDC_ERR_PREAUTH_FAILED;
}
}
label_len = cp - tinfo.label;
- pkiDebug("open_session: slotid %d token \"%.*s\"\n",
- (int)slotlist[i], (int)label_len, tinfo.label);
+ TRACE_PKINIT_PKCS11_SLOT(context, (int)slotlist[i], (int)label_len,
+ tinfo.label);
if (cctx->token_label == NULL ||
(strlen(cctx->token_label) == label_len &&
memcmp(cctx->token_label, tinfo.label, label_len) == 0))
}
if (i >= count) {
free(slotlist);
- pkiDebug("open_session: no matching token found\n");
+ TRACE_PKINIT_PKCS11_NO_MATCH_TOKEN(context);
return KRB5KDC_ERR_PREAUTH_FAILED;
}
cctx->slotid = slotlist[i];
r = id_cryptoctx->p11->C_FindObjectsInit(id_cryptoctx->session, attrs, nattrs);
if (r != CKR_OK) {
pkiDebug("krb5_pkinit_sign_data: C_FindObjectsInit: %s\n",
- pkinit_pkcs11_code_to_text(r));
+ pkcs11err(r));
return KRB5KDC_ERR_PREAUTH_FAILED;
}
r = id_cryptoctx->p11->C_FindObjects(id_cryptoctx->session, objp, 1, &count);
id_cryptoctx->p11->C_FindObjectsFinal(id_cryptoctx->session);
- pkiDebug("found %d private keys (%s)\n", (int) count, pkinit_pkcs11_code_to_text(r));
+ pkiDebug("found %d private keys (%s)\n", (int)count, pkcs11err(r));
if (r != CKR_OK || count < 1)
return KRB5KDC_ERR_PREAUTH_FAILED;
return 0;
r = pkinit_C_Decrypt(id_cryptoctx, (CK_BYTE_PTR) data, (CK_ULONG) data_len,
cp, &len);
if (r != CKR_OK) {
- pkiDebug("C_Decrypt: %s\n", pkinit_pkcs11_code_to_text(r));
+ pkiDebug("C_Decrypt: %s\n", pkcs11err(r));
if (r == CKR_BUFFER_TOO_SMALL)
pkiDebug("decrypt %d needs %d\n", (int) data_len, (int) len);
return KRB5KDC_ERR_PREAUTH_FAILED;
if ((r = id_cryptoctx->p11->C_SignInit(id_cryptoctx->session, &mech,
obj)) != CKR_OK) {
- pkiDebug("C_SignInit: %s\n", pkinit_pkcs11_code_to_text(r));
+ pkiDebug("C_SignInit: %s\n", pkcs11err(r));
return KRB5KDC_ERR_PREAUTH_FAILED;
}
(CK_ULONG) data_len, cp, &len);
}
if (r != CKR_OK) {
- pkiDebug("C_Sign: %s\n", pkinit_pkcs11_code_to_text(r));
+ pkiDebug("C_Sign: %s\n", pkcs11err(r));
return KRB5KDC_ERR_PREAUTH_FAILED;
}
pkiDebug("sign %d -> %d\n", (int) data_len, (int) len);
#else
if ((r = id_cryptoctx->p11->C_GetMechanismList(id_cryptoctx->slotid, NULL,
&count)) != CKR_OK || count <= 0) {
- pkiDebug("C_GetMechanismList: %s\n", pkinit_pkcs11_code_to_text(r));
+ pkiDebug("C_GetMechanismList: %s\n", pkcs11err(r));
return KRB5KDC_ERR_PREAUTH_FAILED;
}
mechp = malloc(count * sizeof (CK_MECHANISM_TYPE));
r = id_cryptoctx->p11->C_FindObjectsInit(id_cryptoctx->session, attrs, nattrs);
if (r != CKR_OK) {
- pkiDebug("C_FindObjectsInit: %s\n", pkinit_pkcs11_code_to_text(r));
+ pkiDebug("C_FindObjectsInit: %s\n", pkcs11err(r));
return KRB5KDC_ERR_PREAUTH_FAILED;
}
if ((r = id_cryptoctx->p11->C_GetAttributeValue(id_cryptoctx->session,
obj, attrs, 2)) != CKR_OK && r != CKR_BUFFER_TOO_SMALL) {
- pkiDebug("C_GetAttributeValue: %s\n", pkinit_pkcs11_code_to_text(r));
+ pkiDebug("C_GetAttributeValue: %s\n", pkcs11err(r));
return KRB5KDC_ERR_PREAUTH_FAILED;
}
cert = (CK_BYTE_PTR) malloc((size_t) attrs[0].ulValueLen + 1);
if ((r = id_cryptoctx->p11->C_GetAttributeValue(id_cryptoctx->session,
obj, attrs, 2)) != CKR_OK) {
- pkiDebug("C_GetAttributeValue: %s\n", pkinit_pkcs11_code_to_text(r));
+ pkiDebug("C_GetAttributeValue: %s\n", pkcs11err(r));
return KRB5KDC_ERR_PREAUTH_FAILED;
}
{
switch (idtype) {
case IDTYPE_FILE:
- TRACE_PKINIT_LOAD_FROM_FILE(context);
+ TRACE_PKINIT_LOAD_FROM_FILE(context, id);
return load_cas_and_crls(context, plg_cryptoctx, req_cryptoctx,
id_cryptoctx, catype, id);
break;
case IDTYPE_DIR:
- TRACE_PKINIT_LOAD_FROM_DIR(context);
+ TRACE_PKINIT_LOAD_FROM_DIR(context, id);
return load_cas_and_crls_dir(context, plg_cryptoctx, req_cryptoctx,
id_cryptoctx, catype, id);
break;
}
#endif
-static char *
-pkinit_pkcs11_code_to_text(int err)
+static const char *
+pkcs11err(int err)
{
int i;
- static char uc[32];
for (i = 0; pkcs11_errstrings[i].text != NULL; i++)
if (pkcs11_errstrings[i].code == err)
break;
if (pkcs11_errstrings[i].text != NULL)
return (pkcs11_errstrings[i].text);
- snprintf(uc, sizeof(uc), _("unknown code 0x%x"), err);
- return (uc);
+
+ return "unknown PKCS11 error";
}
/*
}
static int
-regexp_match(krb5_context context, rule_component *rc, char *value)
+regexp_match(krb5_context context, rule_component *rc, char *value, int idx)
{
int code;
- pkiDebug("%s: checking %s rule '%s' with value '%s'\n",
- __FUNCTION__, keyword2string(rc->kw_type), rc->regsrc, value);
-
code = regexec(&rc->regexp, value, 0, NULL, 0);
- pkiDebug("%s: the result is%s a match\n", __FUNCTION__,
- code == REG_NOMATCH ? " NOT" : "");
+ if (code == 0) {
+ TRACE_PKINIT_REGEXP_MATCH(context, keyword2string(rc->kw_type),
+ rc->regsrc, value, idx);
+ } else {
+ TRACE_PKINIT_REGEXP_NOMATCH(context, keyword2string(rc->kw_type),
+ rc->regsrc, value, idx);
+ }
return (code == 0 ? 1: 0);
}
static int
-component_match(krb5_context context,
- rule_component *rc,
- pkinit_cert_matching_data *md)
+component_match(krb5_context context, rule_component *rc,
+ pkinit_cert_matching_data *md, int idx)
{
int match = 0;
int i;
case kwvaltype_regexp:
switch (rc->kw_type) {
case kw_subject:
- match = regexp_match(context, rc, md->subject_dn);
+ match = regexp_match(context, rc, md->subject_dn, idx);
break;
case kw_issuer:
- match = regexp_match(context, rc, md->issuer_dn);
+ match = regexp_match(context, rc, md->issuer_dn, idx);
break;
case kw_san:
for (i = 0; md->sans != NULL && md->sans[i] != NULL; i++) {
krb5_unparse_name(context, md->sans[i], &princ_string);
- match = regexp_match(context, rc, princ_string);
+ match = regexp_match(context, rc, princ_string, idx);
krb5_free_unparsed_name(context, princ_string);
if (match)
break;
}
for (i = 0; md->upns != NULL && md->upns[i] != NULL; i++) {
- match = regexp_match(context, rc, md->upns[i]);
+ match = regexp_match(context, rc, md->upns[i], idx);
if (match)
break;
}
pkiDebug("%s: subject: '%s'\n", __FUNCTION__, md->subject_dn);
certs_checked++;
for (rc = rs->crs; rc != NULL; rc = rc->next) {
- comp_match = component_match(context, rc, md);
+ comp_match = component_match(context, rc, md, i);
if (comp_match) {
pkiDebug("%s: match for keyword type %s\n",
__FUNCTION__, keyword2string(rc->kw_type));
nextcert:
continue;
}
- pkiDebug("%s: After checking %d certs, we found %d matches\n",
- __FUNCTION__, certs_checked, total_cert_matches);
+ TRACE_PKINIT_CERT_NUM_MATCHING(context, certs_checked, total_cert_matches);
if (total_cert_matches == 1) {
*match_found = 1;
*match_index = save_index;
/* parse each rule line one at a time and check all the certs against it */
for (x = 0; rules[x] != NULL; x++) {
- pkiDebug("%s: Processing rule '%s'\n", __FUNCTION__, rules[x]);
+ TRACE_PKINIT_CERT_RULE(context, rules[x]);
/* Free rules from previous time through... */
if (rs != NULL) {
retval = parse_rule_set(context, rules[x], &rs);
if (retval) {
if (retval == EINVAL) {
- pkiDebug("%s: Ignoring invalid rule pkinit_cert_match = '%s'\n",
- __FUNCTION__, rules[x]);
+ TRACE_PKINIT_CERT_RULE_INVALID(context, rules[x]);
continue;
}
goto cleanup;
goto cleanup;
for (rc = rs->crs; rc != NULL; rc = rc->next) {
- comp_match = component_match(context, rc, md);
+ comp_match = component_match(context, rc, md, 0);
if ((comp_match && rs->relation == relation_or) ||
(!comp_match && rs->relation == relation_and)) {
break;
#define TRACE_PKINIT_OPENSSL_ERROR(c, msg) \
TRACE(c, "PKINIT OpenSSL error: {str}", msg)
+#define TRACE_PKINIT_PKCS11_GETFLIST_FAILED(c, errstr) \
+ TRACE(c, "PKINIT PKCS11 C_GetFunctionList failed: {str}", errstr)
+#define TRACE_PKINIT_PKCS11_GETSYM_FAILED(c, errstr) \
+ TRACE(c, "PKINIT unable to find PKCS11 plugin symbol " \
+ "C_GetFunctionList: {str}", errstr)
+#define TRACE_PKINIT_PKCS11_LOGIN_FAILED(c, errstr) \
+ TRACE(c, "PKINIT PKCS11 C_Login failed: {str}", errstr)
+#define TRACE_PKINIT_PKCS11_NO_MATCH_TOKEN(c) \
+ TRACE(c, "PKINIT PKCS#11 module has no matching tokens")
+#define TRACE_PKINIT_PKCS11_NO_TOKEN(c) \
+ TRACE(c, "PKINIT PKCS#11 module shows no slots with tokens")
+#define TRACE_PKINIT_PKCS11_OPEN(c, name) \
+ TRACE(c, "PKINIT opening PKCS#11 module \"{str}\"", name)
+#define TRACE_PKINIT_PKCS11_OPEN_FAILED(c, errstr) \
+ TRACE(c, "PKINIT PKCS#11 module open failed: {str}", errstr)
+#define TRACE_PKINIT_PKCS11_SLOT(c, slot, len, label) \
+ TRACE(c, "PKINIT PKCS#11 slotid {int} token {lenstr}", \
+ slot, len, label)
+
#define TRACE_PKINIT_SERVER_CERT_AUTH(c, modname) \
TRACE(c, "PKINIT server authorizing cert with module {str}", \
modname)
TRACE(c, "PKINIT server could not parse UPN \"{str}\": {kerr}", \
upn, ret)
+#define TRACE_PKINIT_CERT_CHAIN_NAME(c, index, name) \
+ TRACE(c, "PKINIT chain cert #{int}: {str}", index, name)
+#define TRACE_PKINIT_CERT_NUM_MATCHING(c, total, nummatch) \
+ TRACE(c, "PKINIT client checked {int} certs, found {int} matches", \
+ total, nummatch)
+#define TRACE_PKINIT_CERT_RULE(c, rule) \
+ TRACE(c, "PKINIT client matching rule '{str}' against certificates", rule)
+#define TRACE_PKINIT_CERT_RULE_INVALID(c, rule) \
+ TRACE(c, "PKINIT client ignoring invalid rule '{str}'", rule)
+
#define TRACE_PKINIT_EKU(c) \
TRACE(c, "PKINIT found acceptable EKU and digitalSignature KU")
#define TRACE_PKINIT_EKU_NO_KU(c) \
TRACE(c, "PKINIT found acceptable EKU but no digitalSignature KU")
+#define TRACE_PKINIT_IDENTITY_OPTION(c, name) \
+ TRACE(c, "PKINIT loading identity {str}", name)
#define TRACE_PKINIT_LOADED_CERT(c, name) \
TRACE(c, "PKINIT loaded cert and key for {str}", name)
-#define TRACE_PKINIT_LOAD_FROM_FILE(c) \
- TRACE(c, "PKINIT loading CA certs and CRLs from FILE")
-#define TRACE_PKINIT_LOAD_FROM_DIR(c) \
- TRACE(c, "PKINIT loading CA certs and CRLs from DIR")
+#define TRACE_PKINIT_LOAD_FROM_FILE(c, name) \
+ TRACE(c, "PKINIT loading CA certs and CRLs from FILE {str}", name)
+#define TRACE_PKINIT_LOAD_FROM_DIR(c, name) \
+ TRACE(c, "PKINIT loading CA certs and CRLs from DIR {str}", name)
#define TRACE_PKINIT_NO_CA_ANCHOR(c, file) \
TRACE(c, "PKINIT no anchor CA in file {str}", file)
#define TRACE_PKINIT_NO_CA_INTERMEDIATE(c, file) \
TRACE(c, "PKINIT second PKCS12_parse with password failed")
#define TRACE_PKINIT_PKCS_PROMPT_FAIL(c) \
TRACE(c, "PKINIT failed to prompt for PKCS12 password")
+#define TRACE_PKINIT_REGEXP_MATCH(c, keyword, comp, value, idx) \
+ TRACE(c, "PKINIT matched {str} rule '{str}' with " \
+ "value '{str}' in cert #{int}", keyword, comp, value, (idx) + 1)
+#define TRACE_PKINIT_REGEXP_NOMATCH(c, keyword, comp, value, idx) \
+ TRACE(c, "PKINIT didn't match {str} rule '{str}' with " \
+ "value '{str}' in cert #{int}", keyword, comp, value, (idx) + 1)
+#define TRACE_PKINIT_SAN_CERT_COUNT(c, count, princ, upns, dns, cert) \
+ TRACE(c, "PKINIT client found {int} SANs ({int} princs, {int} " \
+ "UPNs, {int} DNS names) in certificate {str}", count, princ, \
+ upns, dns, cert)
+#define TRACE_PKINIT_SAN_CERT_NONE(c, cert) \
+ TRACE(c, "PKINIT client found no SANs in certificate {str}", cert)
#define TRACE_CERTAUTH_VTINIT_FAIL(c, ret) \
TRACE(c, "certauth module failed to init vtable: {kerr}", ret)
projects / thirdparty / krb5.git / commitdiff
