From eb21c41e533d218589580ca999dbb6d9eb4c6371 Mon Sep 17 00:00:00 2001
From: Viktor Tarasov <viktor.tarasov@gmail.com>
Date: Sun, 24 Jul 2016 20:38:53 +0200
Subject: [PATCH] piv: coding style, use short log calls

---
 src/libopensc/card-piv.c | 610 +++++++++++++++++++--------------------
 1 file changed, 304 insertions(+), 306 deletions(-)

diff --git a/src/libopensc/card-piv.c b/src/libopensc/card-piv.c
index 78080375..e0b3c9cc 100644
--- a/src/libopensc/card-piv.c
+++ b/src/libopensc/card-piv.c
@@ -394,19 +394,21 @@ static struct sc_card_driver piv_drv = {
 	NULL, 0, NULL
 };
 
-static int piv_find_obj_by_containerid(sc_card_t *card, const u8 * str)
+
+static int
+piv_find_obj_by_containerid(sc_card_t *card, const u8 * str)
 {
 	int i;
 
-	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "str=0x%02X%02X\n", str[0], str[1]);
+	LOG_FUNC_CALLED(card->ctx);
+	sc_log(card->ctx, "str=0x%02X%02X\n", str[0], str[1]);
 
 	for (i = 0; piv_objects[i].enumtag < PIV_OBJ_LAST_ENUM; i++) {
-		if ( str[0] == piv_objects[i].containerid[0]
-			&& str[1] == piv_objects[i].containerid[1])
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_VERBOSE, i);
+		if ( str[0] == piv_objects[i].containerid[0] && str[1] == piv_objects[i].containerid[1])
+			LOG_FUNC_RETURN(card->ctx, i);
 	}
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_VERBOSE, -1);
+
+	LOG_FUNC_RETURN(card->ctx, -1);
 }
 
 /*
@@ -414,7 +416,8 @@ static int piv_find_obj_by_containerid(sc_card_t *card, const u8 * str)
  * otherwise, store tag and length at **ptr, and increment
  */
 
-static size_t put_tag_and_len(unsigned int tag, size_t len, u8 **ptr)
+static size_t
+put_tag_and_len(unsigned int tag, size_t len, u8 **ptr)
 {
 	int i;
 	u8 *p;
@@ -480,8 +483,8 @@ static int piv_general_io(sc_card_t *card, int ins, int p1, int p2,
 
 	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
 
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "%02x %02x %02x %d : %d %d\n",
-		 ins, p1, p2, sendbuflen , card->max_send_size, card->max_recv_size);
+	sc_log(card->ctx, "%02x %02x %02x %d : %d %d",
+		 ins, p1, p2, sendbuflen, card->max_send_size, card->max_recv_size);
 
 	rbuf = rbufinitbuf;
 	rbuflen = sizeof(rbufinitbuf);
@@ -494,7 +497,7 @@ static int piv_general_io(sc_card_t *card, int ins, int p1, int p2,
 
 	r = sc_lock(card);
 	if (r != SC_SUCCESS)
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+		LOG_FUNC_RETURN(card->ctx, r);
 
 	sc_format_apdu(card, &apdu,
 			recvbuf ? SC_APDU_CASE_4_SHORT: SC_APDU_CASE_3_SHORT,
@@ -520,26 +523,25 @@ static int piv_general_io(sc_card_t *card, int ins, int p1, int p2,
 		 apdu.resplen = 0;
 	}
 
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"calling sc_transmit_apdu flags=%x le=%d, resplen=%d, resp=%p",
+	sc_log(card->ctx, "calling sc_transmit_apdu flags=%x le=%d, resplen=%d, resp=%p",
 		apdu.flags, apdu.le, apdu.resplen, apdu.resp);
 
 	/* with new adpu.c and chaining, this actually reads the whole object */
 	r = sc_transmit_apdu(card, &apdu);
 
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"DEE r=%d apdu.resplen=%d sw1=%02x sw2=%02x",
+	sc_log(card->ctx, "DEE r=%d apdu.resplen=%d sw1=%02x sw2=%02x",
 			r, apdu.resplen, apdu.sw1, apdu.sw2);
 	if (r < 0) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"Transmit failed");
+		sc_log(card->ctx, "Transmit failed");
 		goto err;
 	}
 
-	if (!(find_len && apdu.sw1 == 0x61))  {
+	if (!(find_len && apdu.sw1 == 0x61))
 	    r = sc_check_sw(card, apdu.sw1, apdu.sw2);
-	}
 
 /* TODO: - DEE look later at tag vs size read too */
 	if (r < 0) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "Card returned error ");
+		sc_log(card->ctx, "Card returned error ");
 		goto err;
 	}
 
@@ -557,9 +559,9 @@ static int piv_general_io(sc_card_t *card, int ins, int p1, int p2,
 		 * the buffer is bigger, so it will not produce "ASN1.tag too long!" */
 
 		body = rbuf;
-		if (sc_asn1_read_tag(&body, 0xffff, &cla_out, &tag_out, &bodylen) !=  SC_SUCCESS) 		{
+		if (sc_asn1_read_tag(&body, 0xffff, &cla_out, &tag_out, &bodylen) !=  SC_SUCCESS)  {
 			/* only early beta cards had this problem */
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "***** received buffer tag MISSING ");
+			sc_log(card->ctx, "***** received buffer tag MISSING ");
 			body = rbuf;
 			/* some readers/cards might return 6c 00 */
 			if (apdu.sw1 == 0x61  || apdu.sw2 == 0x6c )
@@ -573,7 +575,7 @@ static int piv_general_io(sc_card_t *card, int ins, int p1, int p2,
 		/* if using internal buffer, alloc new one */
 		if (rbuf == rbufinitbuf) {
 			*recvbuf = malloc(rbuflen);
-				sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "DEE got buffer %p len %d",*recvbuf,  rbuflen);
+				sc_log(card->ctx, "DEE got buffer %p len %d",*recvbuf,  rbuflen);
 			if (*recvbuf == NULL) {
 				r = SC_ERROR_OUT_OF_MEMORY;
 				goto err;
@@ -590,7 +592,7 @@ static int piv_general_io(sc_card_t *card, int ins, int p1, int p2,
 
 err:
 	sc_unlock(card);
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 /* Add the PIV-II operations */
@@ -640,7 +642,7 @@ static int piv_generate_key(sc_card_t *card,
 			keydata->ecparam_len = 0;
 			break;
 		default:
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_INVALID_ARGUMENTS);
+			LOG_FUNC_RETURN(card->ctx, SC_ERROR_INVALID_ARGUMENTS);
 	}
 
 	p = tagbuf;
@@ -665,7 +667,7 @@ static int piv_generate_key(sc_card_t *card,
 
 		r = sc_asn1_read_tag(&cp, rbuflen, &cla_out, &tag_out, &in_len);
 		if (r != SC_SUCCESS) {
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"Tag buffer not found");
+			sc_log(card->ctx, "Tag buffer not found");
 			goto err;
 		}
 
@@ -674,39 +676,39 @@ static int piv_generate_key(sc_card_t *card,
 			tag = sc_asn1_find_tag(card->ctx, cp, in_len, 0x82, &taglen);
 			if (tag != NULL && taglen <= 4) {
 				keydata->exponent = 0;
-				for (i = 0; i < taglen;i++) {
+				for (i = 0; i < taglen;i++)
 					keydata->exponent = (keydata->exponent<<8) + tag[i];
-				}
 			}
-			tag = sc_asn1_find_tag(card->ctx, cp, in_len, 0x81, &taglen);
 
+			tag = sc_asn1_find_tag(card->ctx, cp, in_len, 0x81, &taglen);
 			if (tag != NULL && taglen > 0) {
 				keydata->pubkey = malloc(taglen);
 				if (keydata->pubkey == NULL)
-					SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OUT_OF_MEMORY);
+					LOG_FUNC_RETURN(card->ctx, SC_ERROR_OUT_OF_MEMORY);
 				keydata->pubkey_len = taglen;
 				memcpy (keydata->pubkey, tag, taglen);
 			}
-		} else { /* must be EC */
+		}
+		else { /* must be EC */
 			tag = sc_asn1_find_tag(card->ctx, cp, in_len, 0x86, &taglen);
 			if (tag != NULL && taglen > 0) {
 				keydata->ecpoint = malloc(taglen);
 				if (keydata->ecpoint == NULL)
-					SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OUT_OF_MEMORY);
+					LOG_FUNC_RETURN(card->ctx, SC_ERROR_OUT_OF_MEMORY);
 				keydata->ecpoint_len = taglen;
 				memcpy (keydata->ecpoint, tag, taglen);
-            }
+			}
 		}
 
 		/* TODO: -DEE Could add key to cache so could use engine to generate key,
-	 	 * and sign req in single operation */
+		 * and sign req in single operation */
 		r = 0;
 	}
 
 err:
 	if (rbuf)
 		free(rbuf);
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 
@@ -715,9 +717,8 @@ static int piv_select_aid(sc_card_t* card, u8* aid, size_t aidlen, u8* response,
 	sc_apdu_t apdu;
 	int r;
 
-	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,
-		"Got args: aid=%x, aidlen=%d, response=%x, responselen=%d\n",
+	LOG_FUNC_CALLED(card->ctx);
+	sc_log(card->ctx, "Got args: aid=%x, aidlen=%d, response=%x, responselen=%d",
 		aid, aidlen, response, responselen ? *responselen : 0);
 
 	sc_format_apdu(card, &apdu,
@@ -732,8 +733,9 @@ static int piv_select_aid(sc_card_t* card, u8* aid, size_t aidlen, u8* response,
 	r = sc_transmit_apdu(card, &apdu);
 	if (responselen)
 		*responselen = apdu.resplen;
-	SC_TEST_RET(card->ctx, SC_LOG_DEBUG_NORMAL, r, "PIV select failed");
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_VERBOSE,  sc_check_sw(card, apdu.sw1, apdu.sw2));
+	LOG_TEST_RET(card->ctx, r, "PIV select failed");
+
+	LOG_FUNC_RETURN(card->ctx, sc_check_sw(card, apdu.sw1, apdu.sw2));
 }
 
 /* find the PIV AID on the card. If card->type already filled in,
@@ -764,7 +766,7 @@ static int piv_find_aid(sc_card_t * card, sc_file_t *aid_file)
 		if (tag != NULL) {
 			pix = sc_asn1_find_tag(card->ctx, tag, taglen, 0x4F, &pixlen);
 			if (pix != NULL ) {
-				sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"found PIX");
+				sc_log(card->ctx, "found PIX");
 
 				/* early cards returned full AID, rather then just the pix */
 				for (i = 0; piv_aids[i].len_long != 0; i++) {
@@ -776,9 +778,9 @@ static int piv_find_aid(sc_card_t * card, sc_file_t *aid_file)
 						if (card->type > SC_CARD_TYPE_PIV_II_BASE &&
 							card->type < SC_CARD_TYPE_PIV_II_BASE+1000 &&
 							card->type == piv_aids[i].enumtag) {
-							SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, i);
+							LOG_FUNC_RETURN(card->ctx, i);
 						} else {
-							SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, i);
+							LOG_FUNC_RETURN(card->ctx, i);
 						}
 					}
 				}
