Skip to content

Proper display / filtering of ROOT log messages from stderr in terminal output and InfoLogger #13683

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
davidrohr merged 2 commits into from
Nov 19, 2024
Merged

Proper display / filtering of ROOT log messages from stderr in terminal output and InfoLogger #13683

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
9ef027f
Assign proper InfoLogger log level to ROOT log messages from stderr
ehellbar Nov 14, 2024
7751300
DPL: display stderr ROOT logs in the terminal output according to the…
ehellbar Nov 14, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions Framework/Core/include/Framework/DeviceInfo.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -45,6 +45,8 @@ struct DeviceInfo {
size_t historySize;
/// The maximum log level ever seen by this device
LogParsingHelpers::LogLevel maxLogLevel;
/// The minimum log level for log messages sent/displayed by this device
LogParsingHelpers::LogLevel logLevel{LogParsingHelpers::LogLevel::Info};

/// The minimum level after which the device will exit with 0
LogParsingHelpers::LogLevel minFailureLevel;
Expand Down
14 changes: 12 additions & 2 deletions Framework/Core/src/LogParsingHelpers.cxx
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -30,7 +30,7 @@ LogLevel LogParsingHelpers::parseTokenLevel(std::string_view const s)
// Example format: [99:99:99][ERROR] (string begins with that, longest is 17 chars)
constexpr size_t MAXPREFLEN = 17;
constexpr size_t LABELPOS = 10;
if (s.size() < MAXPREFLEN) {
if (s.size() < MAXPREFLEN && s.find("*** Break ***") == std::string::npos && !s.starts_with("[INFO]")) {
return LogLevel::Unknown;
}

Expand All @@ -41,7 +41,17 @@ LogLevel LogParsingHelpers::parseTokenLevel(std::string_view const s)
(unsigned char)s[1] - '0' > 9 || (unsigned char)s[2] - '0' > 9 ||
(unsigned char)s[4] - '0' > 9 || (unsigned char)s[5] - '0' > 9 ||
(unsigned char)s[7] - '0' > 9 || (unsigned char)s[8] - '0' > 9) {
return LogLevel::Unknown;
if (s.starts_with("Info in <") || s.starts_with("Print in <") || s.starts_with("[INFO]")) {
return LogLevel::Info;
} else if (s.starts_with("Warning in <")) {
return LogLevel::Warning;
} else if (s.find("Error in <") != std::string::npos) {
return LogLevel::Error;
} else if (s.starts_with("Fatal in <") || s.find("*** Break ***") != std::string::npos) {
return LogLevel::Fatal;
} else {
return LogLevel::Unknown;
}
}

if (s.compare(LABELPOS, 8, "[DEBUG] ") == 0) {
Expand Down
34 changes: 32 additions & 2 deletions Framework/Core/src/runDataProcessing.cxx
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -884,8 +884,7 @@ void processChildrenOutput(uv_loop_t* loop,
throw runtime_error("stdout is not supported anymore as a driver backend. Please use ws://");
} else if (logLevel == LogParsingHelpers::LogLevel::Info && DeviceConfigHelper::parseConfig(token.substr(16), configMatch)) {
throw runtime_error("stdout is not supported anymore as a driver backend. Please use ws://");
} else if (!control.quiet && (token.find(control.logFilter) != std::string::npos) &&
logLevel >= control.logLevel) {
} else if (!control.quiet && (token.find(control.logFilter) != std::string::npos) && logLevel >= info.logLevel) {
assert(info.historyPos >= 0);
assert(info.historyPos < info.history.size());
info.history[info.historyPos] = token;
Expand Down Expand Up @@ -2126,6 +2125,37 @@ int runStateMachine(DataProcessorSpecs const& workflow,
driverInfo.resourcesMonitoringDumpInterval * 1000,
driverInfo.resourcesMonitoringDumpInterval * 1000);
}
/// Set the value for the severity of displayed logs to the command line value --severity
for (const auto& processorInfo : dataProcessorInfos) {
const auto& cmdLineArgs = processorInfo.cmdLineArgs;
if (std::find(cmdLineArgs.begin(), cmdLineArgs.end(), "--severity") != cmdLineArgs.end()) {
for (size_t counter = 0; const auto& spec : runningWorkflow.devices) {
if (spec.name.compare(processorInfo.name) == 0) {
auto& info = infos[counter];
const auto logLevelIt = std::find(cmdLineArgs.begin(), cmdLineArgs.end(), "--severity") + 1;
if ((*logLevelIt).compare("debug") == 0) {
info.logLevel = LogParsingHelpers::LogLevel::Debug;
} else if ((*logLevelIt).compare("detail") == 0) {
info.logLevel = LogParsingHelpers::LogLevel::Debug;
} else if ((*logLevelIt).compare("info") == 0) {
info.logLevel = LogParsingHelpers::LogLevel::Info;
} else if ((*logLevelIt).compare("warning") == 0) {
info.logLevel = LogParsingHelpers::LogLevel::Warning;
} else if ((*logLevelIt).compare("error") == 0) {
info.logLevel = LogParsingHelpers::LogLevel::Error;
} else if ((*logLevelIt).compare("important") == 0) {
info.logLevel = LogParsingHelpers::LogLevel::Info;
} else if ((*logLevelIt).compare("alarm") == 0) {
info.logLevel = LogParsingHelpers::LogLevel::Alarm;
} else if ((*logLevelIt).compare("fatal") == 0) {
info.logLevel = LogParsingHelpers::LogLevel::Fatal;
}
break;
}
++counter;
}
}
}
LOG(info) << "Redeployment of configuration done.";
} break;
case DriverState::RUNNING:
Expand Down
18 changes: 0 additions & 18 deletions Framework/GUISupport/src/FrameworkGUIDebugger.cxx
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -142,24 +142,6 @@ void displayHistory(const DeviceInfo& info, DeviceControl& control)
auto& line = info.history[ji];
auto logLevel = info.historyLevel[ji];

// assign proper loglevel to ROOT log messages from stderr
auto getLogLevelUnknown = [&line]() -> LogParsingHelpers::LogLevel {
if (line.starts_with("Print in") || line.starts_with("Info in") || line.starts_with("[INFO]")) {
return LogParsingHelpers::LogLevel::Info;
} else if (line.starts_with("Warning in")) {
return LogParsingHelpers::LogLevel::Warning;
} else if (line.starts_with("Error in") || line.starts_with("SysError in")) {
return LogParsingHelpers::LogLevel::Error;
} else if (line.starts_with("Fatal in") || line.starts_with("*** Break ***")) {
return LogParsingHelpers::LogLevel::Fatal;
} else {
return LogParsingHelpers::LogLevel::Unknown;
}
};
if (logLevel == LogParsingHelpers::LogLevel::Unknown) {
logLevel = getLogLevelUnknown();
}

// Skip empty lines
if (line.empty()) {
ji = (ji + 1) % historySize;
Expand Down
29 changes: 24 additions & 5 deletions Utilities/EPNMonitoring/src/EPNstderrMonitor.cxx
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -68,14 +68,16 @@ class EPNMonitor
private:
void thread();
void check_add_file(const std::string& filename);
void sendLog(const std::string& file, const std::string& message);
void sendLog(const std::string& file, const std::string& message,
const InfoLogger::InfoLogger::Severity severity = InfoLogger::InfoLogger::Severity::Error, int level = 3);

bool mInfoLoggerActive;
volatile bool mTerminate = false;
std::thread mThread;
std::unordered_map<std::string, fileMon> mFiles;
std::string mPath;
std::vector<std::regex> mFilters;
std::unordered_map<std::string, std::pair<InfoLogger::InfoLogger::Severity, int>> mMapRootLogTypes;
volatile unsigned int mRunNumber;
std::string mPartition;
unsigned int nLines = 0;
Expand All @@ -87,11 +89,18 @@ class EPNMonitor
EPNMonitor::EPNMonitor(std::string path, bool infoLogger, int runNumber, std::string partition)
{
mFilters.emplace_back("^Info in <");
mFilters.emplace_back("^Print in <");
mFilters.emplace_back("^[0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}.[0-9]{6}");
mFilters.emplace_back("^Warning in <Fit");
mFilters.emplace_back("^Warning in <TGraph");
mFilters.emplace_back("^Warning in <TInterpreter");
mFilters.emplace_back("Dividing histograms with different labels");
mMapRootLogTypes.emplace("Info in <", std::pair<InfoLogger::InfoLogger::Severity, int>{InfoLogger::InfoLogger::Severity::Info, 13});
mMapRootLogTypes.emplace("Print in <", std::pair<InfoLogger::InfoLogger::Severity, int>{InfoLogger::InfoLogger::Severity::Info, 13});
mMapRootLogTypes.emplace("Warning in <", std::pair<InfoLogger::InfoLogger::Severity, int>{InfoLogger::InfoLogger::Severity::Warning, 11});
mMapRootLogTypes.emplace("Error in <", std::pair<InfoLogger::InfoLogger::Severity, int>{InfoLogger::InfoLogger::Severity::Error, 2});
mMapRootLogTypes.emplace("Fatal in <", std::pair<InfoLogger::InfoLogger::Severity, int>{InfoLogger::InfoLogger::Severity::Fatal, 1});
mMapRootLogTypes.emplace("*** Break ***", std::pair<InfoLogger::InfoLogger::Severity, int>{InfoLogger::InfoLogger::Severity::Fatal, 1});
mInfoLoggerActive = infoLogger;
mPath = path;
mRunNumber = runNumber;
Expand Down Expand Up @@ -120,15 +129,15 @@ void EPNMonitor::check_add_file(const std::string& filename)
}
}

void EPNMonitor::sendLog(const std::string& file, const std::string& message)
void EPNMonitor::sendLog(const std::string& file, const std::string& message, const InfoLogger::InfoLogger::Severity severity, int level)
{
if (mInfoLoggerActive) {
mLoggerContext->setField(InfoLogger::InfoLoggerContext::FieldName::Facility, ("stderr/" + file).substr(0, 31));
mLoggerContext->setField(InfoLogger::InfoLoggerContext::FieldName::Run, mRunNumber != 0 ? std::to_string(mRunNumber) : "unspecified");
static const InfoLogger::InfoLogger::InfoLoggerMessageOption opt = {InfoLogger::InfoLogger::Severity::Error, 3, InfoLogger::InfoLogger::undefinedMessageOption.errorCode, InfoLogger::InfoLogger::undefinedMessageOption.sourceFile, InfoLogger::InfoLogger::undefinedMessageOption.sourceLine};
static const InfoLogger::InfoLogger::InfoLoggerMessageOption opt = {severity, level, InfoLogger::InfoLogger::undefinedMessageOption.errorCode, InfoLogger::InfoLogger::undefinedMessageOption.sourceFile, InfoLogger::InfoLogger::undefinedMessageOption.sourceLine};
mLogger->log(opt, *mLoggerContext, "stderr: %s", file == "SYSLOG" ? (std::string("[GLOBAL SYSLOG]: ") + message).c_str() : message.c_str());
} else {
printf("stderr: %s: %s\n", file.c_str(), message.c_str());
printf("stderr: [%c] %s: %s\n", severity, file.c_str(), message.c_str());
}
}

Expand Down Expand Up @@ -202,6 +211,16 @@ void EPNMonitor::thread()
if (filterLine) {
continue;
}
// assign proper severity / level for remaining ROOT log messages
auto severity{InfoLogger::InfoLogger::Severity::Error};
int level{3};
for (const auto& logType : mMapRootLogTypes) {
if (line.find(logType.first) != std::string::npos) {
severity = std::get<InfoLogger::InfoLogger::Severity>(logType.second);
level = std::get<int>(logType.second);
break;
}
}
f.nLines++;
f.nBytes += line.size();
nLines++;
Expand All @@ -214,7 +233,7 @@ void EPNMonitor::thread()
if (nLines >= MAX_LINES_TOTAL || nBytes >= MAX_BYTES_TOTAL) {
break;
}
sendLog(f.name, line);
sendLog(f.name, line, severity, level);
}
} while (!file.eof());
}
Expand Down
Loading