/*---------------------------------------------------------------------------*
* plog.c *
* *
* Copyright 2007, 2008 Nuance Communciations, Inc. *
* *
* Licensed under the Apache License, Version 2.0 (the 'License'); *
* you may not use this file except in compliance with the License. *
* *
* You may obtain a copy of the License at *
* http://www.apache.org/licenses/LICENSE-2.0 *
* *
* Unless required by applicable law or agreed to in writing, software *
* distributed under the License is distributed on an 'AS IS' BASIS, *
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. *
* See the License for the specific language governing permissions and *
* limitations under the License. *
* *
*---------------------------------------------------------------------------*/
#include <stdio.h>
#include <stdarg.h>
#include "PFileSystem.h"
#include "ptypes.h"
#include "plog.h"
#include "pmemory.h"
#include "pstdio.h"
#include "ptimestamp.h"
#include "passert.h"
#ifdef USE_STACKTRACE
#include "PStackTrace.h"
#endif
#ifdef USE_THREAD
#include "ptrd.h"
#include "pmutex.h"
#endif
#if defined (ANDROID)
#if defined (HAVE_ANDROID_OS)
#define LOG_TAG "Srec"
#include <utils/Log.h>
#endif
#endif
#include "phashtable.h"
#define MTAG __FILE__
#define FILTER_MSG_1 "ESR_BUFFER_OVERFLOW"
#define FILTER_MSG_1_SIZE ( sizeof ( FILTER_MSG_1 ) - 1 )
#define FILTER_MSG_2 "ESR_NO_MATCH_ERROR"
#define FILTER_MSG_2_SIZE ( sizeof ( FILTER_MSG_2 ) - 1 )
static unsigned int GlogLevel = 0;
static PLogger *Glogger = NULL;
static LOG_OUTPUT_FORMAT GlogFormat = LOG_OUTPUT_FORMAT_MODULE_NAME |
LOG_OUTPUT_FORMAT_DATE_TIME;
/**
* Used to detect endless recursion where the PLog module calls itself.
*/
static ESR_BOOL locked = ESR_FALSE;
#ifdef USE_THREAD
static PtrdMutex* Gmutex = NULL;
#endif
typedef struct FileLogger_t
{
PLogger base;
PFile* fp;
}
FileLogger;
/**
* Prints and formats a message to the log.
*
* @param self the PLogger.
*
* @param format the format string specifying the next arguments (a la
* printf).
*
* @param args variable argument list.
*
* @return The number of bytes written to the PLogger or -1 if an error
* occurs.
*/
static ESR_ReturnCode FileLoggerPrintf(PLogger *self, const LCHAR *format, ...)
{
FileLogger *p = STATIC_CAST(self, FileLogger, base);
ESR_ReturnCode rc;
va_list args;
va_start(args, format);
rc = pvfprintf(p->fp, format, args);
va_end(args);
return rc;
}
static ESR_ReturnCode FileLoggerFlush(PLogger *self)
{
FileLogger *p = STATIC_CAST(self, FileLogger, base);
return pfflush(p->fp) == 0 ? ESR_SUCCESS : ESR_FATAL_ERROR;
}
/**
* Destroys the logger. This function is responsible to deallocate any
* resources used by the logger. In particular, if buffering is internally
* used, it needs to flush the buffer.
*/
static void FileLoggerDestroy(PLogger *self)
{
FileLogger *p = STATIC_CAST(self, FileLogger, base);
pfflush(p->fp);
if (p->fp != PSTDERR && p->fp != PSTDOUT)
pfclose(p->fp);
FREE(p);
}
static ESR_ReturnCode createPFileLogger(PFile* fp, PLogger** logger)
{
FileLogger* fileLogger;
if (fp == NULL)
return ESR_INVALID_ARGUMENT;
fileLogger = NEW(FileLogger, MTAG);
if (fileLogger == NULL)
return ESR_OUT_OF_MEMORY;
fileLogger->base.printf = FileLoggerPrintf;
fileLogger->base.flush = FileLoggerFlush;
fileLogger->base.destroy = FileLoggerDestroy;
fileLogger->fp = fp;
*logger = &fileLogger->base;
return ESR_SUCCESS;
}
/**
* Initializes the LOG library. This function must be called before any
* logging can take place.
*
* @param logger The logger to be used to output the messages. If NULL, then
* logging goes to PSTDERR. @param logLevel The level of logging requested.
*
* @return ESR_SUCCESS if success, anything else if an error occurs.
*
*/
ESR_ReturnCode PLogInit(PLogger *logger, unsigned int logLevel)
{
ESR_ReturnCode rc = ESR_SUCCESS;
if (Glogger != NULL)
return ESR_INVALID_STATE;
GlogLevel = logLevel;
#ifdef USE_THREAD
if ((rc = PtrdMutexCreate(&Gmutex)) != ESR_SUCCESS)
return rc;
#endif
if (logger != NULL)
Glogger = logger;
else
{
rc = createPFileLogger(PSTDERR, &Glogger);
if (rc != ESR_SUCCESS)
goto CLEANUP;
}
return rc;
CLEANUP:
#ifdef USE_THREAD
if (Gmutex != NULL)
{
PtrdMutexDestroy(Gmutex);
Gmutex = NULL;
}
#endif
return rc;
}
ESR_ReturnCode PLogIsInitialized(ESR_BOOL* isInit)
{
if (isInit == NULL)
return ESR_INVALID_STATE;
*isInit = Glogger != NULL;
return ESR_SUCCESS;
}
ESR_ReturnCode PLogIsLocked(ESR_BOOL* isLocked)
{
if (isLocked == NULL)
return ESR_INVALID_STATE;
*isLocked = locked;
return ESR_SUCCESS;
}
/**
* Shutdowns the LOG library. Once this function is called, no logging activity can be performed.
* Also, the logger that was given to pLogInit is destroyed.
*
* @return ESR_SUCCESS if success, anything else if an error occurs.
*
*/
ESR_ReturnCode PLogShutdown()
{
ESR_ReturnCode rc = ESR_SUCCESS;
if (Glogger == NULL)
return ESR_INVALID_STATE;
#ifdef USE_THREAD
if ((rc = PtrdMutexDestroy(Gmutex)) != ESR_SUCCESS)
return rc;
Gmutex = NULL;
#endif
if (Glogger->flush != NULL)
Glogger->flush(Glogger);
Glogger->destroy(Glogger);
Glogger = NULL;
return rc;
}
ESR_ReturnCode PLogGetLevel(unsigned int *logLevel)
{
if (Glogger == NULL)
return ESR_INVALID_STATE;
if (logLevel == NULL)
return ESR_INVALID_ARGUMENT;
*logLevel = GlogLevel;
return ESR_SUCCESS;
}
ESR_ReturnCode PLogSetLevel(unsigned int logLevel)
{
if (Glogger == NULL)
return ESR_INVALID_STATE;
GlogLevel = logLevel;
return ESR_SUCCESS;
}
#define TIME_BUF_SIZE 24
#define TIME_FORMAT L("%Y/%m/%d %H:%M:%S")
#define PLOG_PANIC(x, rc) \
do \
{ \
{ \
pfprintf(PSTDERR, L("[%s:%d] %s failed with %s\n"), __FILE__, __LINE__, x, ESR_rc2str(rc)); \
pfflush(PSTDERR); \
} \
} while (0)
static ESR_ReturnCode logIt(const LCHAR *format, va_list args, ESR_BOOL showStackTrace)
{
ESR_ReturnCode rc = ESR_SUCCESS;
ESR_ReturnCode flushRC = ESR_SUCCESS;
#ifdef USE_STACKTRACE
#define BUFFER_SIZE P_MAX_STACKTRACE + 2000
#else
#define BUFFER_SIZE 2000
#endif
LCHAR buffer[BUFFER_SIZE] = L("");
// TODO: Remove once logging subsystem supports "warn" level
if (strstr(format, "ESR_BUFFER_OVERFLOW")==format)
return ESR_SUCCESS;
#ifdef USE_STACKTRACE
if (Glogger == NULL)
{
/*
* There are three possible scenerios for why logging would occur although the PLog module
* is uninitialized:
*
* 1) The code fails before PLog is initialized (perhaps in other portable components)
* 2) The user forgets to initialize the PLog module
* 3) The code fails after PLog is uninitialized (on shutdown)
*
* We do our best by logging any errors but this might result in the memory leak of
* the PStackTrace module in case 3.
*/
rc = PStackTraceCreate();
if (rc != ESR_SUCCESS)
{
PLOG_PANIC(L("PStackTraceCreate"), rc);
goto CLEANUP;
}
}
else
{
#ifdef USE_THREAD
rc = PtrdMutexLock(Gmutex);
if (rc != ESR_SUCCESS)
return rc;
#endif
}
if (locked)
return ESR_INVALID_STATE;
locked = ESR_TRUE;
if (GlogFormat & LOG_OUTPUT_FORMAT_DATE_TIME)
{
PTimeStamp now;
struct tm* loctime;
LCHAR timeStr[TIME_BUF_SIZE];
size_t timeStrSize;
PTimeStampSet(&now);
loctime = localtime(&now.secs);
timeStrSize = LSTRFTIME(timeStr, TIME_BUF_SIZE, TIME_FORMAT, loctime);
passert(timeStrSize == (TIME_BUF_SIZE - 5));
psprintf(timeStr + (TIME_BUF_SIZE - 5), ".%03hu", now.msecs);
psprintf(buffer + LSTRLEN(buffer), L("%s|"), timeStr);
passert(LSTRLEN(buffer) < BUFFER_SIZE);
}
if (GlogFormat & LOG_OUTPUT_FORMAT_THREAD_ID)
{
rc = psprintf(buffer + LSTRLEN(buffer), L("trd=%u|"), PtrdGetCurrentThreadId());
passert(LSTRLEN(buffer) < BUFFER_SIZE);
}
if (GlogFormat & LOG_OUTPUT_FORMAT_MODULE_NAME && showStackTrace)
{
size_t len = P_MAX_STACKTRACE;
LCHAR text[P_MAX_STACKTRACE];
LCHAR* index;
size_t i;
rc = PStackTraceGetValue((LCHAR*) & text, &len);
if (rc == ESR_SUCCESS)
{
for (i = 0; i < 2; ++i)
{
rc = PStackTracePopLevel((LCHAR*) & text);
if (rc != ESR_SUCCESS)
{
PLOG_PANIC(L("PStackTracePopLevel"), rc);
goto CLEANUP;
}
}
index = text;
while (index)
{
index = LSTRSTR(index, L(" at\n"));
if (index != NULL)
{
*(index + 1) = L('<');
*(index + 2) = L('-');
*(index + 3) = L(' ');
}
}
}
else if (rc == ESR_NOT_SUPPORTED)
LSTRCPY(text, L(""));
else if (rc != ESR_SUCCESS)
{
PLOG_PANIC(L("PStackTraceGetValue"), rc);
goto CLEANUP;
}
rc = psprintf(buffer + LSTRLEN(buffer), L("Module=%s|"), text);
passert(LSTRLEN(buffer) < BUFFER_SIZE);
}
pvsprintf(buffer + LSTRLEN(buffer), format, args);
#else
pvsprintf(buffer + LSTRLEN(buffer), format, args);
#endif
passert(LSTRLEN(buffer) < BUFFER_SIZE);
psprintf(buffer + LSTRLEN(buffer), L("\n"));
passert(LSTRLEN(buffer) < BUFFER_SIZE);
if (Glogger != NULL)
{
rc = Glogger->printf(Glogger, L("%s"), buffer);
if (rc != ESR_SUCCESS)
goto CLEANUP;
flushRC = Glogger->flush(Glogger);
}
else
{
/* We need to log but the logging module is disabled or is locked so we output to stderr instead */
{
pfprintf(PSTDERR, L("%s"), buffer);
pfflush(PSTDERR);
}
}
locked = ESR_FALSE;
#ifdef USE_THREAD
PtrdMutexUnlock(Gmutex);
#endif
return flushRC;
CLEANUP:
if (Glogger != NULL && Glogger->flush != NULL)
flushRC = Glogger->flush(Glogger);
locked = ESR_FALSE;
#ifdef USE_THREAD
PtrdMutexUnlock(Gmutex);
#endif
return rc != ESR_SUCCESS ? rc : flushRC;
}
/**
* Conditionally PLogs a message. The message is logged only if module is enabled.
*
* @param msg The message format specification (ala printf).
* @return ESR_SUCCESS if success, anything else if an error occurs.
*/
ESR_ReturnCode PLogMessage(const char* msg, ...)
{
va_list args;
ESR_ReturnCode rc;
#if USE_STACKTRACE
size_t depth;
#endif
#if defined (ANDROID)
#if defined (HAVE_ANDROID_OS)
return ( ESR_SUCCESS );/* Get rid of this for phone device */
#endif
#endif
if (Glogger == NULL)
return ESR_INVALID_STATE;
#ifdef USE_STACKTRACE
return ESR_SUCCESS;
rc = PStackTraceGetDepth(&depth);
if (rc == ESR_NOT_SUPPORTED)
{
/* Debugging symbols are missing */
return ESR_SUCCESS;
}
else if (rc != ESR_SUCCESS)
{
pfprintf(PSTDERR, L("PStackTraceGetDepth"), ESR_rc2str(rc));
goto CLEANUP;
}
/* Remove PLogMessage() from depth */
--depth;
if (GlogLevel < depth)
return ESR_SUCCESS;
#endif
va_start(args, msg);
rc = logIt(msg, args, ESR_FALSE);
va_end(args);
return rc;
#if USE_STACKTRACE
CLEANUP:
return rc;
#endif
}
/**
* Unconditionally logs an error message.
*
* @param msg The message format specification (ala printf).
* @return ESR_SUCCESS if success, anything else if an error occurs.
*/
ESR_ReturnCode PLogError(const char* msg, ...)
{
va_list args;
ESR_ReturnCode rc;
#if defined (ANDROID)
#if defined (HAVE_ANDROID_OS)
char log_text [2048];
#endif
#endif
va_start(args, msg);
#if defined (ANDROID)
#if defined (HAVE_ANDROID_OS)
pvsprintf ( log_text, msg, args);
/* We need to disable some error messages because they are frequently not
* errors but due to sloppy use of some functions. This prevents us from
* getting flooded with bad error messages. SteveR
*/
if ( ( strncmp ( log_text, FILTER_MSG_1, FILTER_MSG_1_SIZE ) != 0 ) &&
( strncmp ( log_text, FILTER_MSG_2, FILTER_MSG_2_SIZE ) != 0 ) )
{
LOGE ("%s", log_text );
}
rc = 0;
#else
rc = logIt(msg, args, ESR_TRUE);
#endif
#else
rc = logIt(msg, args, ESR_TRUE);
#endif
va_end(args);
return rc;
}
ESR_ReturnCode PLogCreateFileLogger(PFile* file, PLogger **logger)
{
if (logger == NULL || file == NULL)
return ESR_INVALID_ARGUMENT;
return createPFileLogger(file, logger);
}
/**
* Creates a logger that logs to a circular file.
*
* @param filename The name of the file to be created.
* @param maxsize The maximum number of bytes that the file may have.
* @param logger logger handle receiving the created logger.
*/
ESR_ReturnCode PLogCreateCircularFileLogger(const LCHAR *filename,
unsigned int maxsize,
PLogger **logger)
{
return ESR_NOT_SUPPORTED;
}
ESR_ReturnCode PLogSetFormat(LOG_OUTPUT_FORMAT format)
{
GlogFormat = format;
return ESR_SUCCESS;
}