// // EventLogger.c - MrsWatson // Created by Nik Reiman on 1/2/12. // Copyright (c) 2012 Teragon Audio. All rights reserved. // // Redistribution and use in source and binary forms, with or without // modification, are permitted provided that the following conditions are met: // // * Redistributions of source code must retain the above copyright notice, // this list of conditions and the following disclaimer. // * Redistributions in binary form must reproduce the above copyright notice, // this list of conditions and the following disclaimer in the documentation // and/or other materials provided with the distribution. // // THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" // AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE // IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE // ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE // LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR // CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF // SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS // INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN // CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) // ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE // POSSIBILITY OF SUCH DAMAGE. // #include #include #include #include #include "app/BuildInfo.h" #include "audio/AudioSettings.h" #include "logging/EventLogger.h" #include "logging/LogPrinter.h" #include "time/AudioClock.h" #include "MrsWatson.h" #if WINDOWS #include #include #elif UNIX #include #endif EventLogger eventLoggerInstance = NULL; void initEventLogger(void) { #if WINDOWS ULONGLONG currentTime; #else struct timeval currentTime; #endif eventLoggerInstance = (EventLogger)malloc(sizeof(EventLoggerMembers)); eventLoggerInstance->logLevel = LOG_INFO; eventLoggerInstance->logFile = NULL; eventLoggerInstance->useColor = false; eventLoggerInstance->zebraStripeSize = (unsigned long)DEFAULT_SAMPLE_RATE; eventLoggerInstance->systemErrorMessage = NULL; #if WINDOWS currentTime = GetTickCount(); eventLoggerInstance->startTimeInSec = (unsigned long)(currentTime / 1000); eventLoggerInstance->startTimeInMs = (unsigned long)currentTime; #else gettimeofday(¤tTime, NULL); eventLoggerInstance->startTimeInSec = currentTime.tv_sec; eventLoggerInstance->startTimeInMs = currentTime.tv_usec / 1000; #endif if (isatty(1)) { eventLoggerInstance->useColor = true; } } static EventLogger _getEventLoggerInstance(void) { return eventLoggerInstance; } char *stringForLastError(int errorNumber) { EventLogger eventLogger = _getEventLoggerInstance(); if (eventLogger->systemErrorMessage == NULL) { eventLogger->systemErrorMessage = newCharString(); } #if UNIX return strerror(errorNumber); #elif WINDOWS FormatMessageA(FORMAT_MESSAGE_FROM_SYSTEM, 0, errorNumber, MAKELANGID(LANG_NEUTRAL, SUBLANG_DEFAULT), eventLogger->systemErrorMessage->data, eventLogger->systemErrorMessage->capacity - 1, NULL); return eventLogger->systemErrorMessage->data; #endif } boolByte isLogLevelAtLeast(LogLevel logLevel) { EventLogger eventLogger = _getEventLoggerInstance(); return (boolByte)(logLevel >= eventLogger->logLevel); } void setLogLevel(LogLevel logLevel) { EventLogger eventLogger = _getEventLoggerInstance(); eventLogger->logLevel = logLevel; } void setLogLevelFromString(const CharString logLevelString) { if (charStringIsEqualToCString(logLevelString, "debug", true)) { setLogLevel(LOG_DEBUG); } else if (charStringIsEqualToCString(logLevelString, "info", true)) { setLogLevel(LOG_INFO); } else if (charStringIsEqualToCString(logLevelString, "warn", true)) { setLogLevel(LOG_WARN); } else if (charStringIsEqualToCString(logLevelString, "error", true)) { setLogLevel(LOG_ERROR); } else { logCritical("Invalid log level '%s', see '--help full' for valid arguments", logLevelString->data); } } void setLogFile(const CharString logFileName) { EventLogger eventLogger = _getEventLoggerInstance(); eventLogger->logFile = fopen(logFileName->data, "a"); if (eventLogger->logFile == NULL) { logCritical("Could not open file '%s' for logging", logFileName->data); } else { eventLogger->useColor = false; } } void setLoggingColorEnabled(boolByte useColor) { EventLogger eventLogger = _getEventLoggerInstance(); eventLogger->useColor = useColor; } void setLoggingColorEnabledWithString(const CharString colorSchemeName) { if (charStringIsEmpty(colorSchemeName)) { setLoggingColorEnabled(false); } else if (charStringIsEqualToCString(colorSchemeName, "none", false)) { setLoggingColorEnabled(false); } else if (charStringIsEqualToCString(colorSchemeName, "auto", false)) { setLoggingColorEnabled((boolByte)isatty(1)); } else if (charStringIsEqualToCString(colorSchemeName, "force", false)) { setLoggingColorEnabled(true); } else { // Use critical log level to avoid colors logCritical("Unknown color scheme '%s'", colorSchemeName->data); } } void setLoggingZebraSize(const unsigned long zebraStripeSize) { EventLogger eventLogger = _getEventLoggerInstance(); eventLogger->zebraStripeSize = zebraStripeSize; } static char _logLevelStatusChar(const LogLevel logLevel) { switch (logLevel) { case LOG_DEBUG: return 'D'; case LOG_INFO: return '-'; case LOG_WARN: return 'W'; case LOG_ERROR: return 'E'; default: return '!'; } } static LogColor _logLevelStatusColor(const LogLevel logLevel) { switch (logLevel) { case LOG_DEBUG: return COLOR_FG_DKGRAY; case LOG_INFO: return COLOR_RESET; case LOG_WARN: return COLOR_FG_YELLOW; case LOG_ERROR: return COLOR_FG_RED; default: return COLOR_RESET; } } static LogColor _logTimeColor(void) { return COLOR_FG_CYAN; } static LogColor _logTimeZebraStripeColor(const long elapsedTime, const unsigned long zebraSizeInMs) { boolByte zebraState = (boolByte)((elapsedTime / zebraSizeInMs) % 2); return zebraState ? COLOR_FG_OLIVE : COLOR_FG_GREEN; } static void _printMessage(const LogLevel logLevel, const long elapsedTimeInMs, const long numFramesProcessed, const char *message, const EventLogger eventLogger) { char *logString = (char *)malloc(sizeof(char) * kCharStringLengthLong); if (eventLogger->useColor) { snprintf(logString, kCharStringLengthLong, "%c ", _logLevelStatusChar(logLevel)); printToLog(_logLevelStatusColor(logLevel), eventLogger->logFile, logString); snprintf(logString, kCharStringLengthLong, "%08ld ", numFramesProcessed); printToLog(_logTimeZebraStripeColor(numFramesProcessed, eventLogger->zebraStripeSize), eventLogger->logFile, logString); snprintf(logString, kCharStringLengthLong, "%06ld ", elapsedTimeInMs); printToLog(_logTimeColor(), eventLogger->logFile, logString); printToLog(_logLevelStatusColor(logLevel), eventLogger->logFile, message); } else { snprintf(logString, kCharStringLengthLong, "%c %08ld %06ld %s", _logLevelStatusChar(logLevel), numFramesProcessed, elapsedTimeInMs, message); printToLog(COLOR_NONE, eventLogger->logFile, logString); } flushLog(eventLogger->logFile); free(logString); } static void _logMessage(const LogLevel logLevel, const char *message, va_list arguments) { long elapsedTimeInMs; EventLogger eventLogger = _getEventLoggerInstance(); #if WINDOWS ULONGLONG currentTime; #else struct timeval currentTime; #endif if (eventLogger != NULL && logLevel >= eventLogger->logLevel) { CharString formattedMessage = newCharStringWithCapacity(kCharStringLengthDefault * 2); vsnprintf(formattedMessage->data, formattedMessage->capacity, message, arguments); #if WINDOWS currentTime = GetTickCount(); elapsedTimeInMs = (unsigned long)(currentTime - eventLogger->startTimeInMs); #else gettimeofday(¤tTime, NULL); elapsedTimeInMs = ((currentTime.tv_sec - (eventLogger->startTimeInSec + 1)) * 1000) + (currentTime.tv_usec / 1000) + (1000 - eventLogger->startTimeInMs); #endif _printMessage(logLevel, elapsedTimeInMs, getAudioClock()->currentFrame, formattedMessage->data, eventLogger); freeCharString(formattedMessage); } } void logDebug(const char *message, ...) { va_list arguments; va_start(arguments, message); _logMessage(LOG_DEBUG, message, arguments); va_end(arguments); } void logInfo(const char *message, ...) { va_list arguments; va_start(arguments, message); _logMessage(LOG_INFO, message, arguments); va_end(arguments); } void logWarn(const char *message, ...) { va_list arguments; va_start(arguments, message); _logMessage(LOG_WARN, message, arguments); va_end(arguments); } void logError(const char *message, ...) { va_list arguments; va_start(arguments, message); _logMessage(LOG_ERROR, message, arguments); va_end(arguments); } void logCritical(const char *message, ...) { va_list arguments; CharString formattedMessage = newCharString(); CharString wrappedMessage; va_start(arguments, message); // Instead of going through the common logging method, we always dump critical // messages to stderr vsnprintf(formattedMessage->data, formattedMessage->capacity, message, arguments); wrappedMessage = charStringWrap(formattedMessage, 0); fprintf(stderr, "ERROR: %s\n", wrappedMessage->data); if (eventLoggerInstance != NULL && eventLoggerInstance->logFile != NULL) { fprintf(eventLoggerInstance->logFile, "ERROR: %s\n", wrappedMessage->data); } freeCharString(formattedMessage); freeCharString(wrappedMessage); va_end(arguments); } void logInternalError(const char *message, ...) { va_list arguments; CharString formattedMessage = newCharString(); va_start(arguments, message); // Instead of going through the common logging method, we always dump critical messages to stderr vsnprintf(formattedMessage->data, formattedMessage->capacity, message, arguments); fprintf(stderr, "INTERNAL ERROR: %s\n", formattedMessage->data); if (eventLoggerInstance != NULL && eventLoggerInstance->logFile != NULL) { fprintf(eventLoggerInstance->logFile, "INTERNAL ERROR: %s\n", formattedMessage->data); } freeCharString(formattedMessage); va_end(arguments); fprintf(stderr, " This should not have happened. Please take a minute to report a bug.\n"); fprintf(stderr, " Support website: %s\n", SUPPORT_WEBSITE); fprintf(stderr, " Support email: %s\n", SUPPORT_EMAIL); } void logUnsupportedFeature(const char *featureName) { fprintf(stderr, "UNSUPPORTED FEATURE: %s\n", featureName); fprintf(stderr, " This feature is not yet supported. Please help us out and submit a patch! :)\n"); fprintf(stderr, " Project website: %s\n", PROJECT_WEBSITE); fprintf(stderr, " Support email: %s\n", SUPPORT_EMAIL); } void logDeprecated(const char *functionName, const char *plugin) { logWarn("Call to deprecated function '%s' made by plugin '%s'", functionName, plugin); } void logFileError(const char *filename, const char *message) { logCritical("Could not parse file '%s'", filename); logCritical("Got error message message: %s", message); logPossibleBug("This file is either corrupt or was parsed incorrectly"); } void logPossibleBug(const char *cause) { CharString extraText = newCharStringWithCString("If you believe this to be a \ bug in MrsWatson, please re-run the program with the --error-report option to \ generate a diagnostic report to send to support."); CharString wrappedCause; CharString wrappedExtraText; wrappedCause = charStringWrap(newCharStringWithCString(cause), 0); wrappedExtraText = charStringWrap(extraText, 0); fprintf(stderr, "%s\n", wrappedCause->data); fprintf(stderr, "%s\n", wrappedExtraText->data); freeCharString(wrappedCause); freeCharString(wrappedExtraText); } void flushErrorLog(void) { if (eventLoggerInstance != NULL && eventLoggerInstance->logFile != NULL) { fflush(eventLoggerInstance->logFile); } } void freeEventLogger(void) { if (eventLoggerInstance->logFile != NULL) { fclose(eventLoggerInstance->logFile); } freeCharString(eventLoggerInstance->systemErrorMessage); free(eventLoggerInstance); eventLoggerInstance = NULL; }