@@ -805,15 +807,12 @@ static int piv_find_aid(sc_card_t * card, sc_file_t *aid_file)
 		apdu.le = 256;
 
 		r = sc_transmit_apdu(card, &apdu);
-		SC_TEST_RET(card->ctx, SC_LOG_DEBUG_NORMAL, r, "APDU transmit failed");
+		LOG_TEST_RET(card->ctx, r, "APDU transmit failed");
 
 		r = sc_check_sw(card, apdu.sw1, apdu.sw2);
-
-
 		if (r)  {
-			if (card->type != 0 && card->type == piv_aids[i].enumtag) {
-				SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, i);
-			}
+			if (card->type != 0 && card->type == piv_aids[i].enumtag)
+				LOG_FUNC_RETURN(card->ctx, i);
 			continue;
 		}
 
@@ -827,10 +826,10 @@ static int piv_find_aid(sc_card_t * card, sc_file_t *aid_file)
 
 		card->ops->process_fci(card, aid_file, apdu.resp+2, apdu.resp[1]);
 
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, i);
+		LOG_FUNC_RETURN(card->ctx, i);
 	}
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_NO_CARD_SUPPORT);
+	LOG_FUNC_RETURN(card->ctx, SC_ERROR_NO_CARD_SUPPORT);
 }
 
 /*
@@ -857,23 +856,21 @@ static int piv_read_obj_from_file(sc_card_t * card, char * filename,
 	*buf_len = 0;
 	f = open(filename, O_RDONLY);
 	if (f < 0) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,
-			"Unable to load PIV off card file: \"%s\"\n",filename);
+		sc_log(card->ctx, "Unable to load PIV off card file: \"%s\"",filename);
 			r = SC_ERROR_FILE_NOT_FOUND;
 			goto err;
 	}
 	len = read(f, tagbuf, sizeof(tagbuf)); /* get tag and length */
 	if (len < 2 || len > sizeof(tagbuf)) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"Problem with \"%s\"\n",filename);
+		sc_log(card->ctx, "Problem with \"%s\"",filename);
 		r =  SC_ERROR_DATA_OBJECT_NOT_FOUND;
 		goto err;
 	}
 	body = tagbuf;
-	if (sc_asn1_read_tag(&body, 0xfffff, &cla_out,
-			&tag_out, &bodylen) != SC_SUCCESS) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "DER problem\n");
-			r = SC_ERROR_INVALID_ASN1_OBJECT;
-			goto err;
+	if (sc_asn1_read_tag(&body, 0xfffff, &cla_out, &tag_out, &bodylen) != SC_SUCCESS) {
+		sc_log(card->ctx, "DER problem");
+		r = SC_ERROR_INVALID_ASN1_OBJECT;
+		goto err;
 	}
 	rbuflen = body - tagbuf + bodylen;
 	*buf = malloc(rbuflen);
@@ -896,12 +893,12 @@ static int piv_read_obj_from_file(sc_card_t * card, char * filename,
 err:
 	if (f >= 0)
 		close(f);
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 /* the tag is the PIV_OBJ_*  */
-static int piv_get_data(sc_card_t * card, int enumtag,
-			u8 **buf, size_t *buf_len)
+static int
+piv_get_data(sc_card_t * card, int enumtag, u8 **buf, size_t *buf_len)
 {
 	u8 *p;
 	int r = 0;
@@ -909,7 +906,7 @@ static int piv_get_data(sc_card_t * card, int enumtag,
 	size_t tag_len;
 
 	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "#%d \n", enumtag);
+	sc_log(card->ctx, "#%d", enumtag);
 
 	/* assert(enumtag >= 0 && enumtag < PIV_OBJ_LAST_ENUM); */
 
@@ -928,15 +925,14 @@ static int piv_get_data(sc_card_t * card, int enumtag,
 		unsigned int cla_out, tag_out;
 		const u8 *body;
 
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"get len of #%d", enumtag);
+		sc_log(card->ctx, "get len of #%d", enumtag);
 		rbuf = rbufinitbuf;
 		rbuflen = sizeof(rbufinitbuf);
-		r = piv_general_io(card, 0xCB, 0x3F, 0xFF, tagbuf,  p - tagbuf,
-				&rbuf, &rbuflen);
+		r = piv_general_io(card, 0xCB, 0x3F, 0xFF, tagbuf,  p - tagbuf, &rbuf, &rbuflen);
 		if (r > 0) {
 			body = rbuf;
 			if (sc_asn1_read_tag(&body, 0xffff, &cla_out, &tag_out, &bodylen) !=  SC_SUCCESS) {
-				sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "***** received buffer tag MISSING ");
+				sc_log(card->ctx, "***** received buffer tag MISSING ");
 				r = SC_ERROR_FILE_NOT_FOUND;
 				goto err;
 			}
@@ -948,7 +944,8 @@ static int piv_get_data(sc_card_t * card, int enumtag,
 			goto err;
 		}
 	}
-sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"buffer for #%d *buf=0x%p len=%d", enumtag, *buf, *buf_len);
+
+	sc_log(card->ctx, "buffer for #%d *buf=0x%p len=%d", enumtag, *buf, *buf_len);
 	if (*buf == NULL && *buf_len > 0) {
 		*buf = malloc(*buf_len);
 		if (*buf == NULL ) {
@@ -957,16 +954,15 @@ sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"buffer for #%d *buf=0x%p len=%d", enumt
 		}
 	}
 
-	r = piv_general_io(card, 0xCB, 0x3F, 0xFF, tagbuf,  p - tagbuf,
-		buf, buf_len);
+	r = piv_general_io(card, 0xCB, 0x3F, 0xFF, tagbuf,  p - tagbuf, buf, buf_len);
 
 err:
