• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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     LOGE ( 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