diff options
author | Chris Wilson <chris+github@qwirx.com> | 2015-02-25 18:56:07 +0000 |
---|---|---|
committer | Chris Wilson <chris+github@qwirx.com> | 2015-02-25 18:56:07 +0000 |
commit | d63936c2f7959d6fff995ec10c91e24266b8c5d7 (patch) | |
tree | 928d4eb0402f82d7f25d4f4008dc3698881e88c9 | |
parent | ca4e4572ca51cce442add6107a59075f76b3aecd (diff) |
Reduce test output noise by hiding some error messages in tests.
Should make the Travis logs shorter and more readable.
-rw-r--r-- | lib/common/Logging.cpp | 56 | ||||
-rw-r--r-- | lib/common/Logging.h | 123 | ||||
-rw-r--r-- | lib/raidfile/RaidFileRead.cpp | 36 | ||||
-rw-r--r-- | lib/raidfile/RaidFileRead.h | 12 | ||||
-rw-r--r-- | test/raidfile/testraidfile.cpp | 7 |
5 files changed, 173 insertions, 61 deletions
diff --git a/lib/common/Logging.cpp b/lib/common/Logging.cpp index b08b311c..fd815132 100644 --- a/lib/common/Logging.cpp +++ b/lib/common/Logging.cpp @@ -42,8 +42,9 @@ std::vector<Logger*> Logging::sLoggers; std::string Logging::sContext; Console* Logging::spConsole = NULL; Syslog* Logging::spSyslog = NULL; -Logging Logging::sGlobalLogging; //automatic initialisation +Logging Logging::sGlobalLogging; // automatic initialisation std::string Logging::sProgramName; +const Log::Category Logging::UNCATEGORISED("Uncategorised"); HideSpecificExceptionGuard::SuppressedExceptions_t HideSpecificExceptionGuard::sSuppressedExceptions; @@ -135,8 +136,9 @@ void Logging::Remove(Logger* pOldLogger) } } -void Logging::Log(Log::Level level, const std::string& rFile, - int line, const std::string& rMessage) +void Logging::Log(Log::Level level, const std::string& file, int line, + const std::string& function, const Log::Category& category, + const std::string& message) { std::string newMessage; @@ -145,12 +147,13 @@ void Logging::Log(Log::Level level, const std::string& rFile, newMessage += "[" + sContext + "] "; } - newMessage += rMessage; + newMessage += message; for (std::vector<Logger*>::iterator i = sLoggers.begin(); i != sLoggers.end(); i++) { - bool result = (*i)->Log(level, rFile, line, newMessage); + bool result = (*i)->Log(level, file, line, function, category, + newMessage); if (!result) { return; @@ -158,8 +161,9 @@ void Logging::Log(Log::Level level, const std::string& rFile, } } -void Logging::LogToSyslog(Log::Level level, const std::string& rFile, - int line, const std::string& rMessage) +void Logging::LogToSyslog(Log::Level level, const std::string& rFile, int line, + const std::string& function, const Log::Category& category, + const std::string& message) { if (!sLogToSyslog) { @@ -173,9 +177,9 @@ void Logging::LogToSyslog(Log::Level level, const std::string& rFile, newMessage += "[" + sContext + "] "; } - newMessage += rMessage; + newMessage += message; - spSyslog->Log(level, rFile, line, newMessage); + spSyslog->Log(level, rFile, line, function, category, newMessage); } void Logging::SetContext(std::string context) @@ -275,8 +279,9 @@ void Console::SetShowPID(bool enabled) sShowPID = enabled; } -bool Console::Log(Log::Level level, const std::string& rFile, - int line, std::string& rMessage) +bool Console::Log(Log::Level level, const std::string& file, int line, + const std::string& function, const Log::Category& category, + const std::string& message) { if (level > GetLevel()) { @@ -333,7 +338,7 @@ bool Console::Log(Log::Level level, const std::string& rFile, buf << "TRACE: "; } - buf << rMessage; + buf << message; #ifdef WIN32 std::string output = buf.str(); @@ -355,8 +360,9 @@ bool Console::Log(Log::Level level, const std::string& rFile, return true; } -bool Syslog::Log(Log::Level level, const std::string& rFile, - int line, std::string& rMessage) +bool Syslog::Log(Log::Level level, const std::string& file, int line, + const std::string& function, const Log::Category& category, + const std::string& message) { if (level > GetLevel()) { @@ -397,7 +403,7 @@ bool Syslog::Log(Log::Level level, const std::string& rFile, msg = "NOTICE: "; } - msg += rMessage; + msg += message; syslog(syslogLevel, "%s", msg.c_str()); @@ -451,8 +457,9 @@ int Syslog::GetNamedFacility(const std::string& rFacility) return LOG_LOCAL6; } -bool FileLogger::Log(Log::Level Level, const std::string& rFile, - int line, std::string& rMessage) +bool FileLogger::Log(Log::Level Level, const std::string& file, int line, + const std::string& function, const Log::Category& category, + const std::string& message) { if (mLogFile.StreamClosed()) { @@ -499,7 +506,7 @@ bool FileLogger::Log(Log::Level Level, const std::string& rFile, buf << "[TRACE] "; } - buf << rMessage << "\n"; + buf << message << "\n"; std::string output = buf.str(); #ifdef WIN32 @@ -703,3 +710,16 @@ std::string Logging::OptionParser::GetUsageString() " -V Run at maximum verbosity, log everything to console and system\n" " -W <level> Set verbosity to error/warning/notice/info/trace/everything\n"; } + +bool HideCategoryGuard::Log(Log::Level level, const std::string& file, int line, + const std::string& function, const Log::Category& category, + const std::string& message) +{ + // Return false if category is in our list, to suppress further + // logging (thus, return true if it's not in our list, i.e. we + // found nothing). + std::list<Log::Category>::iterator i = std::find(mCategories.begin(), + mCategories.end(), category); + return i == mCategories.end(); +} + diff --git a/lib/common/Logging.h b/lib/common/Logging.h index 100d9358..9fd37e28 100644 --- a/lib/common/Logging.h +++ b/lib/common/Logging.h @@ -12,9 +12,11 @@ #include <assert.h> +#include <algorithm> #include <cerrno> #include <cstring> #include <iomanip> +#include <list> #include <sstream> #include <vector> @@ -24,14 +26,24 @@ { \ std::ostringstream _box_log_line; \ _box_log_line << stuff; \ - Logging::Log(level, __FILE__, __LINE__, _box_log_line.str()); \ + Logging::Log(level, __FILE__, __LINE__, __FUNCTION__, \ + Logging::UNCATEGORISED, _box_log_line.str()); \ +} + +#define BOX_LOG_CATEGORY(level, category, stuff) \ +{ \ + std::ostringstream _box_log_line; \ + _box_log_line << stuff; \ + Logging::Log(level, __FILE__, __LINE__, __FUNCTION__, \ + category, _box_log_line.str()); \ } #define BOX_SYSLOG(level, stuff) \ { \ std::ostringstream _box_log_line; \ _box_log_line << stuff; \ - Logging::LogToSyslog(level, __FILE__, __LINE__, _box_log_line.str()); \ + Logging::LogToSyslog(level, __FILE__, __LINE__, __FUNCTION__, \ + _box_log_line.str()); \ } #define BOX_FATAL(stuff) BOX_LOG(Log::FATAL, stuff) @@ -83,18 +95,19 @@ BOX_FILE_MESSAGE(filename, message)) #ifdef WIN32 + #define BOX_WIN_ERRNO_MESSAGE(error_number, stuff) \ + stuff << ": " << GetErrorMessage(error_number) << \ + " (" << error_number << ")" #define BOX_LOG_WIN_ERROR(stuff) \ - BOX_ERROR(stuff << ": " << GetErrorMessage(GetLastError())) + BOX_ERROR(BOX_WIN_ERRNO_MESSAGE(GetLastError(), stuff)) #define BOX_LOG_WIN_WARNING(stuff) \ - BOX_WARNING(stuff << ": " << GetErrorMessage(GetLastError())) + BOX_WARNING(BOX_WIN_ERRNO_MESSAGE(GetLastError(), stuff)) #define BOX_LOG_WIN_ERROR_NUMBER(stuff, number) \ - BOX_ERROR(stuff << ": " << GetErrorMessage(number)) + BOX_ERROR(BOX_WIN_ERRNO_MESSAGE(number, stuff)) #define BOX_LOG_WIN_WARNING_NUMBER(stuff, number) \ - BOX_WARNING(stuff << ": " << GetErrorMessage(number)) + BOX_WARNING(BOX_WIN_ERRNO_MESSAGE(number, stuff)) #define BOX_LOG_NATIVE_ERROR(stuff) BOX_LOG_WIN_ERROR(stuff) #define BOX_LOG_NATIVE_WARNING(stuff) BOX_LOG_WIN_WARNING(stuff) - #define BOX_WIN_ERRNO_MESSAGE(error_number, stuff) \ - stuff << ": " << GetErrorMessage(error_number) #define THROW_WIN_ERROR_NUMBER(message, error_number, exception, subtype) \ THROW_EXCEPTION_MESSAGE(exception, subtype, \ BOX_WIN_ERRNO_MESSAGE(error_number, message)) @@ -166,6 +179,18 @@ namespace Log EVERYTHING, INVALID = -1 }; + + class Category { + private: + std::string mName; + + public: + Category(const std::string& name) + : mName(name) + { } + const std::string& ToString() { return mName; } + bool operator==(const Category& other) { return mName == other.mName; } + }; } // -------------------------------------------------------------------------- @@ -187,8 +212,9 @@ class Logger Logger(Log::Level level); virtual ~Logger(); - virtual bool Log(Log::Level level, const std::string& rFile, - int line, std::string& rMessage) = 0; + virtual bool Log(Log::Level level, const std::string& file, int line, + const std::string& function, const Log::Category& category, + const std::string& message) = 0; void Filter(Log::Level level) { @@ -243,8 +269,9 @@ class Console : public Logger static std::string sTag; public: - virtual bool Log(Log::Level level, const std::string& rFile, - int line, std::string& rMessage); + virtual bool Log(Log::Level level, const std::string& file, int line, + const std::string& function, const Log::Category& category, + const std::string& message); virtual const char* GetType() { return "Console"; } virtual void SetProgramName(const std::string& rProgramName); @@ -274,8 +301,9 @@ class Syslog : public Logger Syslog(); virtual ~Syslog(); - virtual bool Log(Log::Level level, const std::string& rFile, - int line, std::string& rMessage); + virtual bool Log(Log::Level level, const std::string& file, int line, + const std::string& function, const Log::Category& category, + const std::string& message); virtual const char* GetType() { return "Syslog"; } virtual void SetProgramName(const std::string& rProgramName); virtual void SetFacility(int facility); @@ -297,9 +325,13 @@ class Capture : public Logger public: struct Message { + Message(const Log::Category& category) + : mCategory(category) { } Log::Level level; std::string file; int line; + std::string function; + Log::Category mCategory; std::string message; }; @@ -309,15 +341,17 @@ class Capture : public Logger public: virtual ~Capture() { } - virtual bool Log(Log::Level level, const std::string& rFile, - int line, std::string& rMessage) + virtual bool Log(Log::Level level, const std::string& file, int line, + const std::string& function, const Log::Category& category, + const std::string& message) { - Message message; - message.level = level; - message.file = rFile; - message.line = line; - message.message = rMessage; - mMessages.push_back(message); + Message msg(category); + msg.level = level; + msg.file = file; + msg.line = line; + msg.function = function; + msg.message = message; + mMessages.push_back(msg); return true; } virtual const char* GetType() { return "Capture"; } @@ -366,10 +400,12 @@ class Logging static void FilterConsole (Log::Level level); static void Add (Logger* pNewLogger); static void Remove (Logger* pOldLogger); - static void Log(Log::Level level, const std::string& rFile, - int line, const std::string& rMessage); - static void LogToSyslog(Log::Level level, const std::string& rFile, - int line, const std::string& rMessage); + static void Log(Log::Level level, const std::string& file, int line, + const std::string& function, const Log::Category& category, + const std::string& message); + static void LogToSyslog(Log::Level level, const std::string& rFile, int line, + const std::string& function, const Log::Category& category, + const std::string& message); static void SetContext(std::string context); static void ClearContext(); static Log::Level GetNamedLevel(const std::string& rName); @@ -481,6 +517,8 @@ class Logging return (Log::Level) mCurrentLevel; } }; + + static const Log::Category UNCATEGORISED; }; class FileLogger : public Logger @@ -496,8 +534,9 @@ class FileLogger : public Logger mLogFile(rFileName, O_WRONLY | O_CREAT | (append ? O_APPEND : O_TRUNC)) { } - virtual bool Log(Log::Level Level, const std::string& rFile, - int Line, std::string& rMessage); + virtual bool Log(Log::Level level, const std::string& file, int line, + const std::string& function, const Log::Category& category, + const std::string& message); virtual const char* GetType() { return "FileLogger"; } virtual void SetProgramName(const std::string& rProgramName) { } @@ -546,6 +585,34 @@ class HideSpecificExceptionGuard static bool IsHidden(int type, int subtype); }; +class HideCategoryGuard : public Logger +{ + private: + std::list<Log::Category> mCategories; + HideCategoryGuard(const HideCategoryGuard& other); // no copying + HideCategoryGuard& operator=(const HideCategoryGuard& other); // no assignment + + public: + HideCategoryGuard(const Log::Category& category) + { + mCategories.push_back(category); + Logging::Add(this); + } + ~HideCategoryGuard() + { + Logging::Remove(this); + } + void Add(const Log::Category& category) + { + mCategories.push_back(category); + } + virtual bool Log(Log::Level level, const std::string& file, int line, + const std::string& function, const Log::Category& category, + const std::string& message); + virtual const char* GetType() { return "HideCategoryGuard"; } + virtual void SetProgramName(const std::string& rProgramName) { } +}; + std::string PrintEscapedBinaryData(const std::string& rInput); #endif // LOGGING__H diff --git a/lib/raidfile/RaidFileRead.cpp b/lib/raidfile/RaidFileRead.cpp index 1e8b380f..7b755395 100644 --- a/lib/raidfile/RaidFileRead.cpp +++ b/lib/raidfile/RaidFileRead.cpp @@ -47,6 +47,10 @@ // We want to use POSIX fstat() for now, not the emulated one, because it's // difficult to rewrite all this code to use HANDLEs instead of ints. +const RaidFileReadCategory RaidFileRead::OPEN_IN_RECOVERY("OpenInRecovery"); +const RaidFileReadCategory RaidFileRead::IO_ERROR("IoError"); +const RaidFileReadCategory RaidFileRead::RECOVERING_IO_ERROR("RecoverIoError"); + // -------------------------------------------------------------------------- // // Class @@ -548,7 +552,8 @@ void RaidFileRead_Raid::MoveDamagedFileAlertDaemon(int SetNumber, const std::str // -------------------------------------------------------------------------- void RaidFileRead_Raid::AttemptToRecoverFromIOError(bool Stripe1) { - BOX_WARNING("Attempting to recover from I/O error: " << mSetNumber << + BOX_LOG_CATEGORY(Log::WARNING, RaidFileRead::RECOVERING_IO_ERROR, + "Attempting to recover from I/O error: " << mSetNumber << " " << mFilename << ", on stripe " << (Stripe1?1:2)); // Close offending file @@ -861,10 +866,10 @@ void RaidFileRead_Raid::SetPosition(pos_type FilePosition) { if(errno == EIO) { - BOX_ERROR("I/O error when seeking in " << - mSetNumber << " " << mFilename << - " (to " << FilePosition << "), " << - "stripe 1"); + BOX_LOG_CATEGORY(Log::ERROR, RaidFileRead::IO_ERROR, + "I/O error when seeking in set " << mSetNumber << + ": " << mFilename << " (to " << FilePosition << + "), " << "stripe 1"); // Attempt to recover AttemptToRecoverFromIOError(true /* is stripe 1 */); ASSERT(mStripe1Handle == -1); @@ -881,10 +886,10 @@ void RaidFileRead_Raid::SetPosition(pos_type FilePosition) { if(errno == EIO) { - BOX_ERROR("I/O error when seeking in " << - mSetNumber << " " << mFilename << - " (to " << FilePosition << "), " << - "stripe 2"); + BOX_LOG_CATEGORY(Log::ERROR, RaidFileRead::IO_ERROR, + "I/O error when seeking in set " << mSetNumber << + ": " << mFilename << " (to " << FilePosition << + "), " << "stripe 2"); // Attempt to recover AttemptToRecoverFromIOError(false /* is stripe 2 */); ASSERT(mStripe2Handle == -1); @@ -1155,8 +1160,9 @@ std::auto_ptr<RaidFileRead> RaidFileRead::Open(int SetNumber, const std::string bool oktotryagain = true; if(stripe1errno == EIO) { - BOX_ERROR("I/O error on opening " << - SetNumber << " " << Filename << + BOX_LOG_CATEGORY(Log::ERROR, + RaidFileRead::RECOVERING_IO_ERROR, "I/O error " + "on opening " << SetNumber << " " << Filename << " stripe 1, trying recovery mode"); RaidFileRead_Raid::MoveDamagedFileAlertDaemon(SetNumber, Filename, true /* is stripe 1 */); @@ -1172,8 +1178,9 @@ std::auto_ptr<RaidFileRead> RaidFileRead::Open(int SetNumber, const std::string if(stripe2errno == EIO) { - BOX_ERROR("I/O error on opening " << - SetNumber << " " << Filename << + BOX_LOG_CATEGORY(Log::ERROR, + RaidFileRead::RECOVERING_IO_ERROR, "I/O error " + "on opening " << SetNumber << " " << Filename << " stripe 2, trying recovery mode"); RaidFileRead_Raid::MoveDamagedFileAlertDaemon(SetNumber, Filename, false /* is stripe 2 */); @@ -1196,7 +1203,8 @@ std::auto_ptr<RaidFileRead> RaidFileRead::Open(int SetNumber, const std::string if(existance == RaidFileUtil::AsRaidWithMissingReadable) { - BOX_ERROR("Attempting to open RAID file " << SetNumber << + BOX_LOG_CATEGORY(Log::ERROR, RaidFileRead::OPEN_IN_RECOVERY, + "Attempting to open RAID file " << SetNumber << " " << Filename << " in recovery mode (stripe " << ((existingFiles & RaidFileUtil::Stripe1Exists)?1:2) << " present)"); diff --git a/lib/raidfile/RaidFileRead.h b/lib/raidfile/RaidFileRead.h index 570443c8..a3c792d0 100644 --- a/lib/raidfile/RaidFileRead.h +++ b/lib/raidfile/RaidFileRead.h @@ -16,9 +16,17 @@ #include <vector> #include "IOStream.h" +#include "Logging.h" class RaidFileDiscSet; +class RaidFileReadCategory : public Log::Category +{ + public: + RaidFileReadCategory(const std::string& name) + : Log::Category(std::string("RaidFileRead/") + name) + { } +}; // -------------------------------------------------------------------------- // @@ -66,6 +74,10 @@ public: typedef int64_t FileSizeType; + static const RaidFileReadCategory OPEN_IN_RECOVERY; + static const RaidFileReadCategory IO_ERROR; + static const RaidFileReadCategory RECOVERING_IO_ERROR; + protected: int mSetNumber; std::string mFilename; diff --git a/test/raidfile/testraidfile.cpp b/test/raidfile/testraidfile.cpp index 160de5c9..5a62b101 100644 --- a/test/raidfile/testraidfile.cpp +++ b/test/raidfile/testraidfile.cpp @@ -216,6 +216,12 @@ void testReadingFileContents(int set, const char *filename, void *data, int data // Be nasty, and create some errors for the RAID stuff to recover from... if(TestRAIDProperties) { + HideCategoryGuard hide(RaidFileRead::OPEN_IN_RECOVERY); + hide.Add(RaidFileRead::IO_ERROR); + hide.Add(RaidFileRead::RECOVERING_IO_ERROR); + HideSpecificExceptionGuard hex(RaidFileException::ExceptionType, + RaidFileException::ErrorOpeningFileForRead); + char stripe1fn[256], stripe1fnRename[256]; sprintf(stripe1fn, "testfiles" DIRECTORY_SEPARATOR "%d_%d" DIRECTORY_SEPARATOR "%s.rf", set, startDisc, filename); @@ -273,7 +279,6 @@ void testReadingFileContents(int set, const char *filename, void *data, int data DIRECTORY_SEPARATOR ".raidfile-unreadable" DIRECTORY_SEPARATOR "%s", set, (startDisc + 1) % RAID_NUMBER_DISCS, mungefilename); - #ifdef TRF_CAN_INTERCEPT // Test I/O errors on opening |