1 /*---------------------------------------------------------------------------* 2 * plog.c * 3 * * 4 * Copyright 2007, 2008 Nuance Communciations, Inc. * 5 * * 6 * Licensed under the Apache License, Version 2.0 (the 'License'); * 7 * you may not use this file except in compliance with the License. * 8 * * 9 * You may obtain a copy of the License at * 10 * http://www.apache.org/licenses/LICENSE-2.0 * 11 * * 12 * Unless required by applicable law or agreed to in writing, software * 13 * distributed under the License is distributed on an 'AS IS' BASIS, * 14 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * 15 * See the License for the specific language governing permissions and * 16 * limitations under the License. * 17 * * 18 *---------------------------------------------------------------------------*/ 19 20 21 #include <stdio.h> 22 #include <stdarg.h> 23 #include "PFileSystem.h" 24 #include "ptypes.h" 25 #include "plog.h" 26 #include "pmemory.h" 27 #include "pstdio.h" 28 #include "ptimestamp.h" 29 #include "passert.h" 30 #ifdef USE_STACKTRACE 31 #include "PStackTrace.h" 32 #endif 33 34 #ifdef USE_THREAD 35 #include "ptrd.h" 36 #include "pmutex.h" 37 #endif 38 39 40 #if defined (ANDROID) 41 #if defined (HAVE_ANDROID_OS) 42 #define LOG_TAG "Srec" 43 #include <utils/Log.h> 44 #endif 45 #endif 46 47 #include "phashtable.h" 48 49 #define MTAG __FILE__ 50 51 #define FILTER_MSG_1 "ESR_BUFFER_OVERFLOW" 52 #define FILTER_MSG_1_SIZE ( sizeof ( FILTER_MSG_1 ) - 1 ) 53 54 #define FILTER_MSG_2 "ESR_NO_MATCH_ERROR" 55 #define FILTER_MSG_2_SIZE ( sizeof ( FILTER_MSG_2 ) - 1 ) 56 57 static unsigned int GlogLevel = 0; 58 static PLogger *Glogger = NULL; 59 static LOG_OUTPUT_FORMAT GlogFormat = LOG_OUTPUT_FORMAT_MODULE_NAME | 60 LOG_OUTPUT_FORMAT_DATE_TIME; 61 /** 62 * Used to detect endless recursion where the PLog module calls itself. 63 */ 64 static ESR_BOOL locked = ESR_FALSE; 65 #ifdef USE_THREAD 66 67 static PtrdMutex* Gmutex = NULL; 68 #endif 69 70 typedef struct FileLogger_t 71 { 72 PLogger base; 73 PFile* fp; 74 } 75 FileLogger; 76 77 /** 78 * Prints and formats a message to the log. 79 * 80 * @param self the PLogger. 81 * 82 * @param format the format string specifying the next arguments (a la 83 * printf). 84 * 85 * @param args variable argument list. 86 * 87 * @return The number of bytes written to the PLogger or -1 if an error 88 * occurs. 89 */ 90 static ESR_ReturnCode FileLoggerPrintf(PLogger *self, const LCHAR *format, ...) 91 { 92 FileLogger *p = STATIC_CAST(self, FileLogger, base); 93 ESR_ReturnCode rc; 94 va_list args; 95 96 va_start(args, format); 97 rc = pvfprintf(p->fp, format, args); 98 va_end(args); 99 return rc; 100 } 101 102 static ESR_ReturnCode FileLoggerFlush(PLogger *self) 103 { 104 FileLogger *p = STATIC_CAST(self, FileLogger, base); 105 return pfflush(p->fp) == 0 ? ESR_SUCCESS : ESR_FATAL_ERROR; 106 } 107 108 109 /** 110 * Destroys the logger. This function is responsible to deallocate any 111 * resources used by the logger. In particular, if buffering is internally 112 * used, it needs to flush the buffer. 113 */ 114 static void FileLoggerDestroy(PLogger *self) 115 { 116 FileLogger *p = STATIC_CAST(self, FileLogger, base); 117 pfflush(p->fp); 118 119 if (p->fp != PSTDERR && p->fp != PSTDOUT) 120 pfclose(p->fp); 121 FREE(p); 122 } 123 124 static ESR_ReturnCode createPFileLogger(PFile* fp, PLogger** logger) 125 { 126 FileLogger* fileLogger; 127 128 if (fp == NULL) 129 return ESR_INVALID_ARGUMENT; 130 fileLogger = NEW(FileLogger, MTAG); 131 if (fileLogger == NULL) 132 return ESR_OUT_OF_MEMORY; 133 134 fileLogger->base.printf = FileLoggerPrintf; 135 fileLogger->base.flush = FileLoggerFlush; 136 fileLogger->base.destroy = FileLoggerDestroy; 137 fileLogger->fp = fp; 138 139 *logger = &fileLogger->base; 140 return ESR_SUCCESS; 141 } 142 143 /** 144 * Initializes the LOG library. This function must be called before any 145 * logging can take place. 146 * 147 * @param logger The logger to be used to output the messages. If NULL, then 148 * logging goes to PSTDERR. @param logLevel The level of logging requested. 149 * 150 * @return ESR_SUCCESS if success, anything else if an error occurs. 151 * 152 */ 153 ESR_ReturnCode PLogInit(PLogger *logger, unsigned int logLevel) 154 { 155 ESR_ReturnCode rc = ESR_SUCCESS; 156 157 if (Glogger != NULL) 158 return ESR_INVALID_STATE; 159 160 GlogLevel = logLevel; 161 162 #ifdef USE_THREAD 163 if ((rc = PtrdMutexCreate(&Gmutex)) != ESR_SUCCESS) 164 return rc; 165 #endif 166 167 if (logger != NULL) 168 Glogger = logger; 169 else 170 { 171 rc = createPFileLogger(PSTDERR, &Glogger); 172 if (rc != ESR_SUCCESS) 173 goto CLEANUP; 174 } 175 176 return rc; 177 CLEANUP: 178 #ifdef USE_THREAD 179 if (Gmutex != NULL) 180 { 181 PtrdMutexDestroy(Gmutex); 182 Gmutex = NULL; 183 } 184 #endif 185 return rc; 186 } 187 188 ESR_ReturnCode PLogIsInitialized(ESR_BOOL* isInit) 189 { 190 if (isInit == NULL) 191 return ESR_INVALID_STATE; 192 *isInit = Glogger != NULL; 193 return ESR_SUCCESS; 194 } 195 196 ESR_ReturnCode PLogIsLocked(ESR_BOOL* isLocked) 197 { 198 if (isLocked == NULL) 199 return ESR_INVALID_STATE; 200 *isLocked = locked; 201 return ESR_SUCCESS; 202 } 203 204 /** 205 * Shutdowns the LOG library. Once this function is called, no logging activity can be performed. 206 * Also, the logger that was given to pLogInit is destroyed. 207 * 208 * @return ESR_SUCCESS if success, anything else if an error occurs. 209 * 210 */ 211 ESR_ReturnCode PLogShutdown() 212 { 213 ESR_ReturnCode rc = ESR_SUCCESS; 214 215 if (Glogger == NULL) 216 return ESR_INVALID_STATE; 217 218 #ifdef USE_THREAD 219 if ((rc = PtrdMutexDestroy(Gmutex)) != ESR_SUCCESS) 220 return rc; 221 Gmutex = NULL; 222 #endif 223 224 if (Glogger->flush != NULL) 225 Glogger->flush(Glogger); 226 Glogger->destroy(Glogger); 227 Glogger = NULL; 228 return rc; 229 } 230 231 ESR_ReturnCode PLogGetLevel(unsigned int *logLevel) 232 { 233 if (Glogger == NULL) 234 return ESR_INVALID_STATE; 235 if (logLevel == NULL) 236 return ESR_INVALID_ARGUMENT; 237 238 *logLevel = GlogLevel; 239 return ESR_SUCCESS; 240 } 241 242 ESR_ReturnCode PLogSetLevel(unsigned int logLevel) 243 { 244 if (Glogger == NULL) 245 return ESR_INVALID_STATE; 246 247 GlogLevel = logLevel; 248 return ESR_SUCCESS; 249 } 250 251 #define TIME_BUF_SIZE 24 252 #define TIME_FORMAT L("%Y/%m/%d %H:%M:%S") 253 #define PLOG_PANIC(x, rc) \ 254 do \ 255 { \ 256 { \ 257 pfprintf(PSTDERR, L("[%s:%d] %s failed with %s\n"), __FILE__, __LINE__, x, ESR_rc2str(rc)); \ 258 pfflush(PSTDERR); \ 259 } \ 260 } while (0) 261 262 static ESR_ReturnCode logIt(const LCHAR *format, va_list args, ESR_BOOL showStackTrace) 263 { 264 ESR_ReturnCode rc = ESR_SUCCESS; 265 ESR_ReturnCode flushRC = ESR_SUCCESS; 266 #ifdef USE_STACKTRACE 267 #define BUFFER_SIZE P_MAX_STACKTRACE + 2000 268 #else 269 #define BUFFER_SIZE 2000 270 #endif 271 LCHAR buffer[BUFFER_SIZE] = L(""); 272 273 // TODO: Remove once logging subsystem supports "warn" level 274 if (strstr(format, "ESR_BUFFER_OVERFLOW")==format) 275 return ESR_SUCCESS; 276 277 #ifdef USE_STACKTRACE 278 if (Glogger == NULL) 279 { 280 /* 281 * There are three possible scenerios for why logging would occur although the PLog module 282 * is uninitialized: 283 * 284 * 1) The code fails before PLog is initialized (perhaps in other portable components) 285 * 2) The user forgets to initialize the PLog module 286 * 3) The code fails after PLog is uninitialized (on shutdown) 287 * 288 * We do our best by logging any errors but this might result in the memory leak of 289 * the PStackTrace module in case 3. 290 */ 291 rc = PStackTraceCreate(); 292 if (rc != ESR_SUCCESS) 293 { 294 PLOG_PANIC(L("PStackTraceCreate"), rc); 295 goto CLEANUP; 296 } 297 } 298 else 299 { 300 #ifdef USE_THREAD 301 rc = PtrdMutexLock(Gmutex); 302 if (rc != ESR_SUCCESS) 303 return rc; 304 #endif 305 } 306 if (locked) 307 return ESR_INVALID_STATE; 308 locked = ESR_TRUE; 309 310 if (GlogFormat & LOG_OUTPUT_FORMAT_DATE_TIME) 311 { 312 PTimeStamp now; 313 struct tm* loctime; 314 LCHAR timeStr[TIME_BUF_SIZE]; 315 size_t timeStrSize; 316 317 PTimeStampSet(&now); 318 loctime = localtime(&now.secs); 319 timeStrSize = LSTRFTIME(timeStr, TIME_BUF_SIZE, TIME_FORMAT, loctime); 320 passert(timeStrSize == (TIME_BUF_SIZE - 5)); 321 psprintf(timeStr + (TIME_BUF_SIZE - 5), ".%03hu", now.msecs); 322 323 psprintf(buffer + LSTRLEN(buffer), L("%s|"), timeStr); 324 passert(LSTRLEN(buffer) < BUFFER_SIZE); 325 } 326 327 if (GlogFormat & LOG_OUTPUT_FORMAT_THREAD_ID) 328 { 329 rc = psprintf(buffer + LSTRLEN(buffer), L("trd=%u|"), PtrdGetCurrentThreadId()); 330 passert(LSTRLEN(buffer) < BUFFER_SIZE); 331 } 332 333 if (GlogFormat & LOG_OUTPUT_FORMAT_MODULE_NAME && showStackTrace) 334 { 335 size_t len = P_MAX_STACKTRACE; 336 LCHAR text[P_MAX_STACKTRACE]; 337 LCHAR* index; 338 size_t i; 339 340 rc = PStackTraceGetValue((LCHAR*) & text, &len); 341 if (rc == ESR_SUCCESS) 342 { 343 for (i = 0; i < 2; ++i) 344 { 345 rc = PStackTracePopLevel((LCHAR*) & text); 346 if (rc != ESR_SUCCESS) 347 { 348 PLOG_PANIC(L("PStackTracePopLevel"), rc); 349 goto CLEANUP; 350 } 351 } 352 index = text; 353 while (index) 354 { 355 index = LSTRSTR(index, L(" at\n")); 356 if (index != NULL) 357 { 358 *(index + 1) = L('<'); 359 *(index + 2) = L('-'); 360 *(index + 3) = L(' '); 361 } 362 } 363 } 364 else if (rc == ESR_NOT_SUPPORTED) 365 LSTRCPY(text, L("")); 366 else if (rc != ESR_SUCCESS) 367 { 368 PLOG_PANIC(L("PStackTraceGetValue"), rc); 369 goto CLEANUP; 370 } 371 rc = psprintf(buffer + LSTRLEN(buffer), L("Module=%s|"), text); 372 passert(LSTRLEN(buffer) < BUFFER_SIZE); 373 } 374 375 pvsprintf(buffer + LSTRLEN(buffer), format, args); 376 #else 377 pvsprintf(buffer + LSTRLEN(buffer), format, args); 378 #endif 379 passert(LSTRLEN(buffer) < BUFFER_SIZE); 380 381 psprintf(buffer + LSTRLEN(buffer), L("\n")); 382 passert(LSTRLEN(buffer) < BUFFER_SIZE); 383 384 if (Glogger != NULL) 385 { 386 rc = Glogger->printf(Glogger, L("%s"), buffer); 387 if (rc != ESR_SUCCESS) 388 goto CLEANUP; 389 flushRC = Glogger->flush(Glogger); 390 } 391 else 392 { 393 /* We need to log but the logging module is disabled or is locked so we output to stderr instead */ 394 { 395 pfprintf(PSTDERR, L("%s"), buffer); 396 pfflush(PSTDERR); 397 } 398 } 399 locked = ESR_FALSE; 400 #ifdef USE_THREAD 401 PtrdMutexUnlock(Gmutex); 402 #endif 403 return flushRC; 404 CLEANUP: 405 if (Glogger != NULL && Glogger->flush != NULL) 406 flushRC = Glogger->flush(Glogger); 407 locked = ESR_FALSE; 408 #ifdef USE_THREAD 409 PtrdMutexUnlock(Gmutex); 410 #endif 411 return rc != ESR_SUCCESS ? rc : flushRC; 412 } 413 414 /** 415 * Conditionally PLogs a message. The message is logged only if module is enabled. 416 * 417 * @param msg The message format specification (ala printf). 418 * @return ESR_SUCCESS if success, anything else if an error occurs. 419 */ 420 ESR_ReturnCode PLogMessage(const char* msg, ...) 421 { 422 va_list args; 423 ESR_ReturnCode rc; 424 #if USE_STACKTRACE 425 size_t depth; 426 #endif 427 428 #if defined (ANDROID) 429 #if defined (HAVE_ANDROID_OS) 430 return ( ESR_SUCCESS );/* Get rid of this for phone device */ 431 #endif 432 #endif 433 434 if (Glogger == NULL) 435 return ESR_INVALID_STATE; 436 #ifdef USE_STACKTRACE 437 return ESR_SUCCESS; 438 rc = PStackTraceGetDepth(&depth); 439 440 if (rc == ESR_NOT_SUPPORTED) 441 { 442 /* Debugging symbols are missing */ 443 return ESR_SUCCESS; 444 } 445 else if (rc != ESR_SUCCESS) 446 { 447 pfprintf(PSTDERR, L("PStackTraceGetDepth"), ESR_rc2str(rc)); 448 goto CLEANUP; 449 } 450 451 /* Remove PLogMessage() from depth */ 452 --depth; 453 if (GlogLevel < depth) 454 return ESR_SUCCESS; 455 #endif 456 457 va_start(args, msg); 458 rc = logIt(msg, args, ESR_FALSE); 459 va_end(args); 460 return rc; 461 #if USE_STACKTRACE 462 CLEANUP: 463 return rc; 464 #endif 465 } 466 467 468 /** 469 * Unconditionally logs an error message. 470 * 471 * @param msg The message format specification (ala printf). 472 * @return ESR_SUCCESS if success, anything else if an error occurs. 473 */ 474 ESR_ReturnCode PLogError(const char* msg, ...) 475 { 476 va_list args; 477 ESR_ReturnCode rc; 478 #if defined (ANDROID) 479 #if defined (HAVE_ANDROID_OS) 480 char log_text [2048]; 481 #endif 482 #endif 483 484 va_start(args, msg); 485 #if defined (ANDROID) 486 #if defined (HAVE_ANDROID_OS) 487 pvsprintf ( log_text, msg, args); 488 /* We need to disable some error messages because they are frequently not 489 * errors but due to sloppy use of some functions. This prevents us from 490 * getting flooded with bad error messages. SteveR 491 */ 492 if ( ( strncmp ( log_text, FILTER_MSG_1, FILTER_MSG_1_SIZE ) != 0 ) && 493 ( strncmp ( log_text, FILTER_MSG_2, FILTER_MSG_2_SIZE ) != 0 ) ) 494 { 495 ALOGE ("%s", log_text ); 496 } 497 rc = 0; 498 #else 499 rc = logIt(msg, args, ESR_TRUE); 500 #endif 501 #else 502 rc = logIt(msg, args, ESR_TRUE); 503 #endif 504 va_end(args); 505 506 return rc; 507 } 508 509 510 511 ESR_ReturnCode PLogCreateFileLogger(PFile* file, PLogger **logger) 512 { 513 if (logger == NULL || file == NULL) 514 return ESR_INVALID_ARGUMENT; 515 516 return createPFileLogger(file, logger); 517 } 518 519 /** 520 * Creates a logger that logs to a circular file. 521 * 522 * @param filename The name of the file to be created. 523 * @param maxsize The maximum number of bytes that the file may have. 524 * @param logger logger handle receiving the created logger. 525 */ 526 ESR_ReturnCode PLogCreateCircularFileLogger(const LCHAR *filename, 527 unsigned int maxsize, 528 PLogger **logger) 529 { 530 return ESR_NOT_SUPPORTED; 531 } 532 533 534 ESR_ReturnCode PLogSetFormat(LOG_OUTPUT_FORMAT format) 535 { 536 GlogFormat = format; 537 return ESR_SUCCESS; 538 } 539