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 */
FileLoggerPrintf(PLogger * self,const LCHAR * format,...)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
FileLoggerFlush(PLogger * self)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 */
FileLoggerDestroy(PLogger * self)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
createPFileLogger(PFile * fp,PLogger ** logger)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 */
PLogInit(PLogger * logger,unsigned int logLevel)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
PLogIsInitialized(ESR_BOOL * isInit)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
PLogIsLocked(ESR_BOOL * isLocked)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 */
PLogShutdown()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
PLogGetLevel(unsigned int * logLevel)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
PLogSetLevel(unsigned int logLevel)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
logIt(const LCHAR * format,va_list args,ESR_BOOL showStackTrace)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 */
PLogMessage(const char * msg,...)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 */
PLogError(const char * msg,...)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
PLogCreateFileLogger(PFile * file,PLogger ** logger)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 */
PLogCreateCircularFileLogger(const LCHAR * filename,unsigned int maxsize,PLogger ** logger)526 ESR_ReturnCode PLogCreateCircularFileLogger(const LCHAR *filename,
527 unsigned int maxsize,
528 PLogger **logger)
529 {
530 return ESR_NOT_SUPPORTED;
531 }
532
533
PLogSetFormat(LOG_OUTPUT_FORMAT format)534 ESR_ReturnCode PLogSetFormat(LOG_OUTPUT_FORMAT format)
535 {
536 GlogFormat = format;
537 return ESR_SUCCESS;
538 }
539