-
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
-static int piv_get_cached_data(sc_card_t * card, int enumtag,
-			u8 **buf, size_t *buf_len)
+
+static int
+piv_get_cached_data(sc_card_t * card, int enumtag, u8 **buf, size_t *buf_len)
 {
 
 	piv_private_data_t * priv = PIV_DATA(card);
@@ -975,14 +971,14 @@ static int piv_get_cached_data(sc_card_t * card, int enumtag,
 	size_t rbuflen;
 
 	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "#%d", enumtag);
+	sc_log(card->ctx, "#%d", enumtag);
 
 	assert(enumtag >= 0 && enumtag < PIV_OBJ_LAST_ENUM);
 
 	/* see if we have it cached */
 	if (priv->obj_cache[enumtag].flags & PIV_OBJ_CACHE_VALID) {
 
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"found #%d %p:%d %p:%d",
+		sc_log(card->ctx, "found #%d %p:%d %p:%d",
 				enumtag,
 				priv->obj_cache[enumtag].obj_data,
 				priv->obj_cache[enumtag].obj_len,
@@ -992,8 +988,7 @@ static int piv_get_cached_data(sc_card_t * card, int enumtag,
 
 		if (priv->obj_cache[enumtag].obj_len == 0) {
 			r = SC_ERROR_FILE_NOT_FOUND;
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"#%d found but len=0",
-					enumtag);
+			sc_log(card->ctx, "#%d found but len=0", enumtag);
 			goto err;
 		}
 		*buf = priv->obj_cache[enumtag].obj_data;
@@ -1006,16 +1001,16 @@ static int piv_get_cached_data(sc_card_t * card, int enumtag,
 	 * If we know it can not be on the card  i.e. History object
 	 * has been read, and we know what other certs may or
 	 * may not be on the card. We can avoid extra overhead
- 	 */
+	 */
 
 	if (priv->obj_cache[enumtag].flags & PIV_OBJ_CACHE_NOT_PRESENT) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"no_obj #%d", enumtag);
+		sc_log(card->ctx, "no_obj #%d", enumtag);
 		r = SC_ERROR_FILE_NOT_FOUND;
 		goto err;
 	}
 
 	/* Not cached, try to get it, piv_get_data will allocate a buf */
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"get #%d",  enumtag);
+	sc_log(card->ctx, "get #%d",  enumtag);
 	rbuflen = 1;
 	r = piv_get_data(card, enumtag, &rbuf, &rbuflen);
 	if (r > 0) {
@@ -1025,7 +1020,7 @@ static int piv_get_cached_data(sc_card_t * card, int enumtag,
 		*buf = rbuf;
 		*buf_len = r;
 
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"added #%d  %p:%d %p:%d",
+		sc_log(card->ctx, "added #%d  %p:%d %p:%d",
 				enumtag,
 				priv->obj_cache[enumtag].obj_data,
 				priv->obj_cache[enumtag].obj_len,
@@ -1042,11 +1037,12 @@ static int piv_get_cached_data(sc_card_t * card, int enumtag,
 ok:
 
 err:
-
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
-static int piv_cache_internal_data(sc_card_t *card, int enumtag)
+
+static int
+piv_cache_internal_data(sc_card_t *card, int enumtag)
 {
 	piv_private_data_t * priv = PIV_DATA(card);
 	const u8* tag;
@@ -1057,10 +1053,10 @@ static int piv_cache_internal_data(sc_card_t *card, int enumtag)
 
 	/* if already cached */
 	if (priv->obj_cache[enumtag].internal_obj_data && priv->obj_cache[enumtag].internal_obj_len) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"#%d found internal %p:%d", enumtag,
+		sc_log(card->ctx, "#%d found internal %p:%d", enumtag,
 				priv->obj_cache[enumtag].internal_obj_data,
 				priv->obj_cache[enumtag].internal_obj_len);
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, 0);
+		LOG_FUNC_RETURN(card->ctx, SC_SUCCESS);
 	}
 
 	body = sc_asn1_find_tag(card->ctx,
@@ -1069,7 +1065,7 @@ static int piv_cache_internal_data(sc_card_t *card, int enumtag)
 			0x53, &bodylen);
 
 	if (body == NULL)
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OBJECT_NOT_VALID);
+		LOG_FUNC_RETURN(card->ctx, SC_ERROR_OBJECT_NOT_VALID);
 
 	/* get the certificate out */
 	 if (piv_objects[enumtag].flags & PIV_OBJECT_TYPE_CERT) {
@@ -1077,32 +1073,34 @@ static int piv_cache_internal_data(sc_card_t *card, int enumtag)
 		tag = sc_asn1_find_tag(card->ctx, body, bodylen, 0x71, &taglen);
 		/* 800-72-1 not clear if this is 80 or 01 Sent comment to NIST for 800-72-2 */
 		/* 800-73-3 says it is 01, keep dual test so old cards still work */
-		if (tag && (((*tag) & 0x80) || ((*tag) & 0x01))) {
+		if (tag && (((*tag) & 0x80) || ((*tag) & 0x01)))
 			compressed = 1;
-		}
+
 		tag = sc_asn1_find_tag(card->ctx, body, bodylen, 0x70, &taglen);
 		if (tag == NULL)
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OBJECT_NOT_VALID);
+			LOG_FUNC_RETURN(card->ctx, SC_ERROR_OBJECT_NOT_VALID);
 
 		if (taglen == 0)
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_FILE_NOT_FOUND);
+			LOG_FUNC_RETURN(card->ctx, SC_ERROR_FILE_NOT_FOUND);
 
-			if(compressed) {
+		if(compressed) {
 #ifdef ENABLE_ZLIB
 			size_t len;
 			u8* newBuf = NULL;
-			if(SC_SUCCESS != sc_decompress_alloc(&newBuf, &len, tag, taglen, COMPRESSION_AUTO)) {
-				SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OBJECT_NOT_VALID);
-			}
+
+			if(SC_SUCCESS != sc_decompress_alloc(&newBuf, &len, tag, taglen, COMPRESSION_AUTO))
+				LOG_FUNC_RETURN(card->ctx, SC_ERROR_OBJECT_NOT_VALID);
+
 			priv->obj_cache[enumtag].internal_obj_data = newBuf;
 			priv->obj_cache[enumtag].internal_obj_len = len;
 #else
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"PIV compression not supported, no zlib");
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_NOT_SUPPORTED);
+			sc_log(card->ctx, "PIV compression not supported, no zlib");
+			LOG_FUNC_RETURN(card->ctx, SC_ERROR_NOT_SUPPORTED);
 #endif
-		} else {
+		}
+		else {
 			if (!(priv->obj_cache[enumtag].internal_obj_data = malloc(taglen)))
-				SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OUT_OF_MEMORY);
+				LOG_FUNC_RETURN(card->ctx, SC_ERROR_OUT_OF_MEMORY);
 
 			memcpy(priv->obj_cache[enumtag].internal_obj_data, tag, taglen);
 			priv->obj_cache[enumtag].internal_obj_len = taglen;
@@ -1110,29 +1108,30 @@ static int piv_cache_internal_data(sc_card_t *card, int enumtag)
 
 	/* convert pub key to internal */
 /* TODO: -DEE need to fix ...  would only be used if we cache the pub key, but we don't today */
-	} else if (piv_objects[enumtag].flags & PIV_OBJECT_TYPE_PUBKEY) {
-
+	}
+	else if (piv_objects[enumtag].flags & PIV_OBJECT_TYPE_PUBKEY) {
 		tag = sc_asn1_find_tag(card->ctx, body, bodylen, *body, &taglen);
 		if (tag == NULL)
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OBJECT_NOT_VALID);
+			LOG_FUNC_RETURN(card->ctx, SC_ERROR_OBJECT_NOT_VALID);
 
 		if (taglen == 0)
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_FILE_NOT_FOUND);
+			LOG_FUNC_RETURN(card->ctx, SC_ERROR_FILE_NOT_FOUND);
 
 		if (!(priv->obj_cache[enumtag].internal_obj_data = malloc(taglen)))
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OUT_OF_MEMORY);
+			LOG_FUNC_RETURN(card->ctx, SC_ERROR_OUT_OF_MEMORY);
 
 		memcpy(priv->obj_cache[enumtag].internal_obj_data, tag, taglen);
 		priv->obj_cache[enumtag].internal_obj_len = taglen;
-	} else {
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_INTERNAL);
+	}
+	else {
+		LOG_FUNC_RETURN(card->ctx, SC_ERROR_INTERNAL);
 	}
 
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"added #%d internal %p:%d", enumtag,
+	sc_log(card->ctx, "added #%d internal %p:%d", enumtag,
 		priv->obj_cache[enumtag].internal_obj_data,
 		priv->obj_cache[enumtag].internal_obj_len);
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, 0);
+	LOG_FUNC_RETURN(card->ctx, SC_SUCCESS);
 }
 
 
@@ -1141,8 +1140,8 @@ static int piv_cache_internal_data(sc_card_t *card, int enumtag)
  * select file will have saved the object type for us
  * as well as set that we want the cert from the object.
  */
