Check-in [e4fd58cbb9]
Overview
Comment:Added timing information to debug output

Fixed issue where readers that were removed and readded weren't connected to properly

Downloads: Tarball | ZIP archive | SQL archive
Timelines: family | ancestors | descendants | both | trunk
Files: files | file ages | folders
SHA1:e4fd58cbb96569e996100be1b6929ecc429e3f95
User & Date: rkeene on 2010-07-23 21:23:41
Other Links: manifest | tags
Context
2010-07-23
21:46
Consolidated slot resetting into a single function.

Updated slot resetting to invalidate slot PC/SC handle. check-in: 1edf82bc16 user: rkeene tags: trunk

21:23
Added timing information to debug output

Fixed issue where readers that were removed and readded weren't connected to properly check-in: e4fd58cbb9 user: rkeene tags: trunk

17:24
Fixed retry on NOT_TRANSACTED to retry at a higher level

Consolidated all SCardReconnect calls into a wrapper that takes care of T=0 or T=1 selection check-in: 93bc06dab6 user: rkeene tags: trunk

Changes

Modified cackey.c from [5f33c366a8] to [5667b1108e].

   164    164   #define GSCIS_AID_CCC                 0xA0, 0x00, 0x00, 0x01, 0x16, 0xDB, 0x00
   165    165   
   166    166   /* Maximum size of data portion of APDUs */
   167    167   /** Do not set this above 250 **/
   168    168   #define CACKEY_APDU_MTU               250
   169    169   
   170    170   #ifdef CACKEY_DEBUG
          171  +#  ifdef HAVE_TIME_H
          172  +#    include <time.h>
          173  +static time_t cackey_debug_start_time = 0;
          174  +#    define CACKEY_DEBUG_PRINTTIME { if (cackey_debug_start_time == 0) { cackey_debug_start_time = time(NULL); }; fprintf(stderr, "[%lu]: ", (unsigned long) (time(NULL) - cackey_debug_start_time)); }
          175  +#  else
          176  +#    define CACKEY_DEBUG_PRINTTIME /**/
          177  +#  endif
   171    178   
   172         -#  define CACKEY_DEBUG_PRINTF(x...) { fprintf(stderr, "%s():%i: ", __func__, __LINE__); fprintf(stderr, x); fprintf(stderr, "\n"); fflush(stderr); }
   173         -#  define CACKEY_DEBUG_PRINTBUF(f, x, y) { unsigned char *TMPBUF; unsigned long idx; TMPBUF = (unsigned char *) (x); fprintf(stderr, "%s():%i: %s  (%s/%lu = {%02x", __func__, __LINE__, f, #x, (unsigned long) (y), TMPBUF[0]); for (idx = 1; idx < (y); idx++) { fprintf(stderr, ", %02x", TMPBUF[idx]); }; fprintf(stderr, "})\n"); fflush(stderr); }
   174         -#  define CACKEY_DEBUG_PERROR(x) { fprintf(stderr, "%s():%i: ", __func__, __LINE__); perror(x); fflush(stderr); }
          179  +#  define CACKEY_DEBUG_PRINTF(x...) { CACKEY_DEBUG_PRINTTIME; fprintf(stderr, "%s():%i: ", __func__, __LINE__); fprintf(stderr, x); fprintf(stderr, "\n"); fflush(stderr); }
          180  +#  define CACKEY_DEBUG_PRINTBUF(f, x, y) { unsigned char *TMPBUF; unsigned long idx; TMPBUF = (unsigned char *) (x); CACKEY_DEBUG_PRINTTIME; fprintf(stderr, "%s():%i: %s  (%s/%lu = {%02x", __func__, __LINE__, f, #x, (unsigned long) (y), TMPBUF[0]); for (idx = 1; idx < (y); idx++) { fprintf(stderr, ", %02x", TMPBUF[idx]); }; fprintf(stderr, "})\n"); fflush(stderr); }
          181  +#  define CACKEY_DEBUG_PERROR(x) { fprintf(stderr, "%s():%i: ", __func__, __LINE__); CACKEY_DEBUG_PRINTTIME; perror(x); fflush(stderr); }
   175    182   #  define free(x) { CACKEY_DEBUG_PRINTF("FREE(%p) (%s)", x, #x); free(x); }
   176    183   
   177    184   static void *CACKEY_DEBUG_FUNC_MALLOC(size_t size, const char *func, int line) {
   178    185   	void *retval;
   179    186   
   180    187   	retval = malloc(size);
   181    188   
          189  +	CACKEY_DEBUG_PRINTTIME;
   182    190   	fprintf(stderr, "%s():%i: ", func, line);
   183    191   	fprintf(stderr, "MALLOC() = %p", retval);
   184    192   	fprintf(stderr, "\n");
   185    193   	fflush(stderr);
   186    194   
   187    195   	return(retval);
   188    196   }
