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