/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */ /* vim: set ts=8 sts=2 et sw=2 tw=80: */ /* This Source Code Form is subject to the terms of the Mozilla Public * License, v. 2.0. If a copy of the MPL was not distributed with this * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ #include "mozilla/Logging.h" #include #include "mozilla/ClearOnShutdown.h" #include "mozilla/FileUtils.h" #include "mozilla/Mutex.h" #include "mozilla/StaticPtr.h" #include "mozilla/Snprintf.h" #include "nsClassHashtable.h" #include "nsDebug.h" #include "NSPRLogModulesParser.h" #include "prenv.h" #include "prprf.h" #ifdef XP_WIN #include #else #include #include #endif // NB: Initial amount determined by auditing the codebase for the total amount // of unique module names and padding up to the next power of 2. const uint32_t kInitialModuleCount = 256; namespace mozilla { namespace detail { void log_print(const PRLogModuleInfo* aModule, LogLevel aLevel, const char* aFmt, ...) { va_list ap; va_start(ap, aFmt); char* buff = PR_vsmprintf(aFmt, ap); PR_LogPrint("%s", buff); PR_smprintf_free(buff); va_end(ap); } void log_print(const LogModule* aModule, LogLevel aLevel, const char* aFmt, ...) { va_list ap; va_start(ap, aFmt); aModule->Printv(aLevel, aFmt, ap); va_end(ap); } int log_pid() { #ifdef XP_WIN return _getpid(); #else return getpid(); #endif } } LogLevel ToLogLevel(int32_t aLevel) { aLevel = std::min(aLevel, static_cast(LogLevel::Verbose)); aLevel = std::max(aLevel, static_cast(LogLevel::Disabled)); return static_cast(aLevel); } const char* ToLogStr(LogLevel aLevel) { switch (aLevel) { case LogLevel::Error: return "E"; case LogLevel::Warning: return "W"; case LogLevel::Info: return "I"; case LogLevel::Debug: return "D"; case LogLevel::Verbose: return "V"; case LogLevel::Disabled: default: MOZ_CRASH("Invalid log level."); return ""; } } class LogModuleManager { public: LogModuleManager() : mModulesLock("logmodules") , mModules(kInitialModuleCount) , mOutFile(nullptr) , mMainThread(PR_GetCurrentThread()) , mAddTimestamp(false) , mIsSync(false) { } ~LogModuleManager() { // NB: mModules owns all of the log modules, they will get destroyed by // its destructor. } /** * Loads config from env vars if present. */ void Init() { bool shouldAppend = false; bool addTimestamp = false; bool isSync = false; const char* modules = PR_GetEnv("NSPR_LOG_MODULES"); NSPRLogModulesParser(modules, [&shouldAppend, &addTimestamp, &isSync] (const char* aName, LogLevel aLevel) mutable { if (strcmp(aName, "append") == 0) { shouldAppend = true; } else if (strcmp(aName, "timestamp") == 0) { addTimestamp = true; } else if (strcmp(aName, "sync") == 0) { isSync = true; } else { LogModule::Get(aName)->SetLevel(aLevel); } }); mAddTimestamp = addTimestamp; mIsSync = isSync; const char* logFile = PR_GetEnv("NSPR_LOG_FILE"); if (logFile && logFile[0]) { static const char kPIDToken[] = "%PID"; const char* pidTokenPtr = strstr(logFile, kPIDToken); char buf[2048]; if (pidTokenPtr && snprintf_literal(buf, "%.*s%d%s", static_cast(pidTokenPtr - logFile), logFile, detail::log_pid(), pidTokenPtr + strlen(kPIDToken)) > 0) { logFile = buf; } mOutFile = fopen(logFile, shouldAppend ? "a" : "w"); } } LogModule* CreateOrGetModule(const char* aName) { OffTheBooksMutexAutoLock guard(mModulesLock); LogModule* module = nullptr; if (!mModules.Get(aName, &module)) { module = new LogModule(aName, LogLevel::Disabled); mModules.Put(aName, module); } return module; } void Print(const char* aName, LogLevel aLevel, const char* aFmt, va_list aArgs) { const size_t kBuffSize = 1024; char buff[kBuffSize]; char* buffToWrite = buff; // For backwards compat we need to use the NSPR format string versions // of sprintf and friends and then hand off to printf. va_list argsCopy; va_copy(argsCopy, aArgs); size_t charsWritten = PR_vsnprintf(buff, kBuffSize, aFmt, argsCopy); va_end(argsCopy); if (charsWritten == kBuffSize - 1) { // We may have maxed out, allocate a buffer instead. buffToWrite = PR_vsmprintf(aFmt, aArgs); charsWritten = strlen(buffToWrite); } // Determine if a newline needs to be appended to the message. const char* newline = ""; if (charsWritten == 0 || buffToWrite[charsWritten - 1] != '\n') { newline = "\n"; } FILE* out = mOutFile ? mOutFile : stderr; // This differs from the NSPR format in that we do not output the // opaque system specific thread pointer (ie pthread_t) cast // to a long. The address of the current PR_Thread continues to be // prefixed. // // Additionally we prefix the output with the abbreviated log level // and the module name. PRThread *currentThread = PR_GetCurrentThread(); const char *currentThreadName = (mMainThread == currentThread) ? "Main Thread" : PR_GetThreadName(currentThread); char noNameThread[40]; if (!currentThreadName) { snprintf_literal(noNameThread, "Unnamed thread %p", currentThread); currentThreadName = noNameThread; } if (!mAddTimestamp) { fprintf_stderr(out, "[%s]: %s/%s %s%s", currentThreadName, ToLogStr(aLevel), aName, buffToWrite, newline); } else { PRExplodedTime now; PR_ExplodeTime(PR_Now(), PR_GMTParameters, &now); fprintf_stderr( out, "%04d-%02d-%02d %02d:%02d:%02d.%06d UTC - [%s]: %s/%s %s%s", now.tm_year, now.tm_month + 1, now.tm_mday, now.tm_hour, now.tm_min, now.tm_sec, now.tm_usec, currentThreadName, ToLogStr(aLevel), aName, buffToWrite, newline); } if (mIsSync) { fflush(out); } if (buffToWrite != buff) { PR_smprintf_free(buffToWrite); } } private: OffTheBooksMutex mModulesLock; nsClassHashtable mModules; ScopedCloseFile mOutFile; PRThread *mMainThread; bool mAddTimestamp; bool mIsSync; }; StaticAutoPtr sLogModuleManager; LogModule* LogModule::Get(const char* aName) { // This is just a pass through to the LogModuleManager so // that the LogModuleManager implementation can be kept internal. MOZ_ASSERT(sLogModuleManager != nullptr); return sLogModuleManager->CreateOrGetModule(aName); } void LogModule::Init() { // NB: This method is not threadsafe; it is expected to be called very early // in startup prior to any other threads being run. if (sLogModuleManager) { // Already initialized. return; } // NB: We intentionally do not register for ClearOnShutdown as that happens // before all logging is complete. And, yes, that means we leak, but // we're doing that intentionally. sLogModuleManager = new LogModuleManager(); sLogModuleManager->Init(); } void LogModule::Printv(LogLevel aLevel, const char* aFmt, va_list aArgs) const { MOZ_ASSERT(sLogModuleManager != nullptr); // Forward to LogModule manager w/ level and name sLogModuleManager->Print(Name(), aLevel, aFmt, aArgs); } } // namespace mozilla