/** * WinPR: Windows Portable Runtime * WinPR Logger * * Copyright 2013 Marc-Andre Moreau * * 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. */ #ifdef HAVE_CONFIG_H #include "config.h" #endif #include #include #include #include #include #include #include #if defined(ANDROID) #include #include "../log.h" #endif #include "wlog.h" struct _wLogFilter { DWORD Level; LPSTR* Names; DWORD NameCount; }; typedef struct _wLogFilter wLogFilter; #define WLOG_FILTER_NOT_FILTERED -1 #define WLOG_FILTER_NOT_INITIALIZED -2 /** * References for general logging concepts: * * Short introduction to log4j: * http://logging.apache.org/log4j/1.2/manual.html * * logging - Logging facility for Python: * http://docs.python.org/2/library/logging.html */ LPCSTR WLOG_LEVELS[7] = { "TRACE", "DEBUG", "INFO", "WARN", "ERROR", "FATAL", "OFF" }; static INIT_ONCE _WLogInitialized = INIT_ONCE_STATIC_INIT; static DWORD g_FilterCount = 0; static wLogFilter* g_Filters = NULL; static wLog* g_RootLog = NULL; static wLog* WLog_New(LPCSTR name, wLog* rootLogger); static void WLog_Free(wLog* log); static LONG WLog_GetFilterLogLevel(wLog* log); static int WLog_ParseLogLevel(LPCSTR level); static BOOL WLog_ParseFilter(wLog* root, wLogFilter* filter, LPCSTR name); static BOOL WLog_ParseFilters(wLog* root); static wLog* WLog_Get_int(wLog* root, LPCSTR name); #if !defined(_WIN32) static void WLog_Uninit_(void) __attribute__((destructor)); #endif static void WLog_Uninit_(void) { DWORD index; wLog* child = NULL; wLog* root = g_RootLog; if (!root) return; for (index = 0; index < root->ChildrenCount; index++) { child = root->Children[index]; WLog_Free(child); } WLog_Free(root); g_RootLog = NULL; } static BOOL CALLBACK WLog_InitializeRoot(PINIT_ONCE InitOnce, PVOID Parameter, PVOID* Context) { char* env; DWORD nSize; DWORD logAppenderType; LPCSTR appender = "WLOG_APPENDER"; if (!(g_RootLog = WLog_New("", NULL))) return FALSE; g_RootLog->IsRoot = TRUE; logAppenderType = WLOG_APPENDER_CONSOLE; nSize = GetEnvironmentVariableA(appender, NULL, 0); if (nSize) { env = (LPSTR)malloc(nSize); if (!env) goto fail; if (GetEnvironmentVariableA(appender, env, nSize) != nSize - 1) { fprintf(stderr, "%s environment variable modified in my back", appender); free(env); goto fail; } if (_stricmp(env, "CONSOLE") == 0) logAppenderType = WLOG_APPENDER_CONSOLE; else if (_stricmp(env, "FILE") == 0) logAppenderType = WLOG_APPENDER_FILE; else if (_stricmp(env, "BINARY") == 0) logAppenderType = WLOG_APPENDER_BINARY; #ifdef HAVE_SYSLOG_H else if (_stricmp(env, "SYSLOG") == 0) logAppenderType = WLOG_APPENDER_SYSLOG; #endif /* HAVE_SYSLOG_H */ #ifdef HAVE_JOURNALD_H else if (_stricmp(env, "JOURNALD") == 0) logAppenderType = WLOG_APPENDER_JOURNALD; #endif else if (_stricmp(env, "UDP") == 0) logAppenderType = WLOG_APPENDER_UDP; free(env); } if (!WLog_SetLogAppenderType(g_RootLog, logAppenderType)) goto fail; if (!WLog_ParseFilters(g_RootLog)) goto fail; #if defined(_WIN32) atexit(WLog_Uninit_); #endif return TRUE; fail: WLog_Uninit_(); return FALSE; } static BOOL log_recursion(LPCSTR file, LPCSTR fkt, int line) { BOOL status = FALSE; char** msg = NULL; size_t used, i; void* bt = winpr_backtrace(20); #if defined(ANDROID) LPCSTR tag = WINPR_TAG("utils.wlog"); #endif if (!bt) return FALSE; msg = winpr_backtrace_symbols(bt, &used); if (!msg) goto out; #if defined(ANDROID) if (__android_log_print(ANDROID_LOG_FATAL, tag, "Recursion detected!!!") < 0) goto out; if (__android_log_print(ANDROID_LOG_FATAL, tag, "Check %s [%s:%d]", fkt, file, line) < 0) goto out; for (i = 0; i < used; i++) if (__android_log_print(ANDROID_LOG_FATAL, tag, "%zd: %s", i, msg[i]) < 0) goto out; #else if (fprintf(stderr, "[%s]: Recursion detected!\n", fkt) < 0) goto out; if (fprintf(stderr, "[%s]: Check %s:%d\n", fkt, file, line) < 0) goto out; for (i = 0; i < used; i++) if (fprintf(stderr, "%s: %" PRIuz ": %s\n", fkt, i, msg[i]) < 0) goto out; #endif status = TRUE; out: free(msg); winpr_backtrace_free(bt); return status; } static BOOL WLog_Write(wLog* log, wLogMessage* message) { BOOL status; wLogAppender* appender; appender = WLog_GetLogAppender(log); if (!appender) return FALSE; if (!appender->active) if (!WLog_OpenAppender(log)) return FALSE; if (!appender->WriteMessage) return FALSE; EnterCriticalSection(&appender->lock); if (appender->recursive) status = log_recursion(message->FileName, message->FunctionName, message->LineNumber); else { appender->recursive = TRUE; status = appender->WriteMessage(log, appender, message); appender->recursive = FALSE; } LeaveCriticalSection(&appender->lock); return status; } static BOOL WLog_WriteData(wLog* log, wLogMessage* message) { BOOL status; wLogAppender* appender; appender = WLog_GetLogAppender(log); if (!appender) return FALSE; if (!appender->active) if (!WLog_OpenAppender(log)) return FALSE; if (!appender->WriteDataMessage) return FALSE; EnterCriticalSection(&appender->lock); if (appender->recursive) status = log_recursion(message->FileName, message->FunctionName, message->LineNumber); else { appender->recursive = TRUE; status = appender->WriteDataMessage(log, appender, message); appender->recursive = FALSE; } LeaveCriticalSection(&appender->lock); return status; } static BOOL WLog_WriteImage(wLog* log, wLogMessage* message) { BOOL status; wLogAppender* appender; appender = WLog_GetLogAppender(log); if (!appender) return FALSE; if (!appender->active) if (!WLog_OpenAppender(log)) return FALSE; if (!appender->WriteImageMessage) return FALSE; EnterCriticalSection(&appender->lock); if (appender->recursive) status = log_recursion(message->FileName, message->FunctionName, message->LineNumber); else { appender->recursive = TRUE; status = appender->WriteImageMessage(log, appender, message); appender->recursive = FALSE; } LeaveCriticalSection(&appender->lock); return status; } static BOOL WLog_WritePacket(wLog* log, wLogMessage* message) { BOOL status; wLogAppender* appender; appender = WLog_GetLogAppender(log); if (!appender) return FALSE; if (!appender->active) if (!WLog_OpenAppender(log)) return FALSE; if (!appender->WritePacketMessage) return FALSE; EnterCriticalSection(&appender->lock); if (appender->recursive) status = log_recursion(message->FileName, message->FunctionName, message->LineNumber); else { appender->recursive = TRUE; status = appender->WritePacketMessage(log, appender, message); appender->recursive = FALSE; } LeaveCriticalSection(&appender->lock); return status; } BOOL WLog_PrintMessageVA(wLog* log, DWORD type, DWORD level, DWORD line, const char* file, const char* function, va_list args) { BOOL status = FALSE; wLogMessage message = { 0 }; message.Type = type; message.Level = level; message.LineNumber = line; message.FileName = file; message.FunctionName = function; switch (type) { case WLOG_MESSAGE_TEXT: message.FormatString = va_arg(args, const char*); if (!strchr(message.FormatString, '%')) { message.TextString = (LPSTR)message.FormatString; status = WLog_Write(log, &message); } else { char formattedLogMessage[WLOG_MAX_STRING_SIZE]; if (wvsnprintfx(formattedLogMessage, WLOG_MAX_STRING_SIZE - 1, message.FormatString, args) < 0) return FALSE; message.TextString = formattedLogMessage; status = WLog_Write(log, &message); } break; case WLOG_MESSAGE_DATA: message.Data = va_arg(args, void*); message.Length = va_arg(args, int); status = WLog_WriteData(log, &message); break; case WLOG_MESSAGE_IMAGE: message.ImageData = va_arg(args, void*); message.ImageWidth = va_arg(args, int); message.ImageHeight = va_arg(args, int); message.ImageBpp = va_arg(args, int); status = WLog_WriteImage(log, &message); break; case WLOG_MESSAGE_PACKET: message.PacketData = va_arg(args, void*); message.PacketLength = va_arg(args, int); message.PacketFlags = va_arg(args, int); status = WLog_WritePacket(log, &message); break; default: break; } return status; } BOOL WLog_PrintMessage(wLog* log, DWORD type, DWORD level, DWORD line, const char* file, const char* function, ...) { BOOL status; va_list args; va_start(args, function); status = WLog_PrintMessageVA(log, type, level, line, file, function, args); va_end(args); return status; } DWORD WLog_GetLogLevel(wLog* log) { if (!log) return WLOG_OFF; if (log->FilterLevel <= WLOG_FILTER_NOT_INITIALIZED) log->FilterLevel = WLog_GetFilterLogLevel(log); if (log->FilterLevel > WLOG_FILTER_NOT_FILTERED) return (DWORD)log->FilterLevel; else if (log->Level == WLOG_LEVEL_INHERIT) log->Level = WLog_GetLogLevel(log->Parent); return log->Level; } BOOL WLog_IsLevelActive(wLog* _log, DWORD _log_level) { DWORD level; if (!_log) return FALSE; level = WLog_GetLogLevel(_log); if (level == WLOG_OFF) return FALSE; return _log_level >= level; } BOOL WLog_SetStringLogLevel(wLog* log, LPCSTR level) { int lvl; if (!log || !level) return FALSE; lvl = WLog_ParseLogLevel(level); if (lvl < 0) return FALSE; return WLog_SetLogLevel(log, (DWORD)lvl); } static BOOL WLog_reset_log_filters(wLog* log) { DWORD x; if (!log) return FALSE; log->FilterLevel = WLOG_FILTER_NOT_INITIALIZED; for (x = 0; x < log->ChildrenCount; x++) { wLog* child = log->Children[x]; if (!WLog_reset_log_filters(child)) return FALSE; } return TRUE; } static BOOL WLog_AddStringLogFilters_int(wLog* root, LPCSTR filter) { DWORD pos; DWORD size; DWORD count; LPSTR p; LPSTR filterStr; LPSTR cp; wLogFilter* tmp; if (!filter) return FALSE; count = 1; p = (LPSTR)filter; while ((p = strchr(p, ',')) != NULL) { count++; p++; } pos = g_FilterCount; size = g_FilterCount + count; tmp = (wLogFilter*)realloc(g_Filters, size * sizeof(wLogFilter)); if (!tmp) return FALSE; g_Filters = tmp; cp = (LPSTR)_strdup(filter); if (!cp) return FALSE; p = cp; filterStr = cp; do { p = strchr(p, ','); if (p) *p = '\0'; if (pos < size) { if (!WLog_ParseFilter(root, &g_Filters[pos++], filterStr)) { free(cp); return FALSE; } } else break; if (p) { filterStr = p + 1; p++; } } while (p != NULL); g_FilterCount = size; free(cp); return WLog_reset_log_filters(root); } BOOL WLog_AddStringLogFilters(LPCSTR filter) { /* Ensure logger is initialized */ wLog* root = WLog_GetRoot(); return WLog_AddStringLogFilters_int(root, filter); } static BOOL WLog_UpdateInheritLevel(wLog* log, DWORD logLevel) { if (!log) return FALSE; if (log->inherit) { DWORD x; log->Level = logLevel; for (x = 0; x < log->ChildrenCount; x++) { wLog* child = log->Children[x]; if (!WLog_UpdateInheritLevel(child, logLevel)) return FALSE; } } return TRUE; } BOOL WLog_SetLogLevel(wLog* log, DWORD logLevel) { DWORD x; if (!log) return FALSE; if ((logLevel > WLOG_OFF) && (logLevel != WLOG_LEVEL_INHERIT)) logLevel = WLOG_OFF; log->Level = logLevel; log->inherit = (logLevel == WLOG_LEVEL_INHERIT) ? TRUE : FALSE; for (x = 0; x < log->ChildrenCount; x++) { wLog* child = log->Children[x]; if (!WLog_UpdateInheritLevel(child, logLevel)) return FALSE; } return WLog_reset_log_filters(log); } int WLog_ParseLogLevel(LPCSTR level) { int iLevel = -1; if (!level) return -1; if (_stricmp(level, "TRACE") == 0) iLevel = WLOG_TRACE; else if (_stricmp(level, "DEBUG") == 0) iLevel = WLOG_DEBUG; else if (_stricmp(level, "INFO") == 0) iLevel = WLOG_INFO; else if (_stricmp(level, "WARN") == 0) iLevel = WLOG_WARN; else if (_stricmp(level, "ERROR") == 0) iLevel = WLOG_ERROR; else if (_stricmp(level, "FATAL") == 0) iLevel = WLOG_FATAL; else if (_stricmp(level, "OFF") == 0) iLevel = WLOG_OFF; return iLevel; } BOOL WLog_ParseFilter(wLog* root, wLogFilter* filter, LPCSTR name) { char* p; char* q; int count; LPSTR names; int iLevel; count = 1; if (!name) return FALSE; p = (char*)name; if (p) { while ((p = strchr(p, '.')) != NULL) { count++; p++; } } names = _strdup(name); if (!names) return FALSE; filter->NameCount = count; filter->Names = (LPSTR*)calloc((count + 1UL), sizeof(LPSTR)); if (!filter->Names) { free(names); filter->NameCount = 0; return FALSE; } filter->Names[count] = NULL; count = 0; p = (char*)names; filter->Names[count++] = p; q = strrchr(p, ':'); if (!q) { free(names); free(filter->Names); filter->Names = NULL; filter->NameCount = 0; return FALSE; } *q = '\0'; q++; iLevel = WLog_ParseLogLevel(q); if (iLevel < 0) { free(names); free(filter->Names); filter->Names = NULL; filter->NameCount = 0; return FALSE; } filter->Level = (DWORD)iLevel; while ((p = strchr(p, '.')) != NULL) { if (count < (int)filter->NameCount) filter->Names[count++] = p + 1; *p = '\0'; p++; } return TRUE; } BOOL WLog_ParseFilters(wLog* root) { LPCSTR filter = "WLOG_FILTER"; BOOL res = FALSE; char* env; DWORD nSize; free(g_Filters); g_Filters = NULL; g_FilterCount = 0; nSize = GetEnvironmentVariableA(filter, NULL, 0); if (nSize < 1) return TRUE; env = (LPSTR)malloc(nSize); if (!env) return FALSE; if (GetEnvironmentVariableA(filter, env, nSize) == nSize - 1) res = WLog_AddStringLogFilters_int(root, env); free(env); return res; } LONG WLog_GetFilterLogLevel(wLog* log) { DWORD i, j; BOOL match = FALSE; if (log->FilterLevel >= 0) return log->FilterLevel; for (i = 0; i < g_FilterCount; i++) { for (j = 0; j < g_Filters[i].NameCount; j++) { if (j >= log->NameCount) break; if (_stricmp(g_Filters[i].Names[j], "*") == 0) { match = TRUE; break; } if (_stricmp(g_Filters[i].Names[j], log->Names[j]) != 0) break; if (j == (log->NameCount - 1)) { match = TRUE; break; } } if (match) break; } if (match) log->FilterLevel = g_Filters[i].Level; else log->FilterLevel = WLOG_FILTER_NOT_FILTERED; return log->FilterLevel; } static BOOL WLog_ParseName(wLog* log, LPCSTR name) { char* p; int count; LPSTR names; count = 1; p = (char*)name; while ((p = strchr(p, '.')) != NULL) { count++; p++; } names = _strdup(name); if (!names) return FALSE; log->NameCount = count; log->Names = (LPSTR*)calloc((count + 1UL), sizeof(LPSTR)); if (!log->Names) { free(names); return FALSE; } log->Names[count] = NULL; count = 0; p = (char*)names; log->Names[count++] = p; while ((p = strchr(p, '.')) != NULL) { if (count < (int)log->NameCount) log->Names[count++] = p + 1; *p = '\0'; p++; } return TRUE; } wLog* WLog_New(LPCSTR name, wLog* rootLogger) { wLog* log = NULL; char* env = NULL; DWORD nSize; int iLevel; log = (wLog*)calloc(1, sizeof(wLog)); if (!log) return NULL; log->Name = _strdup(name); if (!log->Name) goto out_fail; if (!WLog_ParseName(log, name)) goto out_fail; log->Parent = rootLogger; log->ChildrenCount = 0; log->ChildrenSize = 16; log->FilterLevel = WLOG_FILTER_NOT_INITIALIZED; if (!(log->Children = (wLog**)calloc(log->ChildrenSize, sizeof(wLog*)))) goto out_fail; log->Appender = NULL; if (rootLogger) { log->Level = WLOG_LEVEL_INHERIT; log->inherit = TRUE; } else { LPCSTR level = "WLOG_LEVEL"; log->Level = WLOG_INFO; nSize = GetEnvironmentVariableA(level, NULL, 0); if (nSize) { env = (LPSTR)malloc(nSize); if (!env) goto out_fail; if (GetEnvironmentVariableA(level, env, nSize) != nSize - 1) { fprintf(stderr, "%s environment variable changed in my back !\n", level); free(env); goto out_fail; } iLevel = WLog_ParseLogLevel(env); free(env); if (iLevel >= 0) { if (!WLog_SetLogLevel(log, (DWORD)iLevel)) goto out_fail; } } } iLevel = WLog_GetFilterLogLevel(log); if (iLevel >= 0) { if (!WLog_SetLogLevel(log, (DWORD)iLevel)) goto out_fail; } return log; out_fail: free(log->Children); free(log->Name); free(log); return NULL; } void WLog_Free(wLog* log) { if (log) { if (log->Appender) { WLog_Appender_Free(log, log->Appender); log->Appender = NULL; } free(log->Name); free(log->Names[0]); free(log->Names); free(log->Children); free(log); } } wLog* WLog_GetRoot(void) { if (!InitOnceExecuteOnce(&_WLogInitialized, WLog_InitializeRoot, NULL, NULL)) return NULL; return g_RootLog; } static BOOL WLog_AddChild(wLog* parent, wLog* child) { if (parent->ChildrenCount >= parent->ChildrenSize) { wLog** tmp; parent->ChildrenSize *= 2; if (!parent->ChildrenSize) { if (parent->Children) free(parent->Children); parent->Children = NULL; } else { tmp = (wLog**)realloc(parent->Children, sizeof(wLog*) * parent->ChildrenSize); if (!tmp) { if (parent->Children) free(parent->Children); parent->Children = NULL; return FALSE; } parent->Children = tmp; } } if (!parent->Children) return FALSE; parent->Children[parent->ChildrenCount++] = child; child->Parent = parent; return TRUE; } static wLog* WLog_FindChild(wLog* root, LPCSTR name) { DWORD index; wLog* child = NULL; BOOL found = FALSE; if (!root) return NULL; for (index = 0; index < root->ChildrenCount; index++) { child = root->Children[index]; if (strcmp(child->Name, name) == 0) { found = TRUE; break; } } return (found) ? child : NULL; } static wLog* WLog_Get_int(wLog* root, LPCSTR name) { wLog* log; if (!(log = WLog_FindChild(root, name))) { if (!root) return NULL; if (!(log = WLog_New(name, root))) return NULL; if (!WLog_AddChild(root, log)) { WLog_Free(log); return NULL; } } return log; } wLog* WLog_Get(LPCSTR name) { wLog* root = WLog_GetRoot(); return WLog_Get_int(root, name); } BOOL WLog_Init(void) { return WLog_GetRoot() != NULL; } BOOL WLog_Uninit(void) { return TRUE; }