-static int piv_read_binary(sc_card_t *card, unsigned int idx,
-		unsigned char *buf, size_t count, unsigned long flags)
+static int
+piv_read_binary(sc_card_t *card, unsigned int idx, unsigned char *buf, size_t count, unsigned long flags)
 {
 	piv_private_data_t * priv = PIV_DATA(card);
 	int enumtag;
@@ -1154,7 +1153,7 @@ static int piv_read_binary(sc_card_t *card, unsigned int idx,
 
 	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
 	if (priv->selected_obj < 0)
-		 SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_INTERNAL);
+		 LOG_FUNC_RETURN(card->ctx, SC_ERROR_INTERNAL);
 	enumtag = piv_objects[priv->selected_obj].enumtag;
 
 	if (priv->rwb_state == -1) {
@@ -1167,17 +1166,17 @@ static int piv_read_binary(sc_card_t *card, unsigned int idx,
 				r = SC_ERROR_FILE_NOT_FOUND;
 				goto err;
 			}
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "DEE rbuf=%p,rbuflen=%d,",rbuf, rbuflen);
+			sc_log(card->ctx, "DEE rbuf=%p,rbuflen=%d,",rbuf, rbuflen);
 			body = sc_asn1_find_tag(card->ctx, rbuf, rbuflen, rbuf[0], &bodylen);
 			if (body == NULL) {
 				/* if missing, assume its the body */
 				/* DEE bug in the beta card */
-				sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL," ***** tag 0x53 MISSING \n");
+				sc_log(card->ctx, " ***** tag 0x53 MISSING");
 				r = SC_ERROR_INVALID_DATA;
 				goto err;
 			}
 			if (bodylen > body - rbuf + rbuflen) {
-				sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL," ***** tag length > then data: %d>%d+%d",
+				sc_log(card->ctx, " ***** tag length > then data: %d>%d+%d",
 					bodylen , body - rbuf, rbuflen);
 				r = SC_ERROR_INVALID_DATA;
 				goto err;
@@ -1211,8 +1210,9 @@ static int piv_read_binary(sc_card_t *card, unsigned int idx,
 		memcpy(buf, rbuf + idx, count);
 		r = count;
 	}
+
 err:
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 
@@ -1221,8 +1221,8 @@ err:
  * The buf should have the 0x53 tag+len+tags and data
  */
 
-static int piv_put_data(sc_card_t *card, int tag,
-		const u8 *buf, size_t buf_len)
+static int
+piv_put_data(sc_card_t *card, int tag, const u8 *buf, size_t buf_len)
 {
 	int r;
 	u8 * sbuf;
@@ -1235,7 +1235,7 @@ static int piv_put_data(sc_card_t *card, int tag,
 	tag_len = piv_objects[tag].tag_len;
 	sbuflen = put_tag_and_len(0x5c, tag_len, NULL) + buf_len;
 	if (!(sbuf = malloc(sbuflen)))
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OUT_OF_MEMORY);
+		LOG_FUNC_RETURN(card->ctx, SC_ERROR_OUT_OF_MEMORY);
 
 	p = sbuf;
 	put_tag_and_len(0x5c, tag_len, &p);
@@ -1245,18 +1245,17 @@ static int piv_put_data(sc_card_t *card, int tag,
 	memcpy(p, buf, buf_len);
 	p += buf_len;
 
-	r = piv_general_io(card, 0xDB, 0x3F, 0xFF,
-			sbuf, p - sbuf, NULL, NULL);
+	r = piv_general_io(card, 0xDB, 0x3F, 0xFF, sbuf, p - sbuf, NULL, NULL);
 
 	if (sbuf)
 		free(sbuf);
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 
-static int piv_write_certificate(sc_card_t *card,
-		const u8* buf, size_t count,
-		unsigned long flags) {
+static int
+piv_write_certificate(sc_card_t *card, const u8* buf, size_t count, unsigned long flags)
+{
 	piv_private_data_t * priv = PIV_DATA(card);
 	int enumtag;
 	int r = SC_SUCCESS;
@@ -1265,7 +1264,7 @@ static int piv_write_certificate(sc_card_t *card,
 	size_t sbuflen;
 	size_t taglen;
 
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"DEE cert len=%d",count);
+	sc_log(card->ctx, "DEE cert len=%d",count);
 	taglen = put_tag_and_len(0x70, count, NULL)
 		+ put_tag_and_len(0x71, 1, NULL)
 		+ put_tag_and_len(0xFE, 0, NULL);
@@ -1274,7 +1273,7 @@ static int piv_write_certificate(sc_card_t *card,
 
 	sbuf = malloc(sbuflen);
 	if (sbuf == NULL)
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OUT_OF_MEMORY);
+		LOG_FUNC_RETURN(card->ctx, SC_ERROR_OUT_OF_MEMORY);
 	p = sbuf;
 	put_tag_and_len(0x53, taglen, &p);
 
@@ -1286,14 +1285,14 @@ static int piv_write_certificate(sc_card_t *card,
 	*p++ = (flags)? 0x01:0x00; /* certinfo, i.e. gziped? */
 	put_tag_and_len(0xFE,0,&p); /* LRC tag */
 
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"DEE buf %p len %d %d", sbuf, p -sbuf, sbuflen);
+	sc_log(card->ctx, "DEE buf %p len %d %d", sbuf, p -sbuf, sbuflen);
 
 	enumtag = piv_objects[priv->selected_obj].enumtag;
 	r = piv_put_data(card, enumtag, sbuf, sbuflen);
 	if (sbuf)
 		free(sbuf);
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 /*
@@ -1323,15 +1322,15 @@ static int piv_write_binary(sc_card_t *card, unsigned int idx,
 	int r;
 	int enumtag;
 
-	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
+	LOG_FUNC_CALLED(card->ctx);
 
 	if (priv->selected_obj < 0)
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_INTERNAL);
+		LOG_FUNC_RETURN(card->ctx, SC_ERROR_INTERNAL);
 
 	enumtag = piv_objects[priv->selected_obj].enumtag;
 
 	if (priv->rwb_state == 1)  /* trying to write at end */
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, 0);
+		LOG_FUNC_RETURN(card->ctx, SC_SUCCESS);
 
 	if (priv->rwb_state == -1) {
 
@@ -1351,11 +1350,11 @@ static int piv_write_binary(sc_card_t *card, unsigned int idx,
 		}
 
 		if (idx != 0)
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_NO_CARD_SUPPORT);
+			LOG_FUNC_RETURN(card->ctx, SC_ERROR_NO_CARD_SUPPORT);
 
 		priv->w_buf_len = flags>>8;
 		if (priv->w_buf_len == 0)
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_INTERNAL);
+			LOG_FUNC_RETURN(card->ctx, SC_ERROR_INTERNAL);
 
 		priv->w_buf = malloc(priv->w_buf_len);
 		priv-> rwb_state = 0;
@@ -1363,26 +1362,25 @@ static int piv_write_binary(sc_card_t *card, unsigned int idx,
 
 	/* on each pass make sure we have w_buf */
 	if (priv->w_buf == NULL)
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OUT_OF_MEMORY);
+		LOG_FUNC_RETURN(card->ctx, SC_ERROR_OUT_OF_MEMORY);
 
 	if (idx + count > priv->w_buf_len)
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OBJECT_NOT_VALID);
+		LOG_FUNC_RETURN(card->ctx, SC_ERROR_OBJECT_NOT_VALID);
 
 	memcpy(priv->w_buf + idx, buf, count); /* copy one chunk */
 
 	/* if this was not the last chunk, return to get rest */
 	if (idx + count < priv->w_buf_len)
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, count);
+		LOG_FUNC_RETURN(card->ctx, count);
 
 	priv-> rwb_state = 1; /* at end of object */
 
 	switch (flags & 0x0f) {
 		case 1:
-			r = piv_write_certificate(card, priv->w_buf, priv->w_buf_len,
-				flags & 0x10);
+			r = piv_write_certificate(card, priv->w_buf, priv->w_buf_len, flags & 0x10);
 			break;
 		case 2: /* pubkey to be added to cache, it should have 0x53 and 0x99 tags. */
-	/* TODO: -DEE this is not fully implemented and not used */
+		/* TODO: -DEE this is not fully implemented and not used */
 			r = priv->w_buf_len;
 			break;
 		default:
@@ -1400,7 +1398,7 @@ static int piv_write_binary(sc_card_t *card, unsigned int idx,
 	}
 	priv->w_buf = NULL;
 	priv->w_buf_len = 0;
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, (r < 0)? r : (int)count);
+	LOG_FUNC_RETURN(card->ctx, (r < 0)? r : (int)count);
 }
 
 /*
@@ -1461,22 +1459,22 @@ static int piv_get_key(sc_card_t *card, unsigned int alg_id, u8 **key, size_t *l
 	keyfilename = (char *)getenv("PIV_EXT_AUTH_KEY");
 
 	if (keyfilename == NULL) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,
-			"Unable to get PIV_EXT_AUTH_KEY=(null) for general_external_authenticate\n");
+		sc_log(card->ctx,
+			"Unable to get PIV_EXT_AUTH_KEY=(null) for general_external_authenticate");
 		r = SC_ERROR_FILE_NOT_FOUND;
 		goto err;
 	}
 
 	r = get_keylen(alg_id, &expected_keylen);
 	if(r) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_VERBOSE, "Invalid cipher selector, none found for:  %02x\n", alg_id);
+		sc_debug(card->ctx, SC_LOG_DEBUG_VERBOSE, "Invalid cipher selector, none found for:  %02x", alg_id);
 		r = SC_ERROR_INVALID_ARGUMENTS;
 		goto err;
 	}
 
 	f = fopen(keyfilename, "rb");
 	if (!f) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL," Unable to load key from file\n");
+		sc_log(card->ctx, " Unable to load key from file\n");
 		r = SC_ERROR_FILE_NOT_FOUND;
 		goto err;
 	}
@@ -1495,21 +1493,21 @@ static int piv_get_key(sc_card_t *card, unsigned int alg_id, u8 **key, size_t *l
 
 	keybuf = malloc(fsize+1); /* if not binary, need null to make it a string */
 	if (!keybuf) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL," Unable to allocate key memory");
+		sc_log(card->ctx, " Unable to allocate key memory");
 		r = SC_ERROR_OUT_OF_MEMORY;
 		goto err;
 	}
 	keybuf[fsize] = 0x00;    /* incase it is text need null */
 
 	if (fread(keybuf, 1, fsize, f) != fsize) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL," Unable to read key\n");
+		sc_log(card->ctx, " Unable to read key\n");
 		r = SC_ERROR_WRONG_LENGTH;
 		goto err;
 	}
 
 	tkey = malloc(expected_keylen);
 	if (!tkey) {
-	    sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL," Unable to allocate key memory");
+	    sc_log(card->ctx, " Unable to allocate key memory");
 	    r = SC_ERROR_OUT_OF_MEMORY;
 	    goto err;
 	}
@@ -1544,7 +1542,7 @@ err:
 		free(tkey);
 	}
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 	return r;
 }
 #endif
