[Box Backup-commit] COMMIT r3530 - in box/trunk: lib/common lib/raidfile test/raidfile
subversion at boxbackup.org
subversion at boxbackup.org
Wed Feb 25 18:56:08 GMT 2015
Author: chris
Date: 2015-02-25 18:56:07 +0000 (Wed, 25 Feb 2015)
New Revision: 3530
Modified:
box/trunk/lib/common/Logging.cpp
box/trunk/lib/common/Logging.h
box/trunk/lib/raidfile/RaidFileRead.cpp
box/trunk/lib/raidfile/RaidFileRead.h
box/trunk/test/raidfile/testraidfile.cpp
Log:
Reduce test output noise by hiding some error messages in tests.
Should make the Travis logs shorter and more readable.
Modified: box/trunk/lib/common/Logging.cpp
===================================================================
--- box/trunk/lib/common/Logging.cpp 2015-02-23 22:26:10 UTC (rev 3529)
+++ box/trunk/lib/common/Logging.cpp 2015-02-25 18:56:07 UTC (rev 3530)
@@ -42,8 +42,9 @@
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::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 @@
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::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 @@
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 @@
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 @@
buf << "TRACE: ";
}
- buf << rMessage;
+ buf << message;
#ifdef WIN32
std::string output = buf.str();
@@ -355,8 +360,9 @@
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 @@
msg = "NOTICE: ";
}
- msg += rMessage;
+ msg += message;
syslog(syslogLevel, "%s", msg.c_str());
@@ -451,8 +457,9 @@
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 @@
buf << "[TRACE] ";
}
- buf << rMessage << "\n";
+ buf << message << "\n";
std::string output = buf.str();
#ifdef WIN32
@@ -703,3 +710,16 @@
" -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();
+}
+
Modified: box/trunk/lib/common/Logging.h
===================================================================
--- box/trunk/lib/common/Logging.h 2015-02-23 22:26:10 UTC (rev 3529)
+++ box/trunk/lib/common/Logging.h 2015-02-25 18:56:07 UTC (rev 3530)
@@ -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 @@
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 @@
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 @@
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 @@
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 @@
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 @@
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 @@
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 @@
return (Log::Level) mCurrentLevel;
}
};
+
+ static const Log::Category UNCATEGORISED;
};
class FileLogger : public Logger
@@ -496,8 +534,9 @@
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 @@
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
Modified: box/trunk/lib/raidfile/RaidFileRead.cpp
===================================================================
--- box/trunk/lib/raidfile/RaidFileRead.cpp 2015-02-23 22:26:10 UTC (rev 3529)
+++ box/trunk/lib/raidfile/RaidFileRead.cpp 2015-02-25 18:56:07 UTC (rev 3530)
@@ -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::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 @@
{
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 @@
{
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 @@
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 @@
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 @@
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)");
Modified: box/trunk/lib/raidfile/RaidFileRead.h
===================================================================
--- box/trunk/lib/raidfile/RaidFileRead.h 2015-02-23 22:26:10 UTC (rev 3529)
+++ box/trunk/lib/raidfile/RaidFileRead.h 2015-02-25 18:56:07 UTC (rev 3530)
@@ -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 @@
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;
Modified: box/trunk/test/raidfile/testraidfile.cpp
===================================================================
--- box/trunk/test/raidfile/testraidfile.cpp 2015-02-23 22:26:10 UTC (rev 3529)
+++ box/trunk/test/raidfile/testraidfile.cpp 2015-02-25 18:56:07 UTC (rev 3530)
@@ -216,6 +216,12 @@
// 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 @@
DIRECTORY_SEPARATOR ".raidfile-unreadable"
DIRECTORY_SEPARATOR "%s", set,
(startDisc + 1) % RAID_NUMBER_DISCS, mungefilename);
-
#ifdef TRF_CAN_INTERCEPT
// Test I/O errors on opening
More information about the Boxbackup-commit
mailing list