pcsc-lite  2.0.3
debuglog.c
Go to the documentation of this file.
1 /*
2  * MUSCLE SmartCard Development ( https://pcsclite.apdu.fr/ )
3  *
4  * Copyright (C) 1999-2002
5  * David Corcoran <corcoran@musclecard.com>
6  * Copyright (C) 2002-2011
7  * Ludovic Rousseau <ludovic.rousseau@free.fr>
8  *
9 Redistribution and use in source and binary forms, with or without
10 modification, are permitted provided that the following conditions
11 are met:
12 
13 1. Redistributions of source code must retain the above copyright
14  notice, this list of conditions and the following disclaimer.
15 2. Redistributions in binary form must reproduce the above copyright
16  notice, this list of conditions and the following disclaimer in the
17  documentation and/or other materials provided with the distribution.
18 3. The name of the author may not be used to endorse or promote products
19  derived from this software without specific prior written permission.
20 
21 THIS SOFTWARE IS PROVIDED BY THE AUTHOR ``AS IS'' AND ANY EXPRESS OR
22 IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES
23 OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED.
24 IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR ANY DIRECT, INDIRECT,
25 INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT
26 NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
27 DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
28 THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
29 (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF
30 THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
31  */
32 
38 #include "config.h"
39 #ifdef HAVE_SYSLOG_H
40 #include <syslog.h>
41 #endif
42 #include <unistd.h>
43 #include <stdio.h>
44 #include <stdlib.h>
45 #include <string.h>
46 #include <stdarg.h>
47 #include <assert.h>
48 #include <sys/types.h>
49 #include <sys/time.h>
50 #include <time.h>
51 #include <pthread.h>
52 
53 #include "pcsclite.h"
54 #include "misc.h"
55 #include "debuglog.h"
56 #include "sys_generic.h"
57 
58 #ifdef NO_LOG
59 
60 void log_msg(const int priority, const char *fmt, ...)
61 {
62  (void)priority;
63  (void)fmt;
64 }
65 
66 void log_xxd(const int priority, const char *msg, const unsigned char *buffer,
67  const int len)
68 {
69  (void)priority;
70  (void)msg;
71  (void)buffer;
72  (void)len;
73 }
74 
75 void DebugLogSetLogType(const int dbgtype)
76 {
77  (void)dbgtype;
78 }
79 
80 void DebugLogSetLevel(const int level)
81 {
82  (void)level;
83 }
84 
85 INTERNAL void DebugLogSetCategory(const int dbginfo)
86 {
87  (void)dbginfo;
88 }
89 
90 INTERNAL void DebugLogCategory(const int category, const unsigned char *buffer,
91  const int len)
92 {
93  (void)category;
94  (void)buffer;
95  (void)len;
96 }
97 
98 #else
99 
103 #define DEBUG_BUF_SIZE 2048
104 
105 static char LogMsgType = DEBUGLOG_NO_DEBUG;
106 static char LogCategory = DEBUG_CATEGORY_NOTHING;
107 
109 static char LogLevel = PCSC_LOG_ERROR;
110 
111 static signed char LogDoColor = 0;
113 static pthread_mutex_t LastTimeMutex = PTHREAD_MUTEX_INITIALIZER;
114 
115 static void log_line(const int priority, const char *DebugBuffer,
116  unsigned int rv);
117 
118 /*
119  * log a message with the RV value returned by the daemon
120  */
121 void log_msg_rv(const int priority, unsigned int rv, const char *fmt, ...)
122 {
123  char DebugBuffer[DEBUG_BUF_SIZE];
124  va_list argptr;
125 
126  if ((priority < LogLevel) /* log priority lower than threshold? */
127  || (DEBUGLOG_NO_DEBUG == LogMsgType))
128  return;
129 
130  va_start(argptr, fmt);
131  vsnprintf(DebugBuffer, sizeof DebugBuffer, fmt, argptr);
132  va_end(argptr);
133 
134  log_line(priority, DebugBuffer, rv);
135 }
136 
137 void log_msg(const int priority, const char *fmt, ...)
138 {
139  char DebugBuffer[DEBUG_BUF_SIZE];
140  va_list argptr;
141  // boolean not to do openlog several times
142  static int syslog_opened = 0;
143 
144  if ((priority < LogLevel) /* log priority lower than threshold? */
145  || (DEBUGLOG_NO_DEBUG == LogMsgType))
146  return;
147 
148  va_start(argptr, fmt);
149  vsnprintf(DebugBuffer, sizeof DebugBuffer, fmt, argptr);
150  va_end(argptr);
151 
152  if (DEBUGLOG_SYSLOG_DEBUG == LogMsgType && !syslog_opened) {
153  openlog(NULL, LOG_PID, LOG_DAEMON);
154  syslog_opened = 1;
155  }
156 
157  log_line(priority, DebugBuffer, -1);
158 } /* log_msg */
159 
160 /* convert from integer rv value to a string value
161  * SCARD_S_SUCCESS -> "SCARD_S_SUCCESS"
162  */
163 const char * rv2text(unsigned int rv)
164 {
165  const char *rv_text = NULL;
166  static __thread char strError[30];
167 
168 #define CASE(x) \
169  case x: \
170  rv_text = "rv=" #x; \
171  break
172 
173  if (rv != (unsigned int)-1)
174  {
175  switch (rv)
176  {
177  CASE(SCARD_S_SUCCESS);
178  CASE(SCARD_E_CANCELLED);
182  CASE(SCARD_E_INVALID_VALUE);
183  CASE(SCARD_E_NO_MEMORY);
184  CASE(SCARD_E_NO_SERVICE);
185  CASE(SCARD_E_NO_SMARTCARD);
190  CASE(SCARD_E_TIMEOUT);
193  CASE(SCARD_F_COMM_ERROR);
195  CASE(SCARD_W_REMOVED_CARD);
196  CASE(SCARD_W_RESET_CARD);
200 
201  default:
202  (void)snprintf(strError, sizeof(strError)-1,
203  "Unknown error: 0x%08X", rv);
204  rv_text = strError;
205  }
206  }
207 
208  return rv_text;
209 }
210 
211 static void log_line(const int priority, const char *DebugBuffer,
212  unsigned int rv)
213 {
214  if (DEBUGLOG_SYSLOG_DEBUG == LogMsgType)
215  syslog(LOG_DEBUG, "%s", DebugBuffer);
216  else
217  {
218  static struct timeval last_time = { 0, 0 };
219  struct timeval new_time = { 0, 0 };
220  struct timeval tmp;
221  int delta;
222  pthread_t thread_id;
223  const char *rv_text = NULL;
224 
225  (void)pthread_mutex_lock(&LastTimeMutex);
226  gettimeofday(&new_time, NULL);
227  if (0 == last_time.tv_sec)
228  last_time = new_time;
229 
230  tmp.tv_sec = new_time.tv_sec - last_time.tv_sec;
231  tmp.tv_usec = new_time.tv_usec - last_time.tv_usec;
232  if (tmp.tv_usec < 0)
233  {
234  tmp.tv_sec--;
235  tmp.tv_usec += 1000000;
236  }
237  if (tmp.tv_sec < 100)
238  delta = tmp.tv_sec * 1000000 + tmp.tv_usec;
239  else
240  delta = 99999999;
241 
242  last_time = new_time;
243  (void)pthread_mutex_unlock(&LastTimeMutex);
244 
245  thread_id = pthread_self();
246 
247  rv_text = rv2text(rv);
248 
249  if (LogDoColor)
250  {
251  const char *color_pfx = "", *color_sfx = "\33[0m";
252  const char *time_pfx = "\33[36m", *time_sfx = color_sfx;
253 
254  switch (priority)
255  {
256  case PCSC_LOG_CRITICAL:
257  color_pfx = "\33[01;31m"; /* bright + Red */
258  break;
259 
260  case PCSC_LOG_ERROR:
261  color_pfx = "\33[35m"; /* Magenta */
262  break;
263 
264  case PCSC_LOG_INFO:
265  color_pfx = "\33[34m"; /* Blue */
266  break;
267 
268  case PCSC_LOG_DEBUG:
269  color_pfx = ""; /* normal (black) */
270  color_sfx = "";
271  break;
272  }
273 
274 #ifdef __APPLE__
275 #define THREAD_FORMAT "%p"
276 #else
277 #define THREAD_FORMAT "%lu"
278 #endif
279  if (rv_text)
280  {
281  const char * rv_pfx = "", * rv_sfx = "";
282  if (rv != SCARD_S_SUCCESS)
283  {
284  rv_pfx = "\33[31m"; /* Red */
285  rv_sfx = "\33[0m";
286  }
287 
288  printf("%s%.8d%s [" THREAD_FORMAT "] %s%s%s, %s%s%s\n",
289  time_pfx, delta, time_sfx, thread_id,
290  color_pfx, DebugBuffer, color_sfx,
291  rv_pfx, rv_text, rv_sfx);
292  }
293  else
294  printf("%s%.8d%s [" THREAD_FORMAT "] %s%s%s\n",
295  time_pfx, delta, time_sfx, thread_id,
296  color_pfx, DebugBuffer, color_sfx);
297  }
298  else
299  {
300  if (rv_text)
301  printf("%.8d %s, %s\n", delta, DebugBuffer, rv_text);
302  else
303  printf("%.8d %s\n", delta, DebugBuffer);
304  }
305  fflush(stdout);
306  }
307 } /* log_line */
308 
309 static void log_xxd_always(const int priority, const char *msg,
310  const unsigned char *buffer, const int len)
311 {
312  char DebugBuffer[len*3 + strlen(msg) +1];
313  int i;
314  char *c;
315 
316  /* DebugBuffer is always big enough for msg */
317  strcpy(DebugBuffer, msg);
318  c = DebugBuffer + strlen(DebugBuffer);
319 
320  for (i = 0; (i < len); ++i)
321  {
322  /* 2 hex characters, 1 space, 1 NUL : total 4 characters */
323  snprintf(c, 4, "%02X ", buffer[i]);
324  c += 3;
325  }
326 
327  log_line(priority, DebugBuffer, -1);
328 } /* log_xxd_always */
329 
330 void log_xxd(const int priority, const char *msg, const unsigned char *buffer,
331  const int len)
332 {
333  if ((priority < LogLevel) /* log priority lower than threshold? */
334  || (DEBUGLOG_NO_DEBUG == LogMsgType))
335  return;
336 
337  /* len is an error value? */
338  if (len < 0)
339  return;
340 
341  log_xxd_always(priority, msg, buffer, len);
342 } /* log_xxd */
343 
344 void DebugLogSetLogType(const int dbgtype)
345 {
346  switch (dbgtype)
347  {
348  case DEBUGLOG_NO_DEBUG:
349  case DEBUGLOG_SYSLOG_DEBUG:
350  case DEBUGLOG_STDOUT_DEBUG:
351  case DEBUGLOG_STDOUT_COLOR_DEBUG:
352  LogMsgType = dbgtype;
353  break;
354  default:
355  Log2(PCSC_LOG_CRITICAL, "unknown log type (%d), using stdout",
356  dbgtype);
357  LogMsgType = DEBUGLOG_STDOUT_DEBUG;
358  }
359 
360  /* log to stdout and stdout is a tty? */
361  if ((DEBUGLOG_STDOUT_DEBUG == LogMsgType && isatty(fileno(stdout)))
362  || (DEBUGLOG_STDOUT_COLOR_DEBUG == LogMsgType))
363  {
364  char *term;
365 
366  term = getenv("TERM");
367  if (term)
368  {
369  const char *terms[] = { "linux", "xterm", "xterm-color", "Eterm", "rxvt", "rxvt-unicode", "xterm-256color" };
370  unsigned int i;
371 
372  /* for each known color terminal */
373  for (i = 0; i < COUNT_OF(terms); i++)
374  {
375  /* we found a supported term? */
376  if (0 == strcmp(terms[i], term))
377  {
378  LogDoColor = 1;
379  break;
380  }
381  }
382  }
383  }
384 }
385 
386 void DebugLogSetLevel(const int level)
387 {
388  LogLevel = level;
389  switch (level)
390  {
391  case PCSC_LOG_CRITICAL:
392  case PCSC_LOG_ERROR:
393  /* do not log anything */
394  break;
395 
396  case PCSC_LOG_INFO:
397  Log1(PCSC_LOG_INFO, "debug level=info");
398  break;
399 
400  case PCSC_LOG_DEBUG:
401  Log1(PCSC_LOG_DEBUG, "debug level=debug");
402  break;
403 
404  default:
405  LogLevel = PCSC_LOG_INFO;
406  Log2(PCSC_LOG_CRITICAL, "unknown level (%d), using level=info",
407  level);
408  }
409 }
410 
411 INTERNAL void DebugLogSetCategory(const int dbginfo)
412 {
413  /* use a negative number to UNset
414  * typically use ~DEBUG_CATEGORY_APDU
415  */
416  if (dbginfo < 0)
417  LogCategory &= dbginfo;
418  else
419  LogCategory |= dbginfo;
420 
421  if (LogCategory & DEBUG_CATEGORY_APDU)
422  Log1(PCSC_LOG_INFO, "Debug options: APDU");
423 }
424 
425 INTERNAL void DebugLogCategory(const int category, const unsigned char *buffer,
426  const int len)
427 {
428  if ((category & DEBUG_CATEGORY_APDU)
429  && (LogCategory & DEBUG_CATEGORY_APDU))
430  log_xxd_always(PCSC_LOG_INFO, "APDU: ", buffer, len);
431 
432  if ((category & DEBUG_CATEGORY_SW)
433  && (LogCategory & DEBUG_CATEGORY_APDU))
434  log_xxd_always(PCSC_LOG_INFO, "SW: ", buffer, len);
435 }
436 
437 /*
438  * old function supported for backward object code compatibility
439  * defined only for pcscd
440  */
441 #ifdef PCSCD
442 void debug_msg(const char *fmt, ...);
443 void debug_msg(const char *fmt, ...)
444 {
445  char DebugBuffer[DEBUG_BUF_SIZE];
446  va_list argptr;
447 
448  if (DEBUGLOG_NO_DEBUG == LogMsgType)
449  return;
450 
451  va_start(argptr, fmt);
452  vsnprintf(DebugBuffer, sizeof DebugBuffer, fmt, argptr);
453  va_end(argptr);
454 
455  if (DEBUGLOG_SYSLOG_DEBUG == LogMsgType)
456  syslog(LOG_INFO, "%s", DebugBuffer);
457  else
458  puts(DebugBuffer);
459 } /* debug_msg */
460 
461 void debug_xxd(const char *msg, const unsigned char *buffer, const int len);
462 void debug_xxd(const char *msg, const unsigned char *buffer, const int len)
463 {
464  log_xxd(PCSC_LOG_ERROR, msg, buffer, len);
465 } /* debug_xxd */
466 #endif
467 
468 #endif /* NO_LOG */
469 
#define SCARD_E_INVALID_VALUE
One or more of the supplied parameters values could not be properly interpreted.
Definition: pcsclite.h:141
#define SCARD_S_SUCCESS
No error was encountered.
Definition: pcsclite.h:107
#define SCARD_E_TIMEOUT
The user-specified timeout value has expired.
Definition: pcsclite.h:127
#define SCARD_E_NO_SERVICE
The Smart card resource manager is not running.
Definition: pcsclite.h:165
#define SCARD_E_INVALID_PARAMETER
One or more of the supplied parameters could not be properly interpreted.
Definition: pcsclite.h:115
#define SCARD_E_NO_READERS_AVAILABLE
Cannot find a smart card reader.
Definition: pcsclite.h:202
This handles abstract system level calls.
#define SCARD_E_NO_SMARTCARD
The operation requires a Smart Card, but no Smart Card is currently in the device.
Definition: pcsclite.h:131
#define SCARD_W_UNRESPONSIVE_CARD
The smart card is not responding to a reset.
Definition: pcsclite.h:213
#define SCARD_E_NOT_TRANSACTED
An attempt was made to end a non-existent transaction.
Definition: pcsclite.h:151
#define DEBUG_BUF_SIZE
Max string size dumping a maximum of 2 lines of 80 characters.
Definition: debuglog.c:103
#define SCARD_E_PROTO_MISMATCH
The requested protocols are incompatible with the protocol currently in use with the smart card...
Definition: pcsclite.h:137
static char LogLevel
default level
Definition: debuglog.c:109
#define SCARD_E_NO_MEMORY
Not enough memory available to complete this command.
Definition: pcsclite.h:119
#define SCARD_E_READER_UNAVAILABLE
The specified reader is not currently available for use.
Definition: pcsclite.h:153
#define SCARD_W_RESET_CARD
The smart card has been reset, so any shared state information is invalid.
Definition: pcsclite.h:217
This keeps a list of defines for pcsc-lite.
#define SCARD_F_COMM_ERROR
An internal communications error has been detected.
Definition: pcsclite.h:145
#define SCARD_W_REMOVED_CARD
The smart card has been removed, so further communication is not possible.
Definition: pcsclite.h:219
#define SCARD_E_INSUFFICIENT_BUFFER
The data buffer to receive returned data is too small for the returned data.
Definition: pcsclite.h:123
#define SCARD_E_CANCELLED
The action was cancelled by an SCardCancel request.
Definition: pcsclite.h:111
#define SCARD_E_SHARING_VIOLATION
The smart card cannot be accessed because of other connections outstanding.
Definition: pcsclite.h:129
#define SCARD_E_UNKNOWN_READER
The specified reader name is not recognized.
Definition: pcsclite.h:125
#define SCARD_F_INTERNAL_ERROR
An internal consistency check failed.
Definition: pcsclite.h:109
#define SCARD_E_UNSUPPORTED_FEATURE
This smart card does not support the requested feature.
Definition: pcsclite.h:171
#define SCARD_E_INVALID_HANDLE
The supplied handle was invalid.
Definition: pcsclite.h:113
This handles debugging.
#define SCARD_W_UNPOWERED_CARD
Power has been removed from the smart card, so that further communication is not possible.
Definition: pcsclite.h:215
static signed char LogDoColor
no color by default
Definition: debuglog.c:111