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
57static unsigned int GlogLevel = 0;
58static PLogger *Glogger = NULL;
59static 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 */
64static ESR_BOOL locked = ESR_FALSE;
65#ifdef USE_THREAD
66
67static PtrdMutex* Gmutex = NULL;
68#endif
69
70typedef struct FileLogger_t
71{
72  PLogger base;
73  PFile* fp;
74}
75FileLogger;
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 */
90static 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
102static 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 */
114static 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
124static 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 */
153ESR_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;
177CLEANUP:
178#ifdef USE_THREAD
179  if (Gmutex != NULL)
180  {
181    PtrdMutexDestroy(Gmutex);
182    Gmutex = NULL;
183  }
184#endif
185  return rc;
186}
187
188ESR_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
196ESR_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 */
211ESR_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
231ESR_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
242ESR_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
262static 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;
404CLEANUP:
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 */
420ESR_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
462CLEANUP:
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 */
474ESR_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 ("%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
511ESR_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 */
526ESR_ReturnCode PLogCreateCircularFileLogger(const LCHAR *filename,
527    unsigned int maxsize,
528    PLogger **logger)
529{
530  return ESR_NOT_SUPPORTED;
531}
532
533
534ESR_ReturnCode PLogSetFormat(LOG_OUTPUT_FORMAT format)
535{
536  GlogFormat = format;
537  return ESR_SUCCESS;
538}
539