@@ -1799,7 +1797,7 @@ static int piv_general_mutual_authenticate(sc_card_t *card,
 	decrypted_reponse_len += tmplen;
 
 	if (decrypted_reponse_len != nonce_len || memcmp(nonce, decrypted_reponse, nonce_len) != 0) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "mutual authentication failed, card returned wrong value %zu:%zu",
+		sc_log(card->ctx, "mutual authentication failed, card returned wrong value %zu:%zu",
 				decrypted_reponse_len, nonce_len);
 		r = SC_ERROR_DECRYPT_FAILED;
 		goto err;
@@ -1824,11 +1822,11 @@ err:
 		free(key);
 
 #else
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"OpenSSL Required");
+	sc_log(card->ctx, "OpenSSL Required");
 	r = SC_ERROR_NOT_SUPPORTED;
 #endif /* ENABLE_OPENSSL */
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 
@@ -2026,14 +2024,16 @@ err:
 	if (output_buf)
 		free(output_buf);
 #else
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"OpenSSL Required");
+	sc_log(card->ctx, "OpenSSL Required");
 	r = SC_ERROR_NOT_SUPPORTED;
 #endif /* ENABLE_OPENSSL */
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
-static int piv_get_serial_nr_from_CHUI(sc_card_t* card, sc_serial_number_t* serial)
+
+static int
+piv_get_serial_nr_from_CHUI(sc_card_t* card, sc_serial_number_t* serial)
 {
 	int r;
 	int i;
@@ -2049,7 +2049,7 @@ static int piv_get_serial_nr_from_CHUI(sc_card_t* card, sc_serial_number_t* seri
 	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
 	if (card->serialnr.len)   {
 		*serial = card->serialnr;
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_SUCCESS);
+		LOG_FUNC_RETURN(card->ctx, SC_SUCCESS);
 	}
 
 	/* ensure we've got the PIV selected, and nothing else is in process */
@@ -2063,7 +2063,7 @@ static int piv_get_serial_nr_from_CHUI(sc_card_t* card, sc_serial_number_t* seri
 	piv_select_aid(card, piv_aids[0].value, piv_aids[0].len_short, temp, &templen);
 
 	r = piv_get_cached_data(card, PIV_OBJ_CHUI, &rbuf, &rbuflen);
-	SC_TEST_RET(card->ctx, SC_LOG_DEBUG_NORMAL, r, "Failure retrieving CHUI");
+	LOG_TEST_RET(card->ctx, r, "Failure retrieving CHUI");
 
 	r = SC_ERROR_INTERNAL;
 	if (rbuflen != 0) {
@@ -2078,7 +2078,7 @@ static int piv_get_serial_nr_from_CHUI(sc_card_t* card, sc_serial_number_t* seri
 					gbits = gbits | guid[i]; /* if all are zero, gbits will be zero */
 				}
 			}
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"fascn=%p,fascnlen=%d,guid=%p,guidlen=%d,gbits=%2.2x\n",
+			sc_log(card->ctx, "fascn=%p,fascnlen=%d,guid=%p,guidlen=%d,gbits=%2.2x",
 					fascn, fascnlen, guid, guidlen, gbits);
 
 			if (fascn && fascnlen == 25) {
@@ -2100,7 +2100,7 @@ static int piv_get_serial_nr_from_CHUI(sc_card_t* card, sc_serial_number_t* seri
 	}
 
 	card->serialnr = *serial;
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 /*
@@ -2124,7 +2124,7 @@ static int piv_is_object_present(sc_card_t *card, u8 *ptr)
 	if (enumtag >= 0 && priv->obj_cache[enumtag].flags & PIV_OBJ_CACHE_NOT_PRESENT)
 		r = 1;
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 /*
@@ -2137,7 +2137,7 @@ static int piv_get_pin_preference(sc_card_t *card, int *ptr)
 	piv_private_data_t * priv = PIV_DATA(card);
 
 	*ptr = priv->pin_preference;
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_SUCCESS);
+	LOG_FUNC_RETURN(card->ctx, SC_SUCCESS);
 }
 
 static int piv_card_ctl(sc_card_t *card, unsigned long cmd, void *ptr)
@@ -2193,11 +2193,11 @@ static int piv_get_challenge(sc_card_t *card, u8 *rnd, size_t len)
 
 	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
 
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"challenge len=%d",len);
+	sc_log(card->ctx, "challenge len=%d",len);
 
 	r = sc_lock(card);
 	if (r != SC_SUCCESS)
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+		LOG_FUNC_RETURN(card->ctx, r);
 
 	p = sbuf;
 	*p++ = 0x7c;
@@ -2211,11 +2211,10 @@ static int piv_get_challenge(sc_card_t *card, u8 *rnd, size_t len)
 		size_t n = len > 8 ? 8 : len;
 
 		/* NIST 800-73-3 says use 9B, previous verisons used 00 */
-		r = piv_general_io(card, 0x87, 0x00, 0x9B, sbuf, p - sbuf,
-				&rbuf, &rbuflen);
- 		if (r < 0) {
+		r = piv_general_io(card, 0x87, 0x00, 0x9B, sbuf, p - sbuf, &rbuf, &rbuflen);
+		if (r < 0) {
 			sc_unlock(card);
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+			LOG_FUNC_RETURN(card->ctx, r);
 		}
 		q = rbuf;
 		if ( (*q++ != 0x7C)
@@ -2224,7 +2223,7 @@ static int piv_get_challenge(sc_card_t *card, u8 *rnd, size_t len)
 			|| (*q++ != rbuflen - 4)) {
 			r =  SC_ERROR_INVALID_DATA;
 			sc_unlock(card);
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+			LOG_FUNC_RETURN(card->ctx, r);
 		}
 		memcpy(rnd, q, n);
 		len -= n;
@@ -2235,20 +2234,19 @@ static int piv_get_challenge(sc_card_t *card, u8 *rnd, size_t len)
 
 	r = sc_unlock(card);
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 
 }
 
-static int piv_set_security_env(sc_card_t *card,
-                    const sc_security_env_t *env,
-                    int se_num)
+static int
+piv_set_security_env(sc_card_t *card, const sc_security_env_t *env, int se_num)
 {
 	piv_private_data_t * priv = PIV_DATA(card);
 	int r = 0;
 
 	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
 
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"flags=%08x op=%d alg=%d algf=%08x algr=%08x kr0=%02x, krfl=%d\n",
+	sc_log(card->ctx, "flags=%08x op=%d alg=%d algf=%08x algr=%08x kr0=%02x, krfl=%d",
 			env->flags, env->operation, env->algorithm, env->algorithm_flags,
 			env->algorithm_ref, env->key_ref[0], env->key_ref_len);
 
@@ -2277,15 +2275,15 @@ static int piv_set_security_env(sc_card_t *card,
 		 r = SC_ERROR_NO_CARD_SUPPORT;
 	priv->key_ref = env->key_ref[0];
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_VERBOSE, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 
 static int piv_restore_security_env(sc_card_t *card, int se_num)
 {
-	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
+	LOG_FUNC_CALLED(card->ctx);
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, 0);
+	LOG_FUNC_RETURN(card->ctx, SC_SUCCESS);
 }
 
 
@@ -2323,7 +2321,7 @@ static int piv_validate_general_authentication(sc_card_t *card,
 
 	/*
 	 * alg_id=06 is a place holder for all RSA keys.
- 	 * Derive the real alg_id based on the size of the
+	 * Derive the real alg_id based on the size of the
 	 * the data, as we are always using raw mode.
 	 * Non RSA keys needs some work in thia area.
 	 */
@@ -2359,12 +2357,13 @@ static int piv_validate_general_authentication(sc_card_t *card,
 	if (rbuf)
 		free(rbuf);
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
-static int piv_compute_signature(sc_card_t *card,
-					const u8 * data, size_t datalen,
-					u8 * out, size_t outlen)
+
+static int
+piv_compute_signature(sc_card_t *card, const u8 * data, size_t datalen,
+		u8 * out, size_t outlen)
 {
 	piv_private_data_t * priv = PIV_DATA(card);
 	int r;
@@ -2390,7 +2389,7 @@ static int piv_compute_signature(sc_card_t *card,
 	if (priv->alg_id == 0x11 || priv->alg_id == 0x14 ) {
 		nLen = (priv->key_size + 7) / 8;
 		if (outlen < 2*nLen) {
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL," output too small for EC signature %d < %d", outlen, 2*nLen);
+			sc_log(card->ctx, " output too small for EC signature %d < %d", outlen, 2*nLen);
 			r = SC_ERROR_INVALID_DATA;
 			goto err;
 		}
@@ -2401,7 +2400,7 @@ static int piv_compute_signature(sc_card_t *card,
 			goto err;
 
 		if ( r >= 0) {
-	 		body = sc_asn1_find_tag(card->ctx, rbuf, rbuflen, 0x30, &bodylen);
+			body = sc_asn1_find_tag(card->ctx, rbuf, rbuflen, 0x30, &bodylen);
 
 			for (i = 0; i<2; i++) {
 				if (body) {
@@ -2438,9 +2437,9 @@ err:
 	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_VERBOSE, r);
 }
 
-static int piv_decipher(sc_card_t *card,
-					 const u8 * data, size_t datalen,
-					 u8 * out, size_t outlen)
+
+static int
+piv_decipher(sc_card_t *card, const u8 * data, size_t datalen, u8 * out, size_t outlen)
 {
 	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
 
@@ -2460,7 +2459,7 @@ static int piv_decipher(sc_card_t *card,
 static int piv_select_file(sc_card_t *card, const sc_path_t *in_path,
 	sc_file_t **file_out)
 {
- 	piv_private_data_t * priv = PIV_DATA(card);
+	piv_private_data_t * priv = PIV_DATA(card);
 	int r;
 	int i;
 	const u8 *path;
@@ -2475,7 +2474,7 @@ static int piv_select_file(sc_card_t *card, const sc_path_t *in_path,
 	pathlen = in_path->len;
 
 	/* only support single EF in current application */
-	/* 
+	/*
 	 * PIV emulates files, and only does so becauses sc_pkcs15_* uses
 	 * select_file and read_binary. The emulation adds path emulated structures
 	 * so piv_select_file will find it.
@@ -2493,7 +2492,7 @@ static int piv_select_file(sc_card_t *card, const sc_path_t *in_path,
 	i = piv_find_obj_by_containerid(card, path);
 
 	if (i < 0)
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_FILE_NOT_FOUND);
+		LOG_FUNC_RETURN(card->ctx, SC_ERROR_FILE_NOT_FOUND);
 
 	/*
 	 * pkcs15 will use a 2 byte path or a 4 byte path
@@ -2513,18 +2512,18 @@ static int piv_select_file(sc_card_t *card, const sc_path_t *in_path,
 		r = piv_get_cached_data(card, i, &rbuf, &rbuflen);
 
 		if (r < 0)
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_FILE_NOT_FOUND);
+			LOG_FUNC_RETURN(card->ctx, SC_ERROR_FILE_NOT_FOUND);
 
 		/* get the cert or the pub key out and into the cache too */
 		if (priv->return_only_cert || piv_objects[i].flags & PIV_OBJECT_TYPE_PUBKEY) {
 			r = piv_cache_internal_data(card, i);
 			if (r < 0)
-				SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+				LOG_FUNC_RETURN(card->ctx, r);
 		}
 
 		file = sc_file_new();
 		if (file == NULL)
-			SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OUT_OF_MEMORY);
+			LOG_FUNC_RETURN(card->ctx, SC_ERROR_OUT_OF_MEMORY);
 
 		file->path = *in_path;
 		/* this could be like the FCI */
@@ -2541,7 +2540,7 @@ static int piv_select_file(sc_card_t *card, const sc_path_t *in_path,
 		*file_out = file;
 	}
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, 0);
+	LOG_FUNC_RETURN(card->ctx, SC_SUCCESS);
 
 }
 
@@ -2571,42 +2570,42 @@ static int piv_process_discovery(sc_card_t *card)
 		goto err;
 	}
 
-sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"Discovery = %p:%d",rbuf, rbuflen);
+	sc_log(card->ctx, "Discovery = %p:%d",rbuf, rbuflen);
 	/* the object is now cached, see what we have */
 	if (rbuflen != 0) {
 		body = rbuf;
 		if ((r = sc_asn1_read_tag(&body, rbuflen, &cla_out, &tag_out,  &bodylen)) != SC_SUCCESS) {
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"DER problem %d\n",r);
+			sc_log(card->ctx, "DER problem %d",r);
 			r = SC_ERROR_INVALID_ASN1_OBJECT;
 			goto err;
 		}
 
-sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"Discovery 0x%2.2x 0x%2.2x %p:%d",
-				cla_out, tag_out, body, bodylen);
-        if ( cla_out+tag_out == 0x7E && body != NULL && bodylen != 0) {
-            aidlen = 0;
-            aid = sc_asn1_find_tag(card->ctx, body, bodylen, 0x4F, &aidlen);
-sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"Discovery aid=%p:%d",aid,aidlen);
-		 	if (aid == NULL || aidlen < piv_aids[0].len_short ||
+	sc_log(card->ctx, "Discovery 0x%2.2x 0x%2.2x %p:%d", cla_out, tag_out, body, bodylen);
+	if ( cla_out+tag_out == 0x7E && body != NULL && bodylen != 0) {
+		aidlen = 0;
+		aid = sc_asn1_find_tag(card->ctx, body, bodylen, 0x4F, &aidlen);
+		sc_log(card->ctx, "Discovery aid=%p:%d",aid,aidlen);
+			if (aid == NULL || aidlen < piv_aids[0].len_short ||
 				memcmp(aid,piv_aids[0].value,piv_aids[0].len_short) != 0) { /*TODO look at long */
-				sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "Discovery object not PIV");
+				sc_log(card->ctx, "Discovery object not PIV");
 				r = SC_SUCCESS; /* not an error could be some other appl */
 				goto err;
 			}
 			pinp = sc_asn1_find_tag(card->ctx, body, bodylen, 0x5F2F, &pinplen);
-sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"Discovery pinp=%p:%d",pinp,pinplen);
+			sc_log(card->ctx, "Discovery pinp=%p:%d",pinp,pinplen);
 			if (pinp && pinplen == 2) {
-sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"Discovery pinp flags=0x%2.2x 0x%2.2x",*pinp, *(pinp+1));
+				sc_log(card->ctx, "Discovery pinp flags=0x%2.2x 0x%2.2x",*pinp, *(pinp+1));
 				r = SC_SUCCESS;
 				if (*pinp == 0x60 && *(pinp+1) == 0x20) { /* use Global pin */
-					sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "Pin Preference - Global");
+					sc_log(card->ctx, "Pin Preference - Global");
 					priv->pin_preference = 0x00;
 				}
 			}
 		}
 	}
-	err:
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+
+err:
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 /*
@@ -2617,8 +2616,8 @@ sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"Discovery pinp flags=0x%2.2x 0x%2.2x",*
  * If the offCardCertURL is not cached by the user, should we wget it here?
  * Its may be out of scope to have OpenSC read the URL.
  */
-
-static int piv_process_history(sc_card_t *card)
+static int
+piv_process_history(sc_card_t *card)
 {
 	piv_private_data_t * priv = PIV_DATA(card);
 	int r;
@@ -2661,54 +2660,54 @@ static int piv_process_history(sc_card_t *card)
 	if (rbuflen != 0) {
 		body = rbuf;
 		if ((r = sc_asn1_read_tag(&body, rbuflen, &cla_out, &tag_out,  &bodylen)) != SC_SUCCESS) {
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"DER problem %d\n",r);
+			sc_log(card->ctx, "DER problem %d",r);
 			r = SC_ERROR_INVALID_ASN1_OBJECT;
 			goto err;
 		}
 
-        if ( cla_out+tag_out == 0x53 && body != NULL && bodylen != 0) {
-            numlen = 0;
-            num = sc_asn1_find_tag(card->ctx, body, bodylen, 0xC1, &numlen);
-            if (num) {
-				if (numlen != 1 ||
-						*num > PIV_OBJ_RETIRED_X509_20-PIV_OBJ_RETIRED_X509_1+1) {
-					r = SC_ERROR_INTERNAL; /* TODO some other error */
-                	goto err;
-				}
-                priv->keysWithOnCardCerts = *num;
-			}
-
-            numlen = 0;
-            num = sc_asn1_find_tag(card->ctx, body, bodylen, 0xC2, &numlen);
-            if (num) {
-				if (numlen != 1 ||
-						*num > PIV_OBJ_RETIRED_X509_20-PIV_OBJ_RETIRED_X509_1+1) {
+		if ( cla_out+tag_out == 0x53 && body != NULL && bodylen != 0) {
+			numlen = 0;
+			num = sc_asn1_find_tag(card->ctx, body, bodylen, 0xC1, &numlen);
+			if (num) {
+				if (numlen != 1 || *num > PIV_OBJ_RETIRED_X509_20-PIV_OBJ_RETIRED_X509_1+1) {
 					r = SC_ERROR_INTERNAL; /* TODO some other error */
 					goto err;
 				}
-                priv->keysWithOffCardCerts = *num;
+
+				priv->keysWithOnCardCerts = *num;
 			}
 
-            url = sc_asn1_find_tag(card->ctx, body, bodylen, 0xF3, &urllen);
-            if (url) {
-                priv->offCardCertURL = calloc(1,urllen+1);
-                if (priv->offCardCertURL == NULL)
-                    SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OUT_OF_MEMORY);
+			numlen = 0;
+			num = sc_asn1_find_tag(card->ctx, body, bodylen, 0xC2, &numlen);
+			if (num) {
+				if (numlen != 1 || *num > PIV_OBJ_RETIRED_X509_20-PIV_OBJ_RETIRED_X509_1+1) {
+					r = SC_ERROR_INTERNAL; /* TODO some other error */
+					goto err;
+				}
+
+				priv->keysWithOffCardCerts = *num;
+			}
+
+			url = sc_asn1_find_tag(card->ctx, body, bodylen, 0xF3, &urllen);
+			if (url) {
+				priv->offCardCertURL = calloc(1,urllen+1);
+				if (priv->offCardCertURL == NULL)
+					LOG_FUNC_RETURN(card->ctx, SC_ERROR_OUT_OF_MEMORY);
 				memcpy(priv->offCardCertURL, url, urllen);
 			}
-		} else {
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"Problem with Histroy object\n");
+		}
+		else {
+			sc_log(card->ctx, "Problem with Histroy object\n");
 			goto err;
 		}
 	}
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "History on=%d off=%d URL=%s\n",
-				priv->keysWithOnCardCerts, priv->keysWithOffCardCerts,
-				priv->offCardCertURL ? priv->offCardCertURL:"NONE");
+	sc_log(card->ctx, "History on=%d off=%d URL=%s",
+			priv->keysWithOnCardCerts, priv->keysWithOffCardCerts,
+			priv->offCardCertURL ? priv->offCardCertURL:"NONE");
 
 	/* now mark what objects are on the card */
-	for (i=0; i<priv->keysWithOnCardCerts; i++) {
+	for (i=0; i<priv->keysWithOnCardCerts; i++)
 		priv->obj_cache[PIV_OBJ_RETIRED_X509_1+i].flags &= ~PIV_OBJ_CACHE_NOT_PRESENT;
-	}
 
 	/*
 	 * If user has gotten copy of the file from the offCardCertsURL,
@@ -2726,20 +2725,19 @@ static int piv_process_history(sc_card_t *card)
 		char filename[PATH_MAX];
 
 		if (strncmp("http://", priv->offCardCertURL, 7)) {
-				r = SC_ERROR_INVALID_DATA;
-				goto err;
+			r = SC_ERROR_INVALID_DATA;
+			goto err;
 		}
 		/* find the last /  so we have the filename part */
 		fp = strrchr(priv->offCardCertURL + 7,'/');
 		if (fp == NULL) {
-				r = SC_ERROR_INVALID_DATA;
-				goto err;
+			r = SC_ERROR_INVALID_DATA;
+			goto err;
 		}
 		fp++;
 
 		/* Use the same directory as used for other OpenSC cached items */
-		r = sc_get_cache_dir(card->ctx, filename,
-				sizeof(filename) - strlen(fp) - 2);
+		r = sc_get_cache_dir(card->ctx, filename, sizeof(filename) - strlen(fp) - 2);
 		if (r != SC_SUCCESS)
 			goto err;
 #ifdef _WIN32
@@ -2764,7 +2762,7 @@ static int piv_process_history(sc_card_t *card)
 		if (sc_asn1_read_tag(&body, ocfhflen, &cla_out,
 				&tag_out, &bodylen) != SC_SUCCESS ||
 				cla_out+tag_out != 0x30) {
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "DER problem\n");
+			sc_log(card->ctx, "DER problem");
 			r = SC_ERROR_INVALID_ASN1_OBJECT;
 			goto err;
 		}
@@ -2774,15 +2772,14 @@ static int piv_process_history(sc_card_t *card)
 			if (sc_asn1_read_tag(&seq, bodylen, &cla_out,
 					&tag_out, &seqlen) != SC_SUCCESS ||
 					cla_out+tag_out != 0x30) {
-				sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"DER problem\n");
+				sc_log(card->ctx, "DER problem");
 				r = SC_ERROR_INVALID_ASN1_OBJECT;
 				goto err;
 			}
-			keyref = sc_asn1_find_tag(card->ctx,
-				seq, seqlen, 0x04, &keyreflen);
+			keyref = sc_asn1_find_tag(card->ctx, seq, seqlen, 0x04, &keyreflen);
 			if (!keyref || keyreflen != 1 ||
 					(*keyref < 0x82 && *keyref > 0x95)) {
-				sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"DER problem\n");
+				sc_log(card->ctx, "DER problem");
 				r = SC_ERROR_INVALID_ASN1_OBJECT;
 				goto err;
 			}
@@ -2818,12 +2815,11 @@ static int piv_process_history(sc_card_t *card)
 			priv->obj_cache[enumtag].flags &= ~PIV_OBJ_CACHE_NOT_PRESENT;
 
 			r = piv_cache_internal_data(card, enumtag);
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "got internal r=%d\n",r);
+			sc_log(card->ctx, "got internal r=%d",r);
 
 			certobj = NULL;
 
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,
-				"Added from off card file #%d %p:%d 0x%02X \n",
+			sc_log(card->ctx, "Added from off card file #%d %p:%d 0x%02X",
 				enumtag,
 				priv->obj_cache[enumtag].obj_data,
 				priv->obj_cache[enumtag].obj_len, *keyref);
@@ -2835,13 +2831,14 @@ static int piv_process_history(sc_card_t *card)
 err:
 	if (ocfhfbuf)
 		free(ocfhfbuf);
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 
-static int piv_finish(sc_card_t *card)
+static int
+piv_finish(sc_card_t *card)
 {
- 	piv_private_data_t * priv = PIV_DATA(card);
+	piv_private_data_t * priv = PIV_DATA(card);
 	int i;
 
 	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
@@ -2853,7 +2850,7 @@ static int piv_finish(sc_card_t *card)
 		if (priv->offCardCertURL)
 			free(priv->offCardCertURL);
 		for (i = 0; i < PIV_OBJ_LAST_ENUM - 1; i++) {
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"DEE freeing #%d, 0x%02x %p:%d %p:%d", i,
+			sc_log(card->ctx, "DEE freeing #%d, 0x%02x %p:%d %p:%d", i,
 				priv->obj_cache[i].flags,
 				priv->obj_cache[i].obj_data, priv->obj_cache[i].obj_len,
 				priv->obj_cache[i].internal_obj_data, priv->obj_cache[i].internal_obj_len);
@@ -2909,12 +2906,12 @@ static int piv_match_card(sc_card_t *card)
 			if (card->reader->atr_info.hist_bytes_len == 8 &&
 					!(memcmp(card->reader->atr_info.hist_bytes, "Yubikey4", 8))) {
 				type = SC_CARD_TYPE_PIV_II_YUBIKEY4;
-			} else
-			if (card->reader->atr_info.hist_bytes_len >= 7 &&
+			}
+			else if (card->reader->atr_info.hist_bytes_len >= 7 &&
 					!(memcmp(card->reader->atr_info.hist_bytes, "Yubikey", 7))) {
 				type = SC_CARD_TYPE_PIV_II_NEO;
-			} else 
-			if (card->reader->atr_info.hist_bytes[0] == 0x80u) { /* compact TLV */
+			}
+			else if (card->reader->atr_info.hist_bytes[0] == 0x80u) { /* compact TLV */
 				p = card->reader->atr_info.hist_bytes;
 				pe = p + card->reader->atr_info.hist_bytes_len;
 				p++; /* skip 0x80u byte */
@@ -2948,7 +2945,7 @@ static int piv_match_card(sc_card_t *card)
 	priv = calloc(1, sizeof(piv_private_data_t));
 
 	if (!priv)
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_OUT_OF_MEMORY);
+		LOG_FUNC_RETURN(card->ctx, SC_ERROR_OUT_OF_MEMORY);
 
 	if (card->type == -1)
 		card->type = type;
@@ -2961,10 +2958,10 @@ static int piv_match_card(sc_card_t *card)
 	priv->tries_left = 10; /* will assume OK at start */
 
 	/* Some objects will only be present if Histroy object says so */
-	for (i=0; i < PIV_OBJ_LAST_ENUM -1; i++) {
+	for (i=0; i < PIV_OBJ_LAST_ENUM -1; i++)
 		if(piv_objects[i].flags & PIV_OBJECT_NOT_PRESENT)
 			priv->obj_cache[i].flags |= PIV_OBJ_CACHE_NOT_PRESENT;
-	}
+
 
 	return 1; /* match */
 }
@@ -2984,16 +2981,16 @@ static int piv_init(sc_card_t *card)
 
 	/* can not force the PIV driver to use non-PIV cards as tested in piv_card_match */
 	if (!priv || card->type == -1)
-		SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, SC_ERROR_NO_CARD_SUPPORT);
+		LOG_FUNC_RETURN(card->ctx, SC_ERROR_NO_CARD_SUPPORT);
 
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "Max send = %d recv = %d card->type = %d\n",
+	sc_log(card->ctx, "Max send = %d recv = %d card->type = %d",
 			card->max_send_size, card->max_recv_size, card->type);
 	card->cla = 0x00;
 	if(card->name == NULL)
 		card->name = "PIV-II card";
 
 	/*
-	 * Set card_issues based on card type either set by piv_match_card or by opensc.conf 
+	 * Set card_issues based on card type either set by piv_match_card or by opensc.conf
 	 */
 
 	switch(card->type) {
@@ -3008,21 +3005,19 @@ static int piv_init(sc_card_t *card)
 			apdu.le = apdu.resplen;
 			r = sc_transmit_apdu(card, &apdu);
 			priv->neo_version = (neo_version_buf[0]<<16) | (neo_version_buf[1] <<8) | neo_version_buf[2];
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "NEO card->type=%d, r=0x%08x version=0x%08x",
-					card->type, r, priv->neo_version);
+			sc_log(card->ctx, "NEO card->type=%d, r=0x%08x version=0x%08x", card->type, r, priv->neo_version);
 			break;
 	}
 