................................................................................
   189    197   
   190    198   static void *CACKEY_DEBUG_FUNC_REALLOC(void *ptr, size_t size, const char *func, int line) {
   191    199   	void *retval;
   192    200   
   193    201   	retval = realloc(ptr, size);
   194    202   
   195    203   	if (retval != ptr) {
          204  +		CACKEY_DEBUG_PRINTTIME;
   196    205   		fprintf(stderr, "%s():%i: ", func, line);
   197    206   		fprintf(stderr, "REALLOC(%p) = %p", ptr, retval);
   198    207   		fprintf(stderr, "\n");
   199    208   		fflush(stderr);
   200    209   	}
   201    210   
   202    211   	if (retval == NULL) {
................................................................................
   207    216   }
   208    217   
   209    218   static char *CACKEY_DEBUG_FUNC_STRDUP(const char *ptr, const char *func, int line) {
   210    219   	char *retval;
   211    220   
   212    221   	retval = strdup(ptr);
   213    222   
          223  +	CACKEY_DEBUG_PRINTTIME;
   214    224   	fprintf(stderr, "%s():%i: ", func, line);
   215    225   	fprintf(stderr, "STRDUP_MALLOC() = %p", retval);
   216    226   	fprintf(stderr, "\n");
   217    227   	fflush(stderr);
   218    228   
   219    229   	return(retval);
   220    230   }
................................................................................
   890    900   		CACKEY_DEBUG_PRINTF("Connection to PC/SC failed, returning in failure");
   891    901   
   892    902   		return(CACKEY_PCSC_E_GENERIC);
   893    903   	}
   894    904   
   895    905   	/* Connect to reader, if needed */
   896    906   	if (!slot->pcsc_card_connected) {
   897         -		slot->protocol = 0;
   898         -
   899    907   		CACKEY_DEBUG_PRINTF("SCardConnect(%s) called", slot->pcsc_reader);
   900    908   		scard_conn_ret = SCardConnect(*cackey_pcsc_handle, slot->pcsc_reader, SCARD_SHARE_SHARED, SCARD_PROTOCOL_T0 | SCARD_PROTOCOL_T1, &slot->pcsc_card, &protocol);
   901    909   
   902    910   		if (scard_conn_ret == SCARD_E_PROTO_MISMATCH) {
   903    911   			CACKEY_DEBUG_PRINTF("SCardConnect() returned SCARD_E_PROTO_MISMATCH, trying with just T=0")
   904    912   			scard_conn_ret = SCardConnect(*cackey_pcsc_handle, slot->pcsc_reader, SCARD_SHARE_SHARED, SCARD_PROTOCOL_T0, &slot->pcsc_card, &protocol);
   905    913   
................................................................................
  1193   1201   		CACKEY_DEBUG_PRINTBUF("Sending APDU:", xmit_buf, xmit_len);
  1194   1202   	}
  1195   1203   
  1196   1204   	recv_len = sizeof(recv_buf);
  1197   1205   	scard_xmit_ret = SCardTransmit(slot->pcsc_card, pioSendPci, xmit_buf, xmit_len, NULL, recv_buf, &recv_len);
  1198   1206   
  1199   1207   	if (scard_xmit_ret == SCARD_E_NOT_TRANSACTED) {
  1200         -		CACKEY_DEBUG_PRINTF("Failed to send APDU to card (SCardTransmit() = %s/%lx), will ask calling function to retry...", CACKEY_DEBUG_FUNC_SCARDERR_TO_STR(scard_xmit_ret), (unsigned long) scard_xmit_ret);
         1208  +		CACKEY_DEBUG_PRINTF("Failed to send APDU to card (SCardTransmit() = %s/%lx), will ask calling function to retry (not resetting card)...", CACKEY_DEBUG_FUNC_SCARDERR_TO_STR(scard_xmit_ret), (unsigned long) scard_xmit_ret);
  1201   1209   
  1202   1210   		/* Begin Smartcard Transaction */
  1203   1211   		cackey_end_transaction(slot);
  1204   1212   
  1205   1213   		return(CACKEY_PCSC_E_RETRY);
  1206   1214   	}
  1207   1215   
................................................................................
  2386   2394   		CACKEY_DEBUG_PRINTF("Unable to connect to card, returning token absent");
  2387   2395   
  2388   2396   		return(CACKEY_PCSC_E_TOKENABSENT);
  2389   2397   	}
  2390   2398   
  2391   2399   	atr_len = sizeof(atr);
  2392   2400   	status_ret = SCardStatus(slot->pcsc_card, NULL, &reader_len, &state, &protocol, atr, &atr_len);
         2401  +
         2402  +	if (status_ret == SCARD_E_INVALID_HANDLE) {
         2403  +		CACKEY_DEBUG_PRINTF("SCardStatus() returned SCARD_E_INVALID_HANDLE, marking is not already connected and trying again");
         2404  +		slot->pcsc_card_connected = 0;
         2405  +		slot->slot_reset = 1;
         2406  +		slot->token_flags = CKF_LOGIN_REQUIRED;
         2407  +
         2408  +		pcsc_connect_ret = cackey_connect_card(slot);
         2409  +		if (pcsc_connect_ret != CACKEY_PCSC_S_OK) {
         2410  +			CACKEY_DEBUG_PRINTF("Unable to connect to card, returning token absent");
         2411  +
         2412  +			return(CACKEY_PCSC_E_TOKENABSENT);
         2413  +		}
         2414  +
         2415  +		atr_len = sizeof(atr);
         2416  +		status_ret = SCardStatus(slot->pcsc_card, NULL, &reader_len, &state, &protocol, atr, &atr_len);
         2417  +	}
         2418  +
  2393   2419   	if (status_ret != SCARD_S_SUCCESS) {
  2394   2420   		slot->slot_reset = 1;
  2395   2421   		slot->token_flags = CKF_LOGIN_REQUIRED;
  2396   2422   
  2397   2423   		if (status_ret == SCARD_W_RESET_CARD) {
  2398   2424   			CACKEY_DEBUG_PRINTF("Reset required, please hold...");
  2399   2425   
................................................................................
  4508   4534   
  4509   4535   		if (cackey_slots[slotID].label != NULL) {
  4510   4536   			free(cackey_slots[slotID].label);
  4511   4537   			cackey_slots[slotID].label = NULL;
  4512   4538   		}
  4513   4539   
  4514   4540   		cackey_slots[slotID].slot_reset = 0;
         4541  +		cackey_slots[slotID].pcsc_card_connected = 0;
  4515   4542   		cackey_slots[slotID].token_flags = CKF_LOGIN_REQUIRED;
  4516   4543   	}
  4517   4544   
  4518   4545   	if (cackey_sessions[hSession].identities == NULL) {
  4519   4546   		cackey_sessions[hSession].identities = cackey_read_identities(&cackey_slots[slotID], &cackey_sessions[hSession].identities_count);
  4520   4547   	}
  4521   4548   

Modified configure.ac from [7e15536eaa] to [1ed71809e2].

    22     22   AC_CHECK_TOOL(AR, ar)
    23     23   AC_CHECK_TOOL(RANLIB, ranlib)
    24     24   
    25     25   dnl Determine how to strip executables
    26     26   AC_CHECK_TOOL(STRIP, strip)
    27     27   
    28     28   dnl Check for all required headers
    29         -AC_CHECK_HEADERS(arpa/inet.h inttypes.h stdarg.h stdint.h stdio.h stdlib.h string.h sys/socket.h sys/types.h sys/un.h unistd.h pthread.h zlib.h limits.h,,[
           29  +AC_CHECK_HEADERS(arpa/inet.h inttypes.h stdarg.h stdint.h stdio.h stdlib.h string.h sys/socket.h sys/types.h sys/un.h time.h unistd.h pthread.h zlib.h limits.h,,[
    30     30   	AC_WARN([Required header missing, compilation will likely fail.])
    31     31   ], [
    32     32   #ifdef HAVE_ARPA_INET_H
    33     33   #  include <arpa/inet.h>
    34     34   #endif
    35     35   #ifdef HAVE_INTTYPES_H
    36     36   #  include <inttypes.h>
................................................................................
    58     58   #endif
    59     59   #ifdef HAVE_SYS_UN_H
    60     60   #  include <sys/un.h>
    61     61   #endif
    62     62   #ifdef HAVE_UNISTD_H
    63     63   #  include <unistd.h>
    64     64   #endif
           65  +#ifdef HAVE_TIME_H
           66  +#  include <time.h>
           67  +#endif
    65     68   #ifdef HAVE_PTHREAD_H
    66     69   #  include <pthread.h>
    67     70   #endif
    68     71   #ifdef HAVE_LIMITS_H
    69     72   #  include <limits.h>
    70     73   #endif
    71     74   #ifdef HAVE_ZLIB_H