nsprpub/pr/src/io/prlog.c

   1 /* -*- Mode: C++; tab-width: 4; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
   2
   3 /* This Source Code Form is subject to the terms of the Mozilla Public
   4  * License, v. 2.0. If a copy of the MPL was not distributed with this
   5  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
   6
   7 #include "primpl.h"
   8 #include "prenv.h"
   9 #include "prprf.h"
  10 #include <string.h>
  11 #ifdef ANDROID
  12 #  include <android/log.h>
  13 #endif
  14
  15 /*
  16  * Lock used to lock the log.
  17  *
  18  * We can't define _PR_LOCK_LOG simply as PR_Lock because PR_Lock may
  19  * contain assertions.  We have to avoid assertions in _PR_LOCK_LOG
  20  * because PR_ASSERT calls PR_LogPrint, which in turn calls _PR_LOCK_LOG.
  21  * This can lead to infinite recursion.
  22  */
  23 static PRLock* _pr_logLock;
  24 #if defined(_PR_PTHREADS) || defined(_PR_BTHREADS)
  25 #  define _PR_LOCK_LOG() PR_Lock(_pr_logLock);
  26 #  define _PR_UNLOCK_LOG() PR_Unlock(_pr_logLock);
  27 #elif defined(_PR_GLOBAL_THREADS_ONLY)
  28 #  define _PR_LOCK_LOG() \
  29     {                    \
  30       _PR_LOCK_LOCK(_pr_logLock)
  31 #  define _PR_UNLOCK_LOG()        \
  32     _PR_LOCK_UNLOCK(_pr_logLock); \
  33     }
  34 #else
  35
  36 #  define _PR_LOCK_LOG()                                \
  37     {                                                   \
  38       PRIntn _is;                                       \
  39       PRThread* _me = _PR_MD_CURRENT_THREAD();          \
  40       if (!_PR_IS_NATIVE_THREAD(_me)) _PR_INTSOFF(_is); \
  41       _PR_LOCK_LOCK(_pr_logLock)
  42
  43 #  define _PR_UNLOCK_LOG()                           \
  44     _PR_LOCK_UNLOCK(_pr_logLock);                    \
  45     PR_ASSERT(_me == _PR_MD_CURRENT_THREAD());       \
  46     if (!_PR_IS_NATIVE_THREAD(_me)) _PR_INTSON(_is); \
  47     }
  48
  49 #endif
  50
  51 #if defined(XP_PC)
  52 #  define strcasecmp stricmp
  53 #endif
  54
  55 /*
  56  * On NT, we can't define _PUT_LOG as PR_Write or _PR_MD_WRITE,
  57  * because every asynchronous file io operation leads to a fiber context
  58  * switch.  So we define _PUT_LOG as fputs (from stdio.h).  A side
  59  * benefit is that fputs handles the LF->CRLF translation.  This
  60  * code can also be used on other platforms with file stream io.
  61  */
  62 #if defined(WIN32)
  63 #  define _PR_USE_STDIO_FOR_LOGGING
  64 #endif
  65
  66 /*
  67 ** Coerce Win32 log output to use OutputDebugString() when
  68 ** NSPR_LOG_FILE is set to "WinDebug".
  69 */
  70 #if defined(XP_PC)
  71 #  define WIN32_DEBUG_FILE (FILE*)-2
  72 #endif
  73
  74 #ifdef WINCE
  75 static void OutputDebugStringA(const char* msg) {
  76   int len = MultiByteToWideChar(CP_ACP, 0, msg, -1, 0, 0);
  77   WCHAR* wMsg = (WCHAR*)PR_Malloc(len * sizeof(WCHAR));
  78   MultiByteToWideChar(CP_ACP, 0, msg, -1, wMsg, len);
  79   OutputDebugStringW(wMsg);
  80   PR_Free(wMsg);
  81 }
  82 #endif
  83
  84 /* Macros used to reduce #ifdef pollution */
  85
  86 #if defined(_PR_USE_STDIO_FOR_LOGGING) && defined(XP_PC)
  87 #  define _PUT_LOG(fd, buf, nb)        \
  88     PR_BEGIN_MACRO                     \
  89     if (logFile == WIN32_DEBUG_FILE) { \
  90       char savebyte = buf[nb];         \
  91       buf[nb] = '\0';                  \
  92       OutputDebugStringA(buf);         \
  93       buf[nb] = savebyte;              \
  94     } else {                           \
  95       fwrite(buf, 1, nb, fd);          \
  96       fflush(fd);                      \
  97     }                                  \
  98     PR_END_MACRO
  99 #elif defined(_PR_USE_STDIO_FOR_LOGGING)
 100 #  define _PUT_LOG(fd, buf, nb) \
 101     {                           \
 102       fwrite(buf, 1, nb, fd);   \
 103       fflush(fd);               \
 104     }
 105 #elif defined(ANDROID)
 106 #  define _PUT_LOG(fd, buf, nb)                            \
 107     PR_BEGIN_MACRO                                         \
 108     if (fd == _pr_stderr) {                                \
 109       char savebyte = buf[nb];                             \
 110       buf[nb] = '\0';                                      \
 111       __android_log_write(ANDROID_LOG_INFO, "PRLog", buf); \
 112       buf[nb] = savebyte;                                  \
 113     } else {                                               \
 114       PR_Write(fd, buf, nb);                               \
 115     }                                                      \
 116     PR_END_MACRO
 117 #elif defined(_PR_PTHREADS)
 118 #  define _PUT_LOG(fd, buf, nb) PR_Write(fd, buf, nb)
 119 #else
 120 #  define _PUT_LOG(fd, buf, nb) _PR_MD_WRITE(fd, buf, nb)
 121 #endif
 122
 123 /************************************************************************/
 124
 125 static PRLogModuleInfo* logModules;
 126
 127 static char* logBuf = NULL;
 128 static char* logp;
 129 static char* logEndp;
 130 #ifdef _PR_USE_STDIO_FOR_LOGGING
 131 static FILE* logFile = NULL;
 132 #else
 133 static PRFileDesc* logFile = 0;
 134 #endif
 135 static PRBool outputTimeStamp = PR_FALSE;
 136 static PRBool appendToLog = PR_FALSE;
 137
 138 #define LINE_BUF_SIZE 512
 139 #define DEFAULT_BUF_SIZE 16384
 140
 141 #ifdef _PR_NEED_STRCASECMP
 142
 143 /*
 144  * strcasecmp is defined in /usr/ucblib/libucb.a on some platforms
 145  * such as NCR.  Linking with both libc and libucb
 146  * may cause some problem, so I just provide our own implementation
 147  * of strcasecmp here.
 148  */
 149
 150 static const unsigned char uc[] = {
 151     '\000', '\001', '\002', '\003', '\004', '\005', '\006', '\007', '\010',
 152     '\011', '\012', '\013', '\014', '\015', '\016', '\017', '\020', '\021',
 153     '\022', '\023', '\024', '\025', '\026', '\027', '\030', '\031', '\032',
 154     '\033', '\034', '\035', '\036', '\037', ' ',    '!',    '"',    '#',
 155     '$',    '%',    '&',    '\'',   '(',    ')',    '*',    '+',    ',',
 156     '-',    '.',    '/',    '0',    '1',    '2',    '3',    '4',    '5',
 157     '6',    '7',    '8',    '9',    ':',    ';',    '<',    '=',    '>',
 158     '?',    '@',    'A',    'B',    'C',    'D',    'E',    'F',    'G',
 159     'H',    'I',    'J',    'K',    'L',    'M',    'N',    'O',    'P',
 160     'Q',    'R',    'S',    'T',    'U',    'V',    'W',    'X',    'Y',
 161     'Z',    '[',    '\\',   ']',    '^',    '_',    '`',    'A',    'B',
 162     'C',    'D',    'E',    'F',    'G',    'H',    'I',    'J',    'K',
 163     'L',    'M',    'N',    'O',    'P',    'Q',    'R',    'S',    'T',
 164     'U',    'V',    'W',    'X',    'Y',    'Z',    '{',    '|',    '}',
 165     '~',    '\177'};
 166
 167 PRIntn strcasecmp(const char* a, const char* b) {
 168   const unsigned char* ua = (const unsigned char*)a;
 169   const unsigned char* ub = (const unsigned char*)b;
 170
 171   if (((const char*)0 == a) || (const char*)0 == b) {
 172     return (PRIntn)(a - b);
 173   }
 174
 175   while ((uc[*ua] == uc[*ub]) && ('\0' != *a)) {
 176     a++;
 177     ua++;
 178     ub++;
 179   }
 180
 181   return (PRIntn)(uc[*ua] - uc[*ub]);
 182 }
 183
 184 #endif /* _PR_NEED_STRCASECMP */
 185
 186 void _PR_InitLog(void) {
 187   char* ev;
 188
 189   _pr_logLock = PR_NewLock();
 190
 191   ev = PR_GetEnv("NSPR_LOG_MODULES");
 192   if (ev && ev[0]) {
 193     char module[64]; /* Security-Critical: If you change this
 194                       * size, you must also change the sscanf
 195                       * format string to be size-1.
 196                       */
 197     PRBool isSync = PR_FALSE;
 198     PRIntn evlen = strlen(ev), pos = 0;
 199     PRInt32 bufSize = DEFAULT_BUF_SIZE;
 200     while (pos < evlen) {
 201       PRIntn level = 1, count = 0, delta = 0;
 202       count = sscanf(
 203           &ev[pos],
 204           "%63[ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789_-"
 205           "]%n:%d%n",
 206           module, &delta, &level, &delta);
 207       pos += delta;
 208       if (count == 0) {
 209         break;
 210       }
 211
 212       /*
 213       ** If count == 2, then we got module and level. If count
 214       ** == 1, then level defaults to 1 (module enabled).
 215       */
 216       if (strcasecmp(module, "sync") == 0) {
 217         isSync = PR_TRUE;
 218       } else if (strcasecmp(module, "bufsize") == 0) {
 219         if (level >= LINE_BUF_SIZE) {
 220           bufSize = level;
 221         }
 222       } else if (strcasecmp(module, "timestamp") == 0) {
 223         outputTimeStamp = PR_TRUE;
 224       } else if (strcasecmp(module, "append") == 0) {
 225         appendToLog = PR_TRUE;
 226       } else {
 227         PRLogModuleInfo* lm = logModules;
 228         PRBool skip_modcheck =
 229             (0 == strcasecmp(module, "all")) ? PR_TRUE : PR_FALSE;
 230
 231         while (lm != NULL) {
 232           if (skip_modcheck) {
 233             lm->level = (PRLogModuleLevel)level;
 234           } else if (strcasecmp(module, lm->name) == 0) {
 235             lm->level = (PRLogModuleLevel)level;
 236             break;
 237           }
 238           lm = lm->next;
 239         }
 240       }
 241       /*found:*/
 242       count = sscanf(&ev[pos], " , %n", &delta);
 243       pos += delta;
 244       if (count == EOF) {
 245         break;
 246       }
 247     }
 248     PR_SetLogBuffering(isSync ? 0 : bufSize);
 249
 250     ev = PR_GetEnvSecure("NSPR_LOG_FILE");
 251     if (ev && ev[0]) {
 252       if (!PR_SetLogFile(ev)) {
 253 #ifdef XP_PC
 254         char* str = PR_smprintf("Unable to create nspr log file '%s'\n", ev);
 255         if (str) {
 256           OutputDebugStringA(str);
 257           PR_smprintf_free(str);
 258         }
 259 #else
 260         fprintf(stderr, "Unable to create nspr log file '%s'\n", ev);
 261 #endif
 262       }
 263     } else {
 264 #ifdef _PR_USE_STDIO_FOR_LOGGING
 265       logFile = stderr;
 266 #else
 267       logFile = _pr_stderr;
 268 #endif
 269     }
 270   }
 271 }
 272
 273 void _PR_LogCleanup(void) {
 274   PRLogModuleInfo* lm = logModules;
 275
 276   PR_LogFlush();
 277
 278 #ifdef _PR_USE_STDIO_FOR_LOGGING
 279   if (logFile && logFile != stdout && logFile != stderr
 280 #  ifdef XP_PC
 281       && logFile != WIN32_DEBUG_FILE
 282 #  endif
 283   ) {
 284     fclose(logFile);
 285   }
 286 #else
 287   if (logFile && logFile != _pr_stdout && logFile != _pr_stderr) {
 288     PR_Close(logFile);
 289   }
 290 #endif
 291   logFile = NULL;
 292
 293   if (logBuf) {
 294     PR_DELETE(logBuf);
 295   }
 296
 297   while (lm != NULL) {
 298     PRLogModuleInfo* next = lm->next;
 299     free((/*const*/ char*)lm->name);
 300     PR_Free(lm);
 301     lm = next;
 302   }
 303   logModules = NULL;
 304
 305   if (_pr_logLock) {
 306     PR_DestroyLock(_pr_logLock);
 307     _pr_logLock = NULL;
 308   }
 309 }
 310
 311 static void _PR_SetLogModuleLevel(PRLogModuleInfo* lm) {
 312   char* ev;
 313
 314   ev = PR_GetEnv("NSPR_LOG_MODULES");
 315   if (ev && ev[0]) {
 316     char module[64]; /* Security-Critical: If you change this
 317                       * size, you must also change the sscanf
 318                       * format string to be size-1.
 319                       */
 320     PRIntn evlen = strlen(ev), pos = 0;
 321     while (pos < evlen) {
 322       PRIntn level = 1, count = 0, delta = 0;
 323
 324       count = sscanf(
 325           &ev[pos],
 326           "%63[ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz0123456789_-"
 327           "]%n:%d%n",
 328           module, &delta, &level, &delta);
 329       pos += delta;
 330       if (count == 0) {
 331         break;
 332       }
 333
 334       /*
 335       ** If count == 2, then we got module and level. If count
 336       ** == 1, then level defaults to 1 (module enabled).
 337       */
 338       if (lm != NULL) {
 339         if ((strcasecmp(module, "all") == 0) ||
 340             (strcasecmp(module, lm->name) == 0)) {
 341           lm->level = (PRLogModuleLevel)level;
 342         }
 343       }
 344       count = sscanf(&ev[pos], " , %n", &delta);
 345       pos += delta;
 346       if (count == EOF) {
 347         break;
 348       }
 349     }
 350   }
 351 } /* end _PR_SetLogModuleLevel() */
 352
 353 PR_IMPLEMENT(PRLogModuleInfo*) PR_NewLogModule(const char* name) {
 354   PRLogModuleInfo* lm;
 355
 356   if (!_pr_initialized) {
 357     _PR_ImplicitInitialization();
 358   }
 359
 360   lm = PR_NEWZAP(PRLogModuleInfo);
 361   if (lm) {
 362     lm->name = strdup(name);
 363     lm->level = PR_LOG_NONE;
 364     lm->next = logModules;
 365     logModules = lm;
 366     _PR_SetLogModuleLevel(lm);
 367   }
 368   return lm;
 369 }
 370
 371 PR_IMPLEMENT(PRBool) PR_SetLogFile(const char* file) {
 372 #ifdef _PR_USE_STDIO_FOR_LOGGING
 373   FILE* newLogFile;
 374
 375 #  ifdef XP_PC
 376   if (strcmp(file, "WinDebug") == 0) {
 377     newLogFile = WIN32_DEBUG_FILE;
 378   } else
 379 #  endif
 380   {
 381     const char* mode = appendToLog ? "a" : "w";
 382     newLogFile = fopen(file, mode);
 383     if (!newLogFile) {
 384       return PR_FALSE;
 385     }
 386
 387 #  ifndef WINCE /* _IONBF does not exist in the Windows Mobile 6 SDK. */
 388     /* We do buffering ourselves. */
 389     setvbuf(newLogFile, NULL, _IONBF, 0);
 390 #  endif
 391   }
 392   if (logFile && logFile != stdout && logFile != stderr
 393 #  ifdef XP_PC
 394       && logFile != WIN32_DEBUG_FILE
 395 #  endif
 396   ) {
 397     fclose(logFile);
 398   }
 399   logFile = newLogFile;
 400   return PR_TRUE;
 401 #else
 402   PRFileDesc* newLogFile;
 403   PRIntn flags = PR_WRONLY | PR_CREATE_FILE;
 404   if (appendToLog) {
 405     flags |= PR_APPEND;
 406   } else {
 407     flags |= PR_TRUNCATE;
 408   }
 409
 410   newLogFile = PR_Open(file, flags, 0666);
 411   if (newLogFile) {
 412     if (logFile && logFile != _pr_stdout && logFile != _pr_stderr) {
 413       PR_Close(logFile);
 414     }
 415     logFile = newLogFile;
 416   }
 417   return (PRBool)(newLogFile != 0);
 418 #endif /* _PR_USE_STDIO_FOR_LOGGING */
 419 }
 420
 421 PR_IMPLEMENT(void) PR_SetLogBuffering(PRIntn buffer_size) {
 422   PR_LogFlush();
 423
 424   if (logBuf) {
 425     PR_DELETE(logBuf);
 426   }
 427
 428   if (buffer_size >= LINE_BUF_SIZE) {
 429     logp = logBuf = (char*)PR_MALLOC(buffer_size);
 430     logEndp = logp + buffer_size;
 431   }
 432 }
 433
 434 PR_IMPLEMENT(void) PR_LogPrint(const char* fmt, ...) {
 435   va_list ap;
 436   char line[LINE_BUF_SIZE];
 437   char* line_long = NULL;
 438   PRUint32 nb_tid = 0, nb;
 439   PRThread* me;
 440   PRExplodedTime now;
 441
 442   if (!_pr_initialized) {
 443     _PR_ImplicitInitialization();
 444   }
 445
 446   if (!logFile) {
 447     return;
 448   }
 449
 450   if (outputTimeStamp) {
 451     PR_ExplodeTime(PR_Now(), PR_GMTParameters, &now);
 452     nb_tid = PR_snprintf(line, sizeof(line) - 1,
 453                          "%04d-%02d-%02d %02d:%02d:%02d.%06d UTC - ",
 454                          now.tm_year, now.tm_month + 1, now.tm_mday,
 455                          now.tm_hour, now.tm_min, now.tm_sec, now.tm_usec);
 456   }
 457
 458   me = PR_GetCurrentThread();
 459   nb_tid += PR_snprintf(line + nb_tid, sizeof(line) - nb_tid - 1, "%ld[%p]: ",
 460 #if defined(_PR_BTHREADS)
 461                         me, me);
 462 #else
 463                         me ? me->id : 0L, me);
 464 #endif
 465
 466   va_start(ap, fmt);
 467   nb = nb_tid + PR_vsnprintf(line + nb_tid, sizeof(line) - nb_tid - 1, fmt, ap);
 468   va_end(ap);
 469
 470   /*
 471    * Check if we might have run out of buffer space (in case we have a
 472    * long line), and malloc a buffer just this once.
 473    */
 474   if (nb == sizeof(line) - 2) {
 475     va_start(ap, fmt);
 476     line_long = PR_vsmprintf(fmt, ap);
 477     va_end(ap);
 478     /* If this failed, we'll fall back to writing the truncated line. */
 479   }
 480
 481   if (line_long) {
 482     nb = strlen(line_long);
 483     _PR_LOCK_LOG();
 484     if (logBuf != 0) {
 485       _PUT_LOG(logFile, logBuf, logp - logBuf);
 486       logp = logBuf;
 487     }
 488     /*
 489      * Write out the thread id (with an optional timestamp) and the
 490      * malloc'ed buffer.
 491      */
 492     _PUT_LOG(logFile, line, nb_tid);
 493     _PUT_LOG(logFile, line_long, nb);
 494     /* Ensure there is a trailing newline. */
 495     if (!nb || (line_long[nb - 1] != '\n')) {
 496       char eol[2];
 497       eol[0] = '\n';
 498       eol[1] = '\0';
 499       _PUT_LOG(logFile, eol, 1);
 500     }
 501     _PR_UNLOCK_LOG();
 502     PR_smprintf_free(line_long);
 503   } else {
 504     /* Ensure there is a trailing newline. */
 505     if (nb && (line[nb - 1] != '\n')) {
 506       line[nb++] = '\n';
 507       line[nb] = '\0';
 508     }
 509     _PR_LOCK_LOG();
 510     if (logBuf == 0) {
 511       _PUT_LOG(logFile, line, nb);
 512     } else {
 513       /* If nb can't fit into logBuf, write out logBuf first. */
 514       if (logp + nb > logEndp) {
 515         _PUT_LOG(logFile, logBuf, logp - logBuf);
 516         logp = logBuf;
 517       }
 518       /* nb is guaranteed to fit into logBuf. */
 519       memcpy(logp, line, nb);
 520       logp += nb;
 521     }
 522     _PR_UNLOCK_LOG();
 523   }
 524   PR_LogFlush();
 525 }
 526
 527 PR_IMPLEMENT(void) PR_LogFlush(void) {
 528   if (logBuf && logFile) {
 529     _PR_LOCK_LOG();
 530     if (logp > logBuf) {
 531       _PUT_LOG(logFile, logBuf, logp - logBuf);
 532       logp = logBuf;
 533     }
 534     _PR_UNLOCK_LOG();
 535   }
 536 }
 537
 538 PR_IMPLEMENT(void) PR_Abort(void) {
 539   PR_LogPrint("Aborting");
 540 #ifdef ANDROID
 541   __android_log_write(ANDROID_LOG_ERROR, "PRLog", "Aborting");
 542 #endif
 543   abort();
 544 }
 545
 546 PR_IMPLEMENT(void) PR_Assert(const char* s, const char* file, PRIntn ln) {
 547   PR_LogPrint("Assertion failure: %s, at %s:%d\n", s, file, ln);
 548   fprintf(stderr, "Assertion failure: %s, at %s:%d\n", s, file, ln);
 549   fflush(stderr);
 550 #ifdef WIN32
 551   DebugBreak();
 552 #elif defined(ANDROID)
 553   __android_log_assert(NULL, "PRLog", "Assertion failure: %s, at %s:%d\n", s,
 554                        file, ln);
 555 #endif
 556   abort();
 557 }