-
-	/* 
+	/*
 	 * set card_issues flags based card->type and new versions
-	 * YubiKey NEO and Ybuikey 4 have PIV applets, with compliance issues 
-	 * with the the NIST 800-73-3 specs The OpenSC developers do not have 
-	 * access to the different versions the NEO and 4, so it is a best 
-	 * if using a protected object can be use to test verify state. 
+	 * YubiKey NEO and Ybuikey 4 have PIV applets, with compliance issues
+	 * with the the NIST 800-73-3 specs The OpenSC developers do not have
+	 * access to the different versions the NEO and 4, so it is a best
+	 * if using a protected object can be use to test verify state.
 	 * TODO use NEO version numbers to set the flags. Allows for finer control
-	 * but needs input from Yubico or users. 
-	 */ 
+	 * but needs input from Yubico or users.
+	 */
 
 	switch(card->type) {
 		case SC_CARD_TYPE_PIV_II_NEO:
@@ -3051,10 +3046,10 @@ static int piv_init(sc_card_t *card)
 
 		default:
 		     priv->card_issues = 0; /* opensc.conf may have it wrong, continue anyway */
-		     sc_debug(card->ctx, SC_LOG_DEBUG_VERBOSE, "Unknown PIV card->type %d\n", card->type);
+		     sc_log(card->ctx, "Unknown PIV card->type %d", card->type);
 		     card->type = SC_CARD_TYPE_PIV_II_BASE;
 	}
