pkcs11: use short form of log messages

Change-Id: Ice298552238da9eeb0b646fc1ddfaf4d7a8ee4bb
This commit is contained in:
Viktor Tarasov 2012-05-13 00:27:38 +02:00
parent 5d1feb3051
commit 20bf3f5484
7 changed files with 140 additions and 142 deletions

View File

@ -163,19 +163,20 @@ static CK_RV pkcs15_bind(struct sc_pkcs11_card *p11card)
int rc;
CK_RV rv;
sc_log(context, "Bind PKCS#15 application");
if (!(fw_data = calloc(1, sizeof(*fw_data))))
return CKR_HOST_MEMORY;
p11card->fw_data = fw_data;
rc = sc_pkcs15_bind(p11card->card, NULL, &fw_data->p15_card);
if (rc != SC_SUCCESS) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "sc_pkcs15_bind failed: %d", rc);
sc_log(context, "sc_pkcs15_bind failed: %d", rc);
return sc_to_cryptoki_error(rc, NULL);
}
rv = register_mechanisms(p11card);
if (rv != CKR_OK) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "register_mechanisms failed: 0x%x", rv);
sc_log(context, "register_mechanisms failed: 0x%x", rv);
return rv;
}
@ -329,7 +330,7 @@ CK_RV C_GetTokenInfo(CK_SLOT_ID slotID, CK_TOKEN_INFO_PTR pInfo)
if (rv != CKR_OK)
return rv;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_GetTokenInfo(%lx)", slotID);
sc_log(context, "C_GetTokenInfo(%lx)", slotID);
rv = slot_get_token(slotID, &slot);
if (rv != CKR_OK)
@ -490,7 +491,7 @@ __pkcs15_create_pubkey_object(struct pkcs15_fw_data *fw_data,
/* if emulation already created pubkey use it */
if (pubkey->emulated && (fw_data->p15_card->flags & SC_PKCS15_CARD_FLAG_EMULATED)) {
p15_key = (struct sc_pkcs15_pubkey *) pubkey->emulated;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Using emulated pubkey %p", p15_key);
sc_log(context, "Using emulated pubkey %p", p15_key);
}
else {
if ((rv = sc_pkcs15_read_pubkey(fw_data->p15_card, pubkey, &p15_key)) < 0)
@ -572,7 +573,7 @@ pkcs15_create_pkcs11_objects(struct pkcs15_fw_data *fw_data,
rv = count = sc_pkcs15_get_objects(fw_data->p15_card, p15_type, p15_object, MAX_OBJECTS);
if (rv >= 0) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Found %d %s%s\n", count,
sc_log(context, "Found %d %s%s\n", count,
name, (count == 1)? "" : "s");
}
@ -589,7 +590,7 @@ __pkcs15_prkey_bind_related(struct pkcs15_fw_data *fw_data, struct pkcs15_prkey_
sc_pkcs15_id_t *id = &pk->prv_info->id;
unsigned int i;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Object is a private key and has id %s",
sc_log(context, "Object is a private key and has id %s",
sc_pkcs15_print_id(id));
for (i = 0; i < fw_data->num_objects; i++) {
@ -615,7 +616,7 @@ __pkcs15_prkey_bind_related(struct pkcs15_fw_data *fw_data, struct pkcs15_prkey_
pubkey = (struct pkcs15_pubkey_object *) obj;
if (sc_pkcs15_compare_id(&pubkey->pub_info->id, id)) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Associating object %d as public key", i);
sc_log(context, "Associating object %d as public key", i);
pk->prv_pubkey = pubkey;
if (pk->prv_info->modulus_length == 0)
pk->prv_info->modulus_length = pubkey->pub_info->modulus_length;
@ -631,7 +632,7 @@ __pkcs15_cert_bind_related(struct pkcs15_fw_data *fw_data, struct pkcs15_cert_ob
sc_pkcs15_id_t *id = &cert->cert_info->id;
unsigned int i;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Object is a certificate and has id %s",
sc_log(context, "Object is a certificate and has id %s",
sc_pkcs15_print_id(id));
/* Loop over all objects to see if we find the certificate of
@ -650,7 +651,7 @@ __pkcs15_cert_bind_related(struct pkcs15_fw_data *fw_data, struct pkcs15_cert_ob
continue;
if (c1->issuer_len == c2->subject_len
&& !memcmp(c1->issuer, c2->subject, c1->issuer_len)) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Associating object %d (id %s) as issuer",
sc_log(context, "Associating object %d (id %s) as issuer",
i, sc_pkcs15_print_id(&cert2->cert_info->id));
cert->cert_issuer = (struct pkcs15_cert_object *) obj;
return;
@ -661,7 +662,7 @@ __pkcs15_cert_bind_related(struct pkcs15_fw_data *fw_data, struct pkcs15_cert_ob
pk = (struct pkcs15_prkey_object *) obj;
if (sc_pkcs15_compare_id(&pk->prv_info->id, id)) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Associating object %d as private key", i);
sc_log(context, "Associating object %d as private key", i);
cert->cert_prvkey = pk;
}
}
@ -682,7 +683,7 @@ pkcs15_bind_related_objects(struct pkcs15_fw_data *fw_data)
if (obj->base.flags & SC_PKCS11_OBJECT_HIDDEN)
continue;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Looking for objects related to object %d", i);
sc_log(context, "Looking for objects related to object %d", i);
if (is_privkey(obj)) {
__pkcs15_prkey_bind_related(fw_data, (struct pkcs15_prkey_object *) obj);
@ -750,7 +751,7 @@ pkcs15_add_object(struct sc_pkcs11_slot *slot,
*pHandle = (CK_OBJECT_HANDLE)obj; /* cast pointer to long */
list_append(&slot->objects, obj);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Setting object handle of 0x%lx to 0x%lx", obj->base.handle, (CK_OBJECT_HANDLE)obj);
sc_log(context, "Setting object handle of 0x%lx to 0x%lx", obj->base.handle, (CK_OBJECT_HANDLE)obj);
obj->base.handle = (CK_OBJECT_HANDLE)obj; /* cast pointer to long */
obj->base.flags |= SC_PKCS11_OBJECT_SEEN;
obj->refcount++;
@ -841,7 +842,7 @@ static void pkcs15_init_slot(struct sc_pkcs15_card *p15card,
if (p15card->flags & SC_PKCS15_CARD_FLAG_EMULATED)
slot->token_info.flags |= CKF_WRITE_PROTECTED;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Initialized token '%s' in slot 0x%lx", tmp, slot->id);
sc_log(context, "Initialized token '%s' in slot 0x%lx", tmp, slot->id);
}
static CK_RV pkcs15_create_slot(struct sc_pkcs11_card *p11card,
@ -882,7 +883,7 @@ static CK_RV pkcs15_create_tokens(struct sc_pkcs11_card *p11card)
SC_PKCS15_MAX_PINS);
if (rv < 0)
return sc_to_cryptoki_error(rv, NULL);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Found %d authentication objects\n", rv);
sc_log(context, "Found %d authentication objects\n", rv);
auth_count = rv;
rv = pkcs15_create_pkcs11_objects(fw_data,
@ -991,15 +992,15 @@ static CK_RV pkcs15_create_tokens(struct sc_pkcs11_card *p11card)
continue;
if (is_privkey(obj)) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Adding private key %d to PIN %d\n", j, i);
sc_log(context, "Adding private key %d to PIN %d\n", j, i);
pkcs15_add_object(slot, obj, NULL);
}
else if (is_data(obj)) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Adding data object %d to PIN %d\n", j, i);
sc_log(context, "Adding data object %d to PIN %d\n", j, i);
pkcs15_add_object(slot, obj, NULL);
}
else if (is_cert(obj)) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Adding cert object %d to PIN %d\n", j, i);
sc_log(context, "Adding cert object %d to PIN %d\n", j, i);
pkcs15_add_object(slot, obj, NULL);
}
}
@ -1022,7 +1023,7 @@ static CK_RV pkcs15_create_tokens(struct sc_pkcs11_card *p11card)
break;
if (!(obj->base.flags & SC_PKCS11_OBJECT_SEEN)) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "%d: Object ('%s',type:%X) was not seen previously\n", j,
sc_log(context, "%d: Object ('%s',type:%X) was not seen previously\n", j,
obj->p15_object->label, obj->p15_object->type);
if (!slot) {
rv = pkcs15_create_slot(p11card, NULL, &slot);
@ -1043,7 +1044,7 @@ static CK_RV pkcs15_create_tokens(struct sc_pkcs11_card *p11card)
}
}
*/
sc_debug(context, SC_LOG_DEBUG_NORMAL, "All tokens created\n");
sc_log(context, "All tokens created\n");
return CKR_OK;
}
@ -1091,7 +1092,7 @@ static CK_RV pkcs15_login(struct sc_pkcs11_slot *slot,
}
}
sc_debug(context, SC_LOG_DEBUG_NORMAL, "No SOPIN found; returns %d", rc);
sc_log(context, "No SOPIN found; returns %d", rc);
return sc_to_cryptoki_error(rc, "C_Login");
}
else if (rc < 0) {
@ -1106,7 +1107,7 @@ static CK_RV pkcs15_login(struct sc_pkcs11_slot *slot,
* using the correct auth_object.
* TODO: handle the CK_SO case
*/
sc_debug(context, SC_LOG_DEBUG_NORMAL, "context specific login %d",
sc_log(context, "context specific login %d",
slot->login_user);
if (slot->login_user == CKU_USER) {
auth_object = slot_data_auth(slot->fw_data);
@ -1132,7 +1133,7 @@ static CK_RV pkcs15_login(struct sc_pkcs11_slot *slot,
}
}
#endif
sc_debug(context, SC_LOG_DEBUG_NORMAL, "context specific login returns %d", rc);
sc_log(context, "context specific login returns %d", rc);
return sc_to_cryptoki_error(rc, "C_Login");
default:
return CKR_USER_TYPE_INVALID;
@ -1183,7 +1184,7 @@ static CK_RV pkcs15_login(struct sc_pkcs11_slot *slot,
}
rc = sc_pkcs15_verify_pin(p15card, auth_object, pPin, ulPinLen);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "PKCS15 verify PIN returned %d", rc);
sc_log(context, "PKCS15 verify PIN returned %d", rc);
if (rc != SC_SUCCESS)
return sc_to_cryptoki_error(rc, "C_Login");
@ -1192,7 +1193,7 @@ static CK_RV pkcs15_login(struct sc_pkcs11_slot *slot,
sc_pkcs15_object_t *p15_obj = p15card->obj_list;
sc_pkcs15_search_key_t sk;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Check if pkcs15 object list can be completed.");
sc_log(context, "Check if pkcs15 object list can be completed.");
/* Ensure non empty list */
if (p15_obj == NULL)
@ -1229,7 +1230,7 @@ static CK_RV pkcs15_login(struct sc_pkcs11_slot *slot,
default: continue;
}
sc_debug(context, SC_LOG_DEBUG_NORMAL, "new object found: type=0x%03X", p15_obj->type);
sc_log(context, "new object found: type=0x%03X", p15_obj->type);
pkcs15_add_object(slot, fw_obj, NULL);
}
}
@ -1282,7 +1283,7 @@ static CK_RV pkcs15_change_pin(struct sc_pkcs11_card *p11card,
if (!(auth_info = slot_data_auth_info(fw_token)))
return CKR_USER_PIN_NOT_INITIALIZED;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Change '%s', reference %i; login type %i",
sc_log(context, "Change '%s', reference %i; login type %i",
pin_obj->label, auth_info->attrs.pin.reference, login_user);
if (p11card->card->reader->capabilities & SC_READER_CAP_PIN_PAD) {
/* pPin should be NULL in case of a pin pad reader, but
@ -1300,14 +1301,14 @@ static CK_RV pkcs15_change_pin(struct sc_pkcs11_card *p11card,
if (login_user < 0) {
if (sc_pkcs11_conf.pin_unblock_style != SC_PKCS11_PIN_UNBLOCK_UNLOGGED_SETPIN) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "PIN unlock is not allowed in unlogged session");
sc_log(context, "PIN unlock is not allowed in unlogged session");
return CKR_FUNCTION_NOT_SUPPORTED;
}
rc = sc_pkcs15_unblock_pin(fw_data->p15_card, pin_obj, pOldPin, ulOldLen, pNewPin, ulNewLen);
}
else if (login_user == CKU_CONTEXT_SPECIFIC) {
if (sc_pkcs11_conf.pin_unblock_style != SC_PKCS11_PIN_UNBLOCK_SCONTEXT_SETPIN) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "PIN unlock is not allowed with CKU_CONTEXT_SPECIFIC login");
sc_log(context, "PIN unlock is not allowed with CKU_CONTEXT_SPECIFIC login");
return CKR_FUNCTION_NOT_SUPPORTED;
}
rc = sc_pkcs15_unblock_pin(fw_data->p15_card, pin_obj, pOldPin, ulOldLen, pNewPin, ulNewLen);
@ -1329,18 +1330,18 @@ static CK_RV pkcs15_change_pin(struct sc_pkcs11_card *p11card,
break;
}
if (i == auth_count) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Change SoPIN non supported");
sc_log(context, "Change SoPIN non supported");
return CKR_FUNCTION_NOT_SUPPORTED;
}
rc = sc_pkcs15_change_pin(fw_data->p15_card, auths[i], pOldPin, ulOldLen, pNewPin, ulNewLen);
}
else {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "cannot change PIN: non supported login type: %i", login_user);
sc_log(context, "cannot change PIN: non supported login type: %i", login_user);
return CKR_FUNCTION_NOT_SUPPORTED;
}
sc_debug(context, SC_LOG_DEBUG_NORMAL, "PIN change returns %d\n", rc);
sc_log(context, "PIN change returns %d\n", rc);
return sc_to_cryptoki_error(rc, "C_SetPIN");
}
@ -1356,7 +1357,7 @@ static CK_RV pkcs15_init_pin(struct sc_pkcs11_card *p11card,
struct sc_pkcs15_auth_info *auth_info;
int rc;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "pkcs15 init PIN: pin %p:%d; unblock style %i",
sc_log(context, "pkcs15 init PIN: pin %p:%d; unblock style %i",
pPin, ulPinLen, sc_pkcs11_conf.pin_unblock_style);
auth_info = slot_data_auth_info(slot->fw_data);
@ -1536,14 +1537,14 @@ static CK_RV pkcs15_create_private_key(struct sc_pkcs11_card *p11card,
if (key_type == CKK_RSA) {
if (!rsa->modulus.len || !rsa->exponent.len || !rsa->d.len || !rsa->p.len || !rsa->q.len) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Template to store the RSA key is incomplete");
sc_log(context, "Template to store the RSA key is incomplete");
rv = CKR_TEMPLATE_INCOMPLETE;
goto out;
}
}
else if (key_type == CKK_GOSTR3410) {
if (!gost->d.len) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Template to store the GOST key is incomplete");
sc_log(context, "Template to store the GOST key is incomplete");
return CKR_ATTRIBUTE_VALUE_INVALID;
}
/* CKA_VALUE arrives in little endian form. pkcs15init framework expects it in a big endian one. */
@ -1896,7 +1897,7 @@ get_X509_usage_privk(CK_ATTRIBUTE_PTR pTempl, CK_ULONG ulCount, unsigned long *x
if (typ == CKA_DERIVE && *val)
*x509_usage |= SC_PKCS15INIT_X509_KEY_AGREEMENT;
if (typ == CKA_VERIFY || typ == CKA_WRAP || typ == CKA_ENCRYPT) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "get_X509_usage_privk(): invalid typ = 0x%0x\n", typ);
sc_log(context, "get_X509_usage_privk(): invalid typ = 0x%0x\n", typ);
return CKR_ATTRIBUTE_TYPE_INVALID;
}
}
@ -1921,7 +1922,7 @@ get_X509_usage_pubk(CK_ATTRIBUTE_PTR pTempl, CK_ULONG ulCount, unsigned long *x5
if (typ == CKA_DERIVE && *val)
*x509_usage |= SC_PKCS15INIT_X509_KEY_AGREEMENT;
if (typ == CKA_SIGN || typ == CKA_UNWRAP || typ == CKA_DECRYPT) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "get_X509_usage_pubk(): invalid typ = 0x%0x\n", typ);
sc_log(context, "get_X509_usage_pubk(): invalid typ = 0x%0x\n", typ);
return CKR_ATTRIBUTE_TYPE_INVALID;
}
}
@ -1991,7 +1992,7 @@ static CK_RV pkcs15_gen_keypair(struct sc_pkcs11_card *p11card,
char priv_label[SC_PKCS15_MAX_LABEL_SIZE];
int rc, rv = CKR_OK;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Keypair generation, mech = 0x%0x\n", pMechanism->mechanism);
sc_log(context, "Keypair generation, mech = 0x%0x\n", pMechanism->mechanism);
if (pMechanism->mechanism != CKM_RSA_PKCS_KEY_PAIR_GEN
&& pMechanism->mechanism != CKM_GOSTR3410_KEY_PAIR_GEN
@ -2098,20 +2099,20 @@ static CK_RV pkcs15_gen_keypair(struct sc_pkcs11_card *p11card,
sc_pkcs15init_set_p15card(profile, fw_data->p15_card);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Try on-card key pair generation");
sc_log(context, "Try on-card key pair generation");
rc = sc_pkcs15init_generate_key(fw_data->p15_card, profile,
&keygen_args, keybits, &priv_key_obj);
if (rc >= 0) {
id = ((struct sc_pkcs15_prkey_info *) priv_key_obj->data)->id;
rc = sc_pkcs15_find_pubkey_by_id(fw_data->p15_card, &id, &pub_key_obj);
if (rc != 0) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "sc_pkcs15_find_pubkey_by_id returned %d\n", rc);
sc_log(context, "sc_pkcs15_find_pubkey_by_id returned %d\n", rc);
rv = sc_to_cryptoki_error(rc, "C_GenerateKeyPair");
goto kpgen_done;
}
}
else if (rc != SC_ERROR_NOT_SUPPORTED) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "sc_pkcs15init_generate_key returned %d\n", rc);
sc_log(context, "sc_pkcs15init_generate_key returned %d\n", rc);
rv = sc_to_cryptoki_error(rc, "C_GenerateKeyPair");
goto kpgen_done;
}
@ -2122,7 +2123,7 @@ static CK_RV pkcs15_gen_keypair(struct sc_pkcs11_card *p11card,
if (rc == 0)
rc = __pkcs15_create_pubkey_object(fw_data, pub_key_obj, &pub_any_obj);
if (rc != 0) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "__pkcs15_create_pr/pubkey_object returned %d\n", rc);
sc_log(context, "__pkcs15_create_pr/pubkey_object returned %d\n", rc);
rv = sc_to_cryptoki_error(rc, "C_GenerateKeyPair");
goto kpgen_done;
}
@ -2626,7 +2627,7 @@ static CK_RV pkcs15_prkey_sign(struct sc_pkcs11_session *ses, void *obj,
struct pkcs15_fw_data *fw_data = (struct pkcs15_fw_data *) ses->slot->card->fw_data;
int rv, flags = 0;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Initiating signing operation, mechanism 0x%x.\n",
sc_log(context, "Initiating signing operation, mechanism 0x%x.\n",
pMechanism->mechanism);
/* See which of the alternative keys supports signing */
@ -2691,7 +2692,7 @@ static CK_RV pkcs15_prkey_sign(struct sc_pkcs11_session *ses, void *obj,
break;
#endif
default:
sc_debug(context, SC_LOG_DEBUG_NORMAL, "DEE - need EC for %d",pMechanism->mechanism);
sc_log(context, "DEE - need EC for %d",pMechanism->mechanism);
return CKR_MECHANISM_INVALID;
}
@ -2707,7 +2708,7 @@ static CK_RV pkcs15_prkey_sign(struct sc_pkcs11_session *ses, void *obj,
}
}
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Selected flags %X. Now computing signature for %d bytes. %d bytes reserved.\n", flags, ulDataLen, *pulDataLen);
sc_log(context, "Selected flags %X. Now computing signature for %d bytes. %d bytes reserved.\n", flags, ulDataLen, *pulDataLen);
rv = sc_pkcs15_compute_signature(fw_data->p15_card,
prkey->prv_p15obj,
flags,
@ -2718,7 +2719,7 @@ static CK_RV pkcs15_prkey_sign(struct sc_pkcs11_session *ses, void *obj,
sc_unlock(ses->slot->card->card);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Sign complete. Result %d.\n", rv);
sc_log(context, "Sign complete. Result %d.\n", rv);
if (rv > 0) {
*pulDataLen = rv;
@ -2739,7 +2740,7 @@ pkcs15_prkey_decrypt(struct sc_pkcs11_session *ses, void *obj,
u8 decrypted[256]; /* FIXME: Will not work for keys above 2048 bits */
int buff_too_small, rv, flags = 0;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Initiating decryption.\n");
sc_log(context, "Initiating decryption.\n");
/* See which of the alternative keys supports decrypt */
prkey = (struct pkcs15_prkey_object *) obj;
@ -2781,7 +2782,7 @@ pkcs15_prkey_decrypt(struct sc_pkcs11_session *ses, void *obj,
sc_unlock(ses->slot->card->card);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Decryption complete. Result %d.\n", rv);
sc_log(context, "Decryption complete. Result %d.\n", rv);
if (rv < 0)
return sc_to_cryptoki_error(rv, "C_Decrypt");
@ -3037,8 +3038,8 @@ static CK_RV data_value_to_attr(CK_ATTRIBUTE_PTR attr, struct sc_pkcs15_data *da
if (!attr || !data)
return CKR_ATTRIBUTE_VALUE_INVALID;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "data %p\n", data);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "data_len %i\n", data->data_len);
sc_log(context, "data %p\n", data);
sc_log(context, "data_len %i\n", data->data_len);
check_attribute_buffer(attr, data->data_len);
memcpy(attr->pValue, data->data, data->data_len);
@ -3583,7 +3584,7 @@ static int lock_card(struct pkcs15_fw_data *fw_data)
int rc;
if ((rc = sc_lock(fw_data->p15_card->card)) < 0)
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Failed to lock card (%d)\n", rc);
sc_log(context, "Failed to lock card (%d)\n", rc);
else
fw_data->locked++;
@ -3608,7 +3609,7 @@ static int reselect_app_df(sc_pkcs15_card_t *p15card)
/* if the application df (of the pkcs15 application) is
* specified select it */
sc_path_t *tpath = &p15card->file_app->path;
sc_debug(p15card->card->ctx, SC_LOG_DEBUG_NORMAL, "reselect application df\n");
sc_log(p15card->card->ctx, "reselect application df\n");
r = sc_select_file(p15card->card, tpath, NULL);
}
return r;

View File

@ -56,7 +56,7 @@ void strcpy_bp(u8 * dst, const char *src, size_t dstsize)
static CK_RV sc_to_cryptoki_error_common(int rc)
{
sc_debug(context, SC_LOG_DEBUG_NORMAL, "libopensc return value: %d (%s)\n", rc, sc_strerror(rc));
sc_log(context, "libopensc return value: %d (%s)\n", rc, sc_strerror(rc));
switch (rc) {
case SC_SUCCESS:
return CKR_OK;
@ -133,8 +133,8 @@ CK_RV session_start_operation(struct sc_pkcs11_session * session,
if (context == NULL)
return CKR_CRYPTOKI_NOT_INITIALIZED;
SC_FUNC_CALLED(context, SC_LOG_DEBUG_NORMAL);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Session 0x%lx, type %d", session->handle, type);
LOG_FUNC_CALLED(context);
sc_log(context, "Session 0x%lx, type %d", session->handle, type);
if (type < 0 || type >= SC_PKCS11_OPERATION_MAX)
return CKR_ARGUMENTS_BAD;
@ -155,7 +155,7 @@ CK_RV session_get_operation(struct sc_pkcs11_session * session, int type, sc_pkc
{
sc_pkcs11_operation_t *op;
SC_FUNC_CALLED(context, SC_LOG_DEBUG_NORMAL);
LOG_FUNC_CALLED(context);
if (type < 0 || type >= SC_PKCS11_OPERATION_MAX)
return CKR_ARGUMENTS_BAD;
@ -316,7 +316,7 @@ void load_pkcs11_parameters(struct sc_pkcs11_config *conf, sc_context_t * ctx)
conf->create_puk_slot = scconf_get_bool(conf_block, "create_puk_slot", conf->create_puk_slot);
conf->zero_ckaid_for_ca_certs = scconf_get_bool(conf_block, "zero_ckaid_for_ca_certs", conf->zero_ckaid_for_ca_certs);
sc_debug(ctx, SC_LOG_DEBUG_NORMAL, "PKCS#11 options: plug_and_play=%d max_virtual_slots=%d slots_per_card=%d "
sc_log(ctx, "PKCS#11 options: plug_and_play=%d max_virtual_slots=%d slots_per_card=%d "
"hide_empty_tokens=%d lock_login=%d pin_unblock_style=%d zero_ckaid_for_ca_certs=%d",
conf->plug_and_play, conf->max_virtual_slots, conf->slots_per_card,
conf->hide_empty_tokens, conf->lock_login, conf->pin_unblock_style,

View File

@ -282,7 +282,7 @@ static CK_RV sc_pkcs11_openssl_md_final(sc_pkcs11_operation_t *op,
EVP_MD_CTX *md_ctx = DIGEST_CTX(op);
if (*pulDigestLen < (unsigned) EVP_MD_CTX_size(md_ctx)) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Provided buffer too small: %ul < %d",
sc_log(context, "Provided buffer too small: %ul < %d",
*pulDigestLen, EVP_MD_CTX_size(md_ctx));
*pulDigestLen = EVP_MD_CTX_size(md_ctx);
return CKR_BUFFER_TOO_SMALL;
@ -429,7 +429,7 @@ CK_RV sc_pkcs11_verify_data(const unsigned char *pubkey, int pubkey_len,
else if (res == 0)
return CKR_SIGNATURE_INVALID;
else {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "EVP_VerifyFinal() returned %d\n", res);
sc_log(context, "EVP_VerifyFinal() returned %d\n", res);
return CKR_GENERAL_ERROR;
}
}
@ -465,7 +465,7 @@ CK_RV sc_pkcs11_verify_data(const unsigned char *pubkey, int pubkey_len,
RSA_free(rsa);
if(rsa_outlen <= 0) {
free(rsa_out);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "RSA_public_decrypt() returned %d\n", rsa_outlen);
sc_log(context, "RSA_public_decrypt() returned %d\n", rsa_outlen);
return CKR_GENERAL_ERROR;
}

View File

@ -208,7 +208,7 @@ CK_RV C_Initialize(CK_VOID_PTR pInitArgs)
#endif
if (context != NULL) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_Initialize(): Cryptoki already initialized\n");
sc_log(context, "C_Initialize(): Cryptoki already initialized\n");
return CKR_CRYPTOKI_ALREADY_INITIALIZED;
}
@ -256,7 +256,7 @@ CK_RV C_Initialize(CK_VOID_PTR pInitArgs)
out:
if (context != NULL)
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_Initialize() = %s", lookup_enum ( RV_T, rv ));
sc_log(context, "C_Initialize() = %s", lookup_enum ( RV_T, rv ));
if (rv != CKR_OK) {
if (context != NULL) {
@ -287,7 +287,7 @@ CK_RV C_Finalize(CK_VOID_PTR pReserved)
if (rv != CKR_OK)
return rv;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_Finalize()");
sc_log(context, "C_Finalize()");
/* cancel pending calls */
in_finalize = 1;
@ -326,7 +326,7 @@ CK_RV C_GetInfo(CK_INFO_PTR pInfo)
if (rv != CKR_OK)
return rv;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_GetInfo()");
sc_log(context, "C_GetInfo()");
memset(pInfo, 0, sizeof(CK_INFO));
pInfo->cryptokiVersion.major = 2;
@ -371,7 +371,7 @@ CK_RV C_GetSlotList(CK_BBOOL tokenPresent, /* only slots with token prese
return rv;
}
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_GetSlotList(token=%d, %s)", tokenPresent,
sc_log(context, "C_GetSlotList(token=%d, %s)", tokenPresent,
(pSlotList==NULL_PTR && sc_pkcs11_conf.plug_and_play)? "plug-n-play":"refresh");
/* Slot list can only change in v2.20 */
@ -408,14 +408,14 @@ CK_RV C_GetSlotList(CK_BBOOL tokenPresent, /* only slots with token prese
}
if (pSlotList == NULL_PTR) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "was only a size inquiry (%d)\n", numMatches);
sc_log(context, "was only a size inquiry (%d)\n", numMatches);
*pulCount = numMatches;
rv = CKR_OK;
goto out;
}
if (*pulCount < numMatches) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "buffer was too small (needed %d)\n", numMatches);
sc_log(context, "buffer was too small (needed %d)\n", numMatches);
*pulCount = numMatches;
rv = CKR_BUFFER_TOO_SMALL;
goto out;
@ -425,7 +425,7 @@ CK_RV C_GetSlotList(CK_BBOOL tokenPresent, /* only slots with token prese
*pulCount = numMatches;
rv = CKR_OK;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "returned %d slots\n", numMatches);
sc_log(context, "returned %d slots\n", numMatches);
out:
if (found != NULL) {
@ -476,7 +476,7 @@ CK_RV C_GetSlotInfo(CK_SLOT_ID slotID, CK_SLOT_INFO_PTR pInfo)
if (rv != CKR_OK)
return rv;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_GetSlotInfo(0x%lx)", slotID);
sc_log(context, "C_GetSlotInfo(0x%lx)", slotID);
rv = slot_get_slot(slotID, &slot);
if (rv == CKR_OK){
@ -498,7 +498,7 @@ CK_RV C_GetSlotInfo(CK_SLOT_ID slotID, CK_SLOT_INFO_PTR pInfo)
if (rv == CKR_OK)
memcpy(pInfo, &slot->slot_info, sizeof(CK_SLOT_INFO));
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_GetSlotInfo(0x%lx) = %s", slotID, lookup_enum ( RV_T, rv ));
sc_log(context, "C_GetSlotInfo(0x%lx) = %s", slotID, lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
}
@ -604,7 +604,7 @@ CK_RV C_WaitForSlotEvent(CK_FLAGS flags, /* blocking/nonblocking flag */
if (pReserved != NULL_PTR)
return CKR_ARGUMENTS_BAD;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_WaitForSlotEvent(block=%d)", !(flags & CKF_DONT_BLOCK));
sc_log(context, "C_WaitForSlotEvent(block=%d)", !(flags & CKF_DONT_BLOCK));
/* Not all pcsc-lite versions implement consistently used functions as they are */
/* FIXME: add proper checking into build to check correct pcsc-lite version for SCardStatusChange/SCardCancel */
if (!(flags & CKF_DONT_BLOCK))
@ -625,7 +625,7 @@ CK_RV C_WaitForSlotEvent(CK_FLAGS flags, /* blocking/nonblocking flag */
goto out;
again:
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_WaitForSlotEvent() reader_states:%p", reader_states);
sc_log(context, "C_WaitForSlotEvent() reader_states:%p", reader_states);
sc_pkcs11_unlock();
r = sc_wait_for_event(context, mask, &found, &events, -1, &reader_states);
if (sc_pkcs11_conf.plug_and_play && events & SC_EVENT_READER_ATTACHED) {
@ -648,7 +648,7 @@ again:
return rv;
if (r != SC_SUCCESS) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "sc_wait_for_event() returned %d\n", r);
sc_log(context, "sc_wait_for_event() returned %d\n", r);
rv = sc_to_cryptoki_error(r, "C_WaitForSlotEvent");
goto out;
}
@ -665,11 +665,11 @@ out:
/* Free allocated readers states holder */
if (reader_states) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "free reader states");
sc_log(context, "free reader states");
sc_wait_for_event(context, 0, NULL, NULL, -1, &reader_states);
}
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_WaitForSlotEvent() = %s, event in 0x%lx", lookup_enum (RV_T, rv), *pSlot);
sc_log(context, "C_WaitForSlotEvent() = %s, event in 0x%lx", lookup_enum (RV_T, rv), *pSlot);
sc_pkcs11_unlock();
return rv;
}

View File

@ -56,7 +56,7 @@ static void sc_find_release(sc_pkcs11_operation_t *operation)
struct sc_pkcs11_find_operation *fop =
(struct sc_pkcs11_find_operation *)operation;
sc_debug(context, SC_LOG_DEBUG_NORMAL,"freeing %d handles used %d at %p",
sc_log(context,"freeing %d handles used %d at %p",
fop->allocated_handles, fop->num_handles, fop->handles);
if (fop->handles) {
free(fop->handles);
@ -96,7 +96,7 @@ CK_RV C_CreateObject(CK_SESSION_HANDLE hSession, /* the session's handle */
rv = sc_pkcs11_lock();
if (rv != CKR_OK)
return rv;
SC_FUNC_CALLED(context, SC_LOG_DEBUG_VERBOSE);
LOG_FUNC_CALLED(context);
dump_template(SC_LOG_DEBUG_NORMAL, "C_CreateObject()", pTemplate, ulCount);
@ -120,7 +120,7 @@ CK_RV C_CreateObject(CK_SESSION_HANDLE hSession, /* the session's handle */
pTemplate, ulCount, phObject);
out: sc_pkcs11_unlock();
SC_FUNC_RETURN(context, SC_LOG_DEBUG_VERBOSE, rv);
LOG_FUNC_RETURN(context, rv);
}
CK_RV C_CopyObject(CK_SESSION_HANDLE hSession, /* the session's handle */
@ -143,7 +143,7 @@ CK_RV C_DestroyObject(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv != CKR_OK)
return rv;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_DestroyObject(hSession=0x%lx, hObject=0x%lx)", hSession, hObject);
sc_log(context, "C_DestroyObject(hSession=0x%lx, hObject=0x%lx)", hSession, hObject);
rv = get_object_from_session(hSession, hObject, &session, &object);
if (rv != CKR_OK)
@ -231,7 +231,7 @@ CK_RV C_GetAttributeValue(CK_SESSION_HANDLE hSession, /* the session's handle */
}
}
out: sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_GetAttributeValue(hSession=0x%lx, hObject=0x%lx) = %s",
out: sc_log(context, "C_GetAttributeValue(hSession=0x%lx, hObject=0x%lx) = %s",
hSession, hObject, lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
@ -304,7 +304,7 @@ CK_RV C_FindObjectsInit(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv != CKR_OK)
goto out;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_FindObjectsInit(slot = %d)\n", session->slot->id);
sc_log(context, "C_FindObjectsInit(slot = %d)\n", session->slot->id);
dump_template(SC_LOG_DEBUG_NORMAL, "C_FindObjectsInit()", pTemplate, ulCount);
rv = session_start_operation(session, SC_PKCS11_OPERATION_FIND,
@ -326,15 +326,14 @@ CK_RV C_FindObjectsInit(CK_SESSION_HANDLE hSession, /* the session's handle */
/* For each object in token do */
for (i=0; i<list_size(&slot->objects); i++) {
object = (struct sc_pkcs11_object *)list_get_at(&slot->objects, i);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Object with handle 0x%lx", object->handle);
sc_log(context, "Object with handle 0x%lx", object->handle);
/* User not logged in and private object? */
if (hide_private) {
if (object->ops->get_attribute(session, object, &private_attribute) != CKR_OK)
continue;
if (is_private) {
sc_debug(context, SC_LOG_DEBUG_NORMAL,
"Object %d/%d: Private object and not logged in.\n",
sc_log(context, "Object %d/%d: Private object and not logged in.",
slot->id, object->handle);
continue;
}
@ -345,26 +344,24 @@ CK_RV C_FindObjectsInit(CK_SESSION_HANDLE hSession, /* the session's handle */
for (j = 0; j < ulCount; j++) {
rv = object->ops->cmp_attribute(session, object, &pTemplate[j]);
if (rv == 0) {
sc_debug(context, SC_LOG_DEBUG_NORMAL,
"Object %d/%d: Attribute 0x%x does NOT match.\n",
sc_log(context, "Object %d/%d: Attribute 0x%x does NOT match.",
slot->id, object->handle, pTemplate[j].type);
match = 0;
break;
}
if (context->debug >= 4) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Object %d/%d: Attribute 0x%x matches.\n",
sc_log(context, "Object %d/%d: Attribute 0x%x matches.",
slot->id, object->handle, pTemplate[j].type);
}
}
if (match) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Object %d/%d matches\n", slot->id, object->handle);
sc_log(context, "Object %d/%d matches\n", slot->id, object->handle);
/* Realloc handles - remove restriction on only 32 matching objects -dee */
if (operation->num_handles >= operation->allocated_handles) {
operation->allocated_handles += SC_PKCS11_FIND_INC_HANDLES;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "realloc for %d handles",
operation->allocated_handles);
sc_log(context, "realloc for %d handles", operation->allocated_handles);
operation->handles = realloc(operation->handles,
sizeof(CK_OBJECT_HANDLE) * operation->allocated_handles);
if (operation->handles == NULL) {
@ -377,7 +374,7 @@ CK_RV C_FindObjectsInit(CK_SESSION_HANDLE hSession, /* the session's handle */
}
rv = CKR_OK;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "%d matching objects\n", operation->num_handles);
sc_log(context, "%d matching objects\n", operation->num_handles);
out: sc_pkcs11_unlock();
return rv;
@ -464,12 +461,12 @@ CK_RV C_DigestInit(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv != CKR_OK)
return rv;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_DigestInit(hSession=0x%lx)", hSession);
sc_log(context, "C_DigestInit(hSession=0x%lx)", hSession);
rv = get_session(hSession, &session);
if (rv == CKR_OK)
rv = sc_pkcs11_md_init(session, pMechanism);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_DigestInit() = %s", lookup_enum ( RV_T, rv ));
sc_log(context, "C_DigestInit() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
}
@ -487,7 +484,7 @@ CK_RV C_Digest(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv != CKR_OK)
return rv;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_Digest(hSession=0x%lx)", hSession);
sc_log(context, "C_Digest(hSession=0x%lx)", hSession);
rv = get_session(hSession, &session);
if (rv != CKR_OK)
goto out;
@ -496,7 +493,7 @@ CK_RV C_Digest(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv == CKR_OK)
rv = sc_pkcs11_md_final(session, pDigest, pulDigestLen);
out: sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_Digest() = %s", lookup_enum ( RV_T, rv ));
out: sc_log(context, "C_Digest() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
}
@ -516,7 +513,7 @@ CK_RV C_DigestUpdate(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv == CKR_OK)
rv = sc_pkcs11_md_update(session, pPart, ulPartLen);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_DigestUpdate() == %s", lookup_enum ( RV_T, rv ));
sc_log(context, "C_DigestUpdate() == %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
}
@ -542,7 +539,7 @@ CK_RV C_DigestFinal(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv == CKR_OK)
rv = sc_pkcs11_md_final(session, pDigest, pulDigestLen);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_DigestFinal() = %s", lookup_enum ( RV_T, rv ));
sc_log(context, "C_DigestFinal() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
}
@ -591,7 +588,7 @@ CK_RV C_SignInit(CK_SESSION_HANDLE hSession, /* the session's handle */
rv = sc_pkcs11_sign_init(session, pMechanism, object, key_type);
out: sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_SignInit() = %s", lookup_enum ( RV_T, rv ));
out: sc_log(context, "C_SignInit() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
}
@ -632,7 +629,7 @@ CK_RV C_Sign(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv == CKR_OK)
rv = sc_pkcs11_sign_final(session, pSignature, pulSignatureLen);
out: sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_Sign() = %s", lookup_enum ( RV_T, rv ));
out: sc_log(context, "C_Sign() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
}
@ -652,7 +649,7 @@ CK_RV C_SignUpdate(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv == CKR_OK)
rv = sc_pkcs11_sign_update(session, pPart, ulPartLen);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_SignUpdate() = %s", lookup_enum ( RV_T, rv ));
sc_log(context, "C_SignUpdate() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
}
@ -688,7 +685,7 @@ CK_RV C_SignFinal(CK_SESSION_HANDLE hSession, /* the session's handle */
rv = sc_pkcs11_sign_final(session, pSignature, pulSignatureLen);
}
out: sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_SignFinal() = %s", lookup_enum ( RV_T, rv ));
out: sc_log(context, "C_SignFinal() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
}
@ -740,11 +737,11 @@ CK_RV C_SignRecoverInit(CK_SESSION_HANDLE hSession, /* the session's handle */
/* XXX: need to tell the signature algorithm that we want
* to recover the signature */
sc_debug(context, SC_LOG_DEBUG_NORMAL, "SignRecover operation initialized\n");
sc_log(context, "SignRecover operation initialized\n");
rv = sc_pkcs11_sign_init(session, pMechanism, object, key_type);
out: sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_SignRecoverInit() = %sn", lookup_enum ( RV_T, rv ));
out: sc_log(context, "C_SignRecoverInit() = %sn", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
}
@ -834,7 +831,7 @@ CK_RV C_DecryptInit(CK_SESSION_HANDLE hSession, /* the session's handle */
rv = sc_pkcs11_decr_init(session, pMechanism, object, key_type);
out: sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_DecryptInit() = %s", lookup_enum ( RV_T, rv ));
out: sc_log(context, "C_DecryptInit() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
}
@ -857,7 +854,7 @@ CK_RV C_Decrypt(CK_SESSION_HANDLE hSession, /* the session's handle */
rv = sc_pkcs11_decr(session, pEncryptedData, ulEncryptedDataLen,
pData, pulDataLen);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_Decrypt() = %s", lookup_enum ( RV_T, rv ));
sc_log(context, "C_Decrypt() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
}
@ -1094,7 +1091,7 @@ CK_RV C_VerifyInit(CK_SESSION_HANDLE hSession, /* the session's handle */
rv = sc_pkcs11_verif_init(session, pMechanism, object, key_type);
out: sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_VerifyInit() = %s", lookup_enum ( RV_T, rv ));
out: sc_log(context, "C_VerifyInit() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
#endif
@ -1124,7 +1121,7 @@ CK_RV C_Verify(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv == CKR_OK)
rv = sc_pkcs11_verif_final(session, pSignature, ulSignatureLen);
out: sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_Verify() = %s", lookup_enum ( RV_T, rv ));
out: sc_log(context, "C_Verify() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
#endif
@ -1148,7 +1145,7 @@ CK_RV C_VerifyUpdate(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv == CKR_OK)
rv = sc_pkcs11_verif_update(session, pPart, ulPartLen);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_VerifyUpdate() = %s", lookup_enum ( RV_T, rv ));
sc_log(context, "C_VerifyUpdate() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
#endif
@ -1172,7 +1169,7 @@ CK_RV C_VerifyFinal(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv == CKR_OK)
rv = sc_pkcs11_verif_final(session, pSignature, ulSignatureLen);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_VerifyFinal() = %s", lookup_enum ( RV_T, rv ));
sc_log(context, "C_VerifyFinal() = %s", lookup_enum ( RV_T, rv ));
sc_pkcs11_unlock();
return rv;
#endif

View File

@ -54,7 +54,7 @@ CK_RV C_OpenSession(CK_SLOT_ID slotID, /* the slot's ID */
if (rv != CKR_OK)
return rv;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_OpenSession(0x%lx)", slotID);
sc_log(context, "C_OpenSession(0x%lx)", slotID);
rv = slot_get_token(slotID, &slot);
if (rv != CKR_OK)
@ -80,10 +80,10 @@ CK_RV C_OpenSession(CK_SLOT_ID slotID, /* the slot's ID */
session->handle = (CK_SESSION_HANDLE) session; /* cast a pointer to long */
list_append(&sessions, session);
*phSession = session->handle;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_OpenSession handle: 0x%lx", session->handle);
sc_log(context, "C_OpenSession handle: 0x%lx", session->handle);
out:
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_OpenSession() = %s", lookup_enum(RV_T, rv));
sc_log(context, "C_OpenSession() = %s", lookup_enum(RV_T, rv));
sc_pkcs11_unlock();
return rv;
}
@ -95,7 +95,7 @@ static CK_RV sc_pkcs11_close_session(CK_SESSION_HANDLE hSession)
struct sc_pkcs11_slot *slot;
struct sc_pkcs11_session *session;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "real C_CloseSession(0x%lx)", hSession);
sc_log(context, "real C_CloseSession(0x%lx)", hSession);
session = list_seek(&sessions, &hSession);
if (!session)
@ -111,7 +111,7 @@ static CK_RV sc_pkcs11_close_session(CK_SESSION_HANDLE hSession)
}
if (list_delete(&sessions, session) != 0)
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Could not delete session from list!");
sc_log(context, "Could not delete session from list!");
free(session);
return CKR_OK;
}
@ -123,7 +123,7 @@ CK_RV sc_pkcs11_close_all_sessions(CK_SLOT_ID slotID)
CK_RV rv = CKR_OK;
struct sc_pkcs11_session *session;
unsigned int i;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "real C_CloseAllSessions(0x%lx) %d", slotID, list_size(&sessions));
sc_log(context, "real C_CloseAllSessions(0x%lx) %d", slotID, list_size(&sessions));
for (i = 0; i < list_size(&sessions); i++) {
session = list_get_at(&sessions, i);
if (session->slot->id == slotID)
@ -141,7 +141,7 @@ CK_RV C_CloseSession(CK_SESSION_HANDLE hSession)
if (rv != CKR_OK)
return rv;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_CloseSession(0x%lx)\n", hSession);
sc_log(context, "C_CloseSession(0x%lx)\n", hSession);
rv = sc_pkcs11_close_session(hSession);
@ -158,7 +158,7 @@ CK_RV C_CloseAllSessions(CK_SLOT_ID slotID)
if (rv != CKR_OK)
return rv;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_CloseAllSessions(0x%lx)\n", slotID);
sc_log(context, "C_CloseAllSessions(0x%lx)\n", slotID);
rv = slot_get_token(slotID, &slot);
if (rv != CKR_OK)
@ -184,7 +184,7 @@ CK_RV C_GetSessionInfo(CK_SESSION_HANDLE hSession, /* the session's handle */
if (rv != CKR_OK)
return rv;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_GetSessionInfo(0x%lx)", hSession);
sc_log(context, "C_GetSessionInfo(0x%lx)", hSession);
session = list_seek(&sessions, &hSession);
if (!session) {
@ -192,7 +192,7 @@ CK_RV C_GetSessionInfo(CK_SESSION_HANDLE hSession, /* the session's handle */
goto out;
}
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_GetSessionInfo(slot 0x%lx).", session->slot->id);
sc_log(context, "C_GetSessionInfo(slot 0x%lx).", session->slot->id);
pInfo->slotID = session->slot->id;
pInfo->flags = session->flags;
pInfo->ulDeviceError = 0;
@ -209,7 +209,7 @@ CK_RV C_GetSessionInfo(CK_SESSION_HANDLE hSession, /* the session's handle */
}
out:
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_GetSessionInfo(0x%lx) = %s", hSession, lookup_enum(RV_T, rv));
sc_log(context, "C_GetSessionInfo(0x%lx) = %s", hSession, lookup_enum(RV_T, rv));
sc_pkcs11_unlock();
return rv;
}
@ -256,7 +256,7 @@ CK_RV C_Login(CK_SESSION_HANDLE hSession, /* the session's handle */
goto out;
}
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_Login(0x%lx, %d)", hSession, userType);
sc_log(context, "C_Login(0x%lx, %d)", hSession, userType);
slot = session->slot;
@ -306,7 +306,7 @@ CK_RV C_Logout(CK_SESSION_HANDLE hSession)
goto out;
}
sc_debug(context, SC_LOG_DEBUG_NORMAL, "C_Logout(0x%lx)", hSession);
sc_log(context, "C_Logout(0x%lx)", hSession);
slot = session->slot;
@ -379,7 +379,7 @@ CK_RV C_SetPIN(CK_SESSION_HANDLE hSession,
}
slot = session->slot;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Changing PIN (session 0x%lx; login user %d)\n", hSession,
sc_log(context, "Changing PIN (session 0x%lx; login user %d)\n", hSession,
slot->login_user);
if (!(session->flags & CKF_RW_SESSION)) {

View File

@ -87,7 +87,7 @@ CK_RV create_slot(sc_reader_t *reader)
list_append(&virtual_slots, slot);
slot->login_user = -1;
slot->id = (CK_SLOT_ID) list_locate(&virtual_slots, slot);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Creating slot with id 0x%lx", slot->id);
sc_log(context, "Creating slot with id 0x%lx", slot->id);
list_init(&slot->objects);
list_attributes_seeker(&slot->objects, object_list_seeker);
@ -115,7 +115,7 @@ CK_RV initialize_reader(sc_reader_t *reader)
list = scconf_find_list(conf_block, "ignored_readers");
while (list != NULL) {
if (strstr(reader->name, list->data) != NULL) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Ignoring reader \'%s\' because of \'%s\'\n", reader->name, list->data);
sc_log(context, "Ignoring reader \'%s\' because of \'%s\'\n", reader->name, list->data);
return CKR_OK;
}
list = list->next;
@ -141,7 +141,7 @@ CK_RV card_removed(sc_reader_t * reader)
unsigned int i;
struct sc_pkcs11_card *card = NULL;
/* Mark all slots as "token not present" */
sc_debug(context, SC_LOG_DEBUG_NORMAL, "%s: card removed", reader->name);
sc_log(context, "%s: card removed", reader->name);
for (i=0; i < list_size(&virtual_slots); i++) {
@ -185,22 +185,22 @@ CK_RV card_detect(sc_reader_t *reader)
rv = CKR_OK;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "%s: Detecting smart card\n", reader->name);
sc_log(context, "%s: Detecting smart card\n", reader->name);
/* Check if someone inserted a card */
again:rc = sc_detect_card_presence(reader);
if (rc < 0) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "%s: failed, %s\n", reader->name, sc_strerror(rc));
sc_log(context, "%s: failed, %s\n", reader->name, sc_strerror(rc));
return sc_to_cryptoki_error(rc, NULL);
}
if (rc == 0) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "%s: card absent\n", reader->name);
sc_log(context, "%s: card absent\n", reader->name);
card_removed(reader); /* Release all resources */
return CKR_TOKEN_NOT_PRESENT;
}
/* If the card was changed, disconnect the current one */
if (rc & SC_READER_CARD_CHANGED) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "%s: Card changed\n", reader->name);
sc_log(context, "%s: Card changed\n", reader->name);
/* The following should never happen - but if it
* does we'll be stuck in an endless loop.
* So better be fussy.
@ -221,7 +221,7 @@ CK_RV card_detect(sc_reader_t *reader)
/* Detect the card if it's not known already */
if (p11card == NULL) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "%s: First seen the card ", reader->name);
sc_log(context, "%s: First seen the card ", reader->name);
p11card = (struct sc_pkcs11_card *)calloc(1, sizeof(struct sc_pkcs11_card));
if (!p11card)
return CKR_HOST_MEMORY;
@ -229,7 +229,7 @@ CK_RV card_detect(sc_reader_t *reader)
}
if (p11card->card == NULL) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "%s: Connecting ... ", reader->name);
sc_log(context, "%s: Connecting ... ", reader->name);
rc = sc_connect_card(reader, &p11card->card);
if (rc != SC_SUCCESS)
return sc_to_cryptoki_error(rc, NULL);
@ -237,7 +237,7 @@ CK_RV card_detect(sc_reader_t *reader)
/* Detect the framework */
if (p11card->framework == NULL) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "%s: Detecting Framework\n", reader->name);
sc_log(context, "%s: Detecting Framework\n", reader->name);
for (i = 0; frameworks[i]; i++) {
if (frameworks[i]->bind == NULL)
@ -251,14 +251,14 @@ CK_RV card_detect(sc_reader_t *reader)
return CKR_TOKEN_NOT_RECOGNIZED;
/* Initialize framework */
sc_debug(context, SC_LOG_DEBUG_NORMAL, "%s: Detected framework %d. Creating tokens.\n", reader->name, i);
sc_log(context, "%s: Detected framework %d. Creating tokens.\n", reader->name, i);
rv = frameworks[i]->create_tokens(p11card);
if (rv != CKR_OK)
return rv;
p11card->framework = frameworks[i];
}
sc_debug(context, SC_LOG_DEBUG_NORMAL, "%s: Detection ended\n", reader->name);
sc_log(context, "%s: Detection ended\n", reader->name);
return CKR_OK;
}
@ -289,7 +289,7 @@ CK_RV slot_allocate(struct sc_pkcs11_slot ** slot, struct sc_pkcs11_card * card)
}
if (!tmp_slot || (i == list_size(&virtual_slots)))
return CKR_FUNCTION_FAILED;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "Allocated slot 0x%lx for card in reader %s", tmp_slot->id,
sc_log(context, "Allocated slot 0x%lx for card in reader %s", tmp_slot->id,
card->reader->name);
tmp_slot->card = card;
tmp_slot->events = SC_EVENT_CARD_INSERTED;
@ -325,7 +325,7 @@ CK_RV slot_get_token(CK_SLOT_ID id, struct sc_pkcs11_slot ** slot)
}
if (!((*slot)->slot_info.flags & CKF_TOKEN_PRESENT)) {
sc_debug(context, SC_LOG_DEBUG_NORMAL, "card detected, but slot not presenting token");
sc_log(context, "card detected, but slot not presenting token");
return CKR_TOKEN_NOT_PRESENT;
}
return CKR_OK;
@ -337,7 +337,7 @@ CK_RV slot_token_removed(CK_SLOT_ID id)
struct sc_pkcs11_slot *slot;
struct sc_pkcs11_object *object;
sc_debug(context, SC_LOG_DEBUG_NORMAL, "slot_token_removed(0x%lx)", id);
sc_log(context, "slot_token_removed(0x%lx)", id);
rv = slot_get_slot(id, &slot);
if (rv != CKR_OK)
return rv;
@ -374,24 +374,24 @@ CK_RV slot_token_removed(CK_SLOT_ID id)
CK_RV slot_find_changed(CK_SLOT_ID_PTR idp, int mask)
{
unsigned int i;
SC_FUNC_CALLED(context, SC_LOG_DEBUG_NORMAL);
LOG_FUNC_CALLED(context);
card_detect_all();
for (i=0; i<list_size(&virtual_slots); i++) {
sc_pkcs11_slot_t *slot = (sc_pkcs11_slot_t *) list_get_at(&virtual_slots, i);
sc_debug(context, SC_LOG_DEBUG_NORMAL, "slot 0x%lx token: %d events: 0x%02X",slot->id, (slot->slot_info.flags & CKF_TOKEN_PRESENT), slot->events);
sc_log(context, "slot 0x%lx token: %d events: 0x%02X",slot->id, (slot->slot_info.flags & CKF_TOKEN_PRESENT), slot->events);
if ((slot->events & SC_EVENT_CARD_INSERTED)
&& !(slot->slot_info.flags & CKF_TOKEN_PRESENT)) {
/* If a token has not been initialized, clear the inserted event */
slot->events &= ~SC_EVENT_CARD_INSERTED;
}
sc_debug(context, SC_LOG_DEBUG_NORMAL, "mask: 0x%02X events: 0x%02X result: %d", mask, slot->events, (slot->events & mask));
sc_log(context, "mask: 0x%02X events: 0x%02X result: %d", mask, slot->events, (slot->events & mask));
if (slot->events & mask) {
slot->events &= ~mask;
*idp = slot->id;
SC_FUNC_RETURN(context, SC_LOG_DEBUG_VERBOSE, CKR_OK);
LOG_FUNC_RETURN(context, CKR_OK);
}
}
SC_FUNC_RETURN(context, SC_LOG_DEBUG_VERBOSE, CKR_NO_EVENT);
LOG_FUNC_RETURN(context, CKR_NO_EVENT);
}