-	sc_debug(card->ctx, SC_LOG_DEBUG_VERBOSE, "PIV card-type=%d card_issues=0x%08x", card->type, priv->card_issues);
+	sc_log(card->ctx, "PIV card-type=%d card_issues=0x%08x", card->type, priv->card_issues);
 
 	priv->enumtag = piv_aids[0].enumtag;
 
@@ -3090,7 +3085,7 @@ static int piv_init(sc_card_t *card)
 
 	if (r > 0)
 		r = 0;
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 
@@ -3110,14 +3105,14 @@ static int piv_check_sw(struct sc_card *card, unsigned int sw1, unsigned int sw2
 		}
 		if (priv->card_issues & CI_VERIFY_630X) {
 
-		/* Handle the Yubikey NEO or any other PIV card which returns in response to a verify 
+		/* Handle the Yubikey NEO or any other PIV card which returns in response to a verify
 		 * 63 0X rather than 63 CX indicate the number of remaining PIN retries.
 		 * Perhaps they misread the spec and thought 0xCX meant "clear" or "don't care", not a literal 0xC!
 		 */
 			if (priv->pin_cmd_verify && sw1 == 0x63U) {
 				priv->pin_cmd_verify_sw2 |= 0xC0U; /* make it easier to test in other code */
 				if ((sw2 & ~0x0fU) == 0x00U) {
-					sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "Verification failed (remaining tries: %d)", (sw2 & 0x0f));
+					sc_log(card->ctx, "Verification failed (remaining tries: %d)", (sw2 & 0x0f));
 					return SC_ERROR_PIN_CODE_INCORRECT;
 					/* this is what the iso_check_sw returns for 63 C0 */
 				}
@@ -3128,7 +3123,9 @@ static int piv_check_sw(struct sc_card *card, unsigned int sw1, unsigned int sw2
 	return r;
 }
 
-static int piv_check_protected_objects(sc_card_t *card)
+
+static int
+piv_check_protected_objects(sc_card_t *card)
 {
 	int r = 0;
 	int i;
@@ -3138,25 +3135,25 @@ static int piv_check_protected_objects(sc_card_t *card)
 	size_t buf_len;
 	static int protected_objects[] = {PIV_OBJ_PI, PIV_OBJ_CHF, PIV_OBJ_IRIS_IMAGE};
 
-	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_NORMAL);
+	LOG_FUNC_CALLED(card->ctx);
 	/*
 	 * routine only called from piv_pin_cmd after verify lc=0 did not return 90 00
-	 * We will test for a protected object using GET DATA. 
+	 * We will test for a protected object using GET DATA.
 	 *
 	 * Based on observations, of cards using the GET DATA APDU,
 	 * SC_ERROR_SECURITY_STATUS_NOT_SATISFIED  means the PIN not verified,
 	 * SC_SUCCESS means PIN has been verified even if it has length 0
 	 * SC_ERROR_FILE_NOT_FOUND (which is the bug) does not tell us anything
-	 * about the state of the PIN and we will try the next object.  
-	 * 
+	 * about the state of the PIN and we will try the next object.
+	 *
 	 * If we can't determine the security state from this process,
 	 * set card_issues CI_CANT_USE_GETDATA_FOR_STATE
 	 * and return SC_ERROR_PIN_CODE_INCORRECT
-	 * The curcomvention is to add a dummy Printed Info object in the card. 
-	 * so we will have an object to test. 
-	 * 
+	 * The curcomvention is to add a dummy Printed Info object in the card.
+	 * so we will have an object to test.
+	 *
 	 * We save the object's number to use in the future.
-	 * 
+	 *
 	 */
 	if (priv->object_test_verify == 0) {
 		for (i = 0; i < (int)(sizeof(protected_objects)/sizeof(int)); i++) {
@@ -3175,9 +3172,9 @@ static int piv_check_protected_objects(sc_card_t *card)
 		}
 		if (priv->object_test_verify == 0) {
 			/*
-			 * none of the objects returned acceptable sw1, sw2 
+			 * none of the objects returned acceptable sw1, sw2
 			 */
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "No protected objects found, setting CI_CANT_USE_GETDATA_FOR_STATE");
+			sc_log(card->ctx, "No protected objects found, setting CI_CANT_USE_GETDATA_FOR_STATE");
 			priv->card_issues |= CI_CANT_USE_GETDATA_FOR_STATE;
 			r = SC_ERROR_PIN_CODE_INCORRECT;
 		}
@@ -3190,18 +3187,19 @@ static int piv_check_protected_objects(sc_card_t *card)
 		priv->pin_cmd_noparse = 0;
 	}
 	if (r == SC_ERROR_FILE_NOT_FOUND)
-			r = SC_ERROR_PIN_CODE_INCORRECT;
+		r = SC_ERROR_PIN_CODE_INCORRECT;
 	else if (r == SC_ERROR_SECURITY_STATUS_NOT_SATISFIED)
-			r = SC_ERROR_PIN_CODE_INCORRECT;
+		r = SC_ERROR_PIN_CODE_INCORRECT;
 	else if (r > 0)
 		r = SC_SUCCESS;
 
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "object_test_verify=%d, card_issues = 0x%08x", priv->object_test_verify, priv->card_issues);
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	sc_log(card->ctx, "object_test_verify=%d, card_issues = 0x%08x", priv->object_test_verify, priv->card_issues);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
-static int piv_pin_cmd(sc_card_t *card, struct sc_pin_cmd_data *data,
-                       int *tries_left)
+
+static int
+piv_pin_cmd(sc_card_t *card, struct sc_pin_cmd_data *data, int *tries_left)
 {
 	int r = 0;
 	piv_private_data_t * priv = PIV_DATA(card);
@@ -3213,7 +3211,7 @@ static int piv_pin_cmd(sc_card_t *card, struct sc_pin_cmd_data *data,
 	struct sc_card_driver *iso_drv = sc_get_iso7816_driver();
 
 	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"piv_pin_cmd tries_left=%d, logged_in=%d", priv->tries_left, priv->logged_in);
+	sc_log(card->ctx, "piv_pin_cmd tries_left=%d, logged_in=%d", priv->tries_left, priv->logged_in);
 	if (data->cmd == SC_PIN_CMD_CHANGE) {
 		int i = 0;
 		if (data->pin2.len < 6) {
@@ -3241,7 +3239,7 @@ static int piv_pin_cmd(sc_card_t *card, struct sc_pin_cmd_data *data,
 
 	/* if access to applet is know to be reset by other driver  we select_aid and try again */
 	if ( priv->card_issues & CI_OTHER_AID_LOSE_STATE && priv->pin_cmd_verify_sw1 == 0x6DU) {
-		sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "AID may be lost doing piv_find_aid and retry pin_cmd");
+		sc_log(card->ctx, "AID may be lost doing piv_find_aid and retry pin_cmd");
 		r = piv_find_aid(card, priv->aid_file); /* return not tested */
 
 		priv->pin_cmd_verify = 1; /* tell piv_check_sw its a verify to save sw1, sw2 */
@@ -3253,7 +3251,7 @@ static int piv_pin_cmd(sc_card_t *card, struct sc_pin_cmd_data *data,
 	if (data->cmd == SC_PIN_CMD_VERIFY) {
 	    if (r >= 0)
 		priv->logged_in = SC_PIN_STATE_LOGGED_IN;
-	    else 
+	    else
 		priv->logged_in = SC_PIN_STATE_LOGGED_OUT;
 	}
 
@@ -3262,7 +3260,7 @@ static int piv_pin_cmd(sc_card_t *card, struct sc_pin_cmd_data *data,
 
 	if (data->cmd == SC_PIN_CMD_GET_INFO) {
 		if (priv->card_issues & CI_CANT_USE_GETDATA_FOR_STATE) {
-			sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL, "CI_CANT_USE_GETDATA_FOR_STATE set, assume logged_in=%d", priv->logged_in);
+			sc_log(card->ctx, "CI_CANT_USE_GETDATA_FOR_STATE set, assume logged_in=%d", priv->logged_in);
 			data->pin1.logged_in =  priv->logged_in; /* use what ever we saw last */
 		} else if (priv->card_issues & CI_VERIFY_LC0_FAIL
 			&& priv->pin_cmd_verify_sw1 == 0x63U ) { /* can not use modified return codes from iso->drv->pin_cmd */
@@ -3285,8 +3283,8 @@ static int piv_pin_cmd(sc_card_t *card, struct sc_pin_cmd_data *data,
 		priv->tries_left = data->pin1.tries_left;
 	}
 
-	sc_debug(card->ctx, SC_LOG_DEBUG_NORMAL,"piv_pin_cmd tries_left=%d, logged_in=%d",priv->tries_left, priv->logged_in);
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	sc_log(card->ctx, "piv_pin_cmd tries_left=%d, logged_in=%d",priv->tries_left, priv->logged_in);
+	LOG_FUNC_RETURN(card->ctx, r);
 }
 
 
@@ -3295,11 +3293,11 @@ static int piv_logout(sc_card_t *card)
 	int r = SC_ERROR_NOT_SUPPORTED; /* TODO Some PIV cards may support a logout */
 	/* piv_private_data_t * priv = PIV_DATA(card); */
 
-	SC_FUNC_CALLED(card->ctx, SC_LOG_DEBUG_VERBOSE);
+	LOG_FUNC_CALLED(card->ctx);
 
 	/* TODO 800-73-3 does not define a logout, 800-73-4 does */
 
-	SC_FUNC_RETURN(card->ctx, SC_LOG_DEBUG_NORMAL, r);
+	LOG_FUNC_RETURN(card->ctx, r);
 }