owen/lms
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Reworked log system: now logs are handled by lms itself (better control on what is logged), ref #725

Browse Source
This commit is contained in:
emeric
2025-08-09 12:49:24 +02:00
parent d529f4cb98
commit 317a6f504e
15 changed files with 229 additions and 211 deletions
Download Patch File Download Diff File Expand all files Collapse all files
src/libs/core/CMakeLists.txt
-2
View File
@@ -27,11 +27,9 @@ add_library(lmscore STATIC
impl/Path.cpp
impl/Random.cpp
impl/RecursiveSharedMutex.cpp
impl/StreamLogger.cpp
impl/String.cpp
impl/TraceLogger.cpp
impl/UUID.cpp
impl/WtLogger.cpp
impl/XxHash3.cpp
${CMAKE_CURRENT_BINARY_DIR}/impl/Version.cpp
)
src/libs/core/bench/TraceLoggerBench.cpp
+1 -3
View File
@@ -17,19 +17,17 @@
* along with LMS. If not, see <http://www.gnu.org/licenses/>.
*/
#include <iostream>
#include <thread>
#include <benchmark/benchmark.h>
#include "core/ILogger.hpp"
#include "core/ITraceLogger.hpp"
#include "core/StreamLogger.hpp"
namespace lms::core
{
// The trace logger is meant to built/destroyed once
const Service<logging::ILogger> logger{ std::make_unique<logging::StreamLogger>(std::cout, logging::StreamLogger::allSeverities) };
const Service<logging::ILogger> logger{ logging::createLogger() };
const Service<tracing::ITraceLogger> traceLogger{ tracing::createTraceLogger(tracing::Level::Overview) };
static void BM_TraceLogger_Overview(benchmark::State& state)
src/libs/core/impl/Logger.cpp
+103 -1
View File
@@ -17,7 +17,17 @@
* along with LMS. If not, see <http://www.gnu.org/licenses/>.
*/
#include "core/ILogger.hpp"
#include "Logger.hpp"
#include <Wt/WDateTime.h>
#include <algorithm>
#include <fstream>
#include <iostream>
#include <thread>
#include "core/Exception.hpp"
#include "core/String.hpp"
namespace lms::core::logging
{
@@ -63,6 +73,8 @@ namespace lms::core::logging
return "UI";
case Module::UTILS:
return "UTILS";
case Module::WT:
return "WT";
}
return "";
}
@@ -103,4 +115,94 @@ namespace lms::core::logging
{
return _oss.str();
}
std::unique_ptr<ILogger> createLogger(Severity minSeverity, const std::filesystem::path& logFilePath)
{
return std::make_unique<Logger>(minSeverity, logFilePath);
}
Logger::OutputStream::OutputStream(std::ostream& os)
: stream{ os }
{
}
Logger::Logger(Severity minSeverity, const std::filesystem::path& logFilePath)
{
if (!logFilePath.empty())
{
_logFileStream = std::make_unique<std::ofstream>(logFilePath, std::ios::out | std::ios::app);
if (!_logFileStream->is_open())
{
const std::error_code ec{ errno, std::generic_category() };
throw LmsException{ "Cannot open log file '" + logFilePath.string() + "' for writing: " + ec.message() };
}
}
switch (minSeverity)
{
case core::logging::Severity::DEBUG:
if (_logFileStream)
addOutputStream(*_logFileStream, { core::logging::Severity::DEBUG });
else
addOutputStream(std::cout, { core::logging::Severity::DEBUG });
[[fallthrough]];
case core::logging::Severity::INFO:
if (_logFileStream)
addOutputStream(*_logFileStream, { core::logging::Severity::INFO });
else
addOutputStream(std::cout, { core::logging::Severity::INFO });
[[fallthrough]];
case core::logging::Severity::WARNING:
if (_logFileStream)
addOutputStream(*_logFileStream, { core::logging::Severity::WARNING });
else
addOutputStream(std::cerr, { core::logging::Severity::WARNING });
[[fallthrough]];
case core::logging::Severity::ERROR:
if (_logFileStream)
addOutputStream(*_logFileStream, { core::logging::Severity::ERROR });
else
addOutputStream(std::cerr, { core::logging::Severity::ERROR });
[[fallthrough]];
case core::logging::Severity::FATAL:
if (_logFileStream)
addOutputStream(*_logFileStream, { core::logging::Severity::FATAL });
else
addOutputStream(std::cerr, { core::logging::Severity::FATAL });
break;
}
}
Logger::~Logger() = default;
void Logger::addOutputStream(std::ostream& os, Severity severity)
{
auto it{ std::find_if(_outputStreams.begin(), _outputStreams.end(), [&os](const OutputStream& outputStream) { return &outputStream.stream == &os; }) };
if (it == _outputStreams.end())
it = _outputStreams.emplace(_outputStreams.end(), os);
assert(!_severityToOutputStreamMap.contains(severity));
_severityToOutputStreamMap.emplace(severity, &(*it));
}
bool Logger::isSeverityActive(Severity severity) const
{
return _severityToOutputStreamMap.contains(severity);
}
void Logger::processLog(const Log& log)
{
processLog(log.getModule(), log.getSeverity(), log.getMessage());
}
void Logger::processLog(Module module, Severity severity, std::string_view message)
{
assert(isSeverityActive(severity)); // should have been filtered out by a isSeverityActive call
OutputStream* outputStream{ _severityToOutputStreamMap.at(severity) };
const Wt::WDateTime now{ Wt::WDateTime::currentDateTime() };
std::unique_lock lock{ outputStream->mutex };
outputStream->stream << stringUtils::toISO8601String(now) << " " << std::this_thread::get_id() << " [" << getSeverityName(severity) << "] [" << getModuleName(module) << "] " << message << std::endl;
}
} // namespace lms::core::logging
src/libs/core/include/core/WtLogger.hpp → src/libs/core/impl/Logger.hpp
+25 -6
View File
@@ -19,22 +19,41 @@
#pragma once
#include <string>
#include <filesystem>
#include <iosfwd>
#include <list>
#include <mutex>
#include <unordered_map>
#include "core/ILogger.hpp"
namespace lms::core::logging
{
class WtLogger final : public ILogger
class Logger final : public ILogger
{
public:
WtLogger(Severity minSeverity);
static std::string computeLogConfig(Severity minSeverity);
Logger(Severity minSeverity, const std::filesystem::path& logFilePath);
~Logger() override;
Logger(const Logger&) = delete;
Logger& operator=(const Logger&) = delete;
private:
bool isSeverityActive(Severity severity) const override;
void processLog(const Log& log) override;
const Severity _minSeverity;
void processLog(Module module, Severity severity, std::string_view message) override;
void addOutputStream(std::ostream& os, Severity severity);
struct OutputStream
{
OutputStream(std::ostream& os);
std::mutex mutex;
std::ostream& stream;
};
std::list<OutputStream> _outputStreams;
std::unordered_map<Severity, OutputStream*> _severityToOutputStreamMap;
std::unique_ptr<std::ofstream> _logFileStream;
};
} // namespace lms::core::logging
src/libs/core/impl/StreamLogger.cpp
-38
View File
@@ -1,38 +0,0 @@
/*
* Copyright (C) 2019 Emeric Poupon
*
* This file is part of LMS.
*
* LMS is free software: you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
* the Free Software Foundation, either version 3 of the License, or
* (at your option) any later version.
*
* LMS is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with LMS. If not, see <http://www.gnu.org/licenses/>.
*/
#include <cassert>
#include <thread>
#include "core/StreamLogger.hpp"
namespace lms::core::logging
{
StreamLogger::StreamLogger(std::ostream& os, EnumSet<Severity> severities)
: _os{ os }
, _severities{ severities }
{
}
void StreamLogger::processLog(const Log& log)
{
assert(isSeverityActive(log.getSeverity()));
_os << std::this_thread::get_id() << " [" << getSeverityName(log.getSeverity()) << "] [" << getModuleName(log.getModule()) << "] " << log.getMessage() << std::endl;
}
} // namespace lms::core::logging
src/libs/core/impl/TraceLogger.cpp
+1
View File
@@ -25,6 +25,7 @@
#include "core/Exception.hpp"
#include "core/ILogger.hpp"
#include "core/String.hpp"
namespace lms::core::tracing
{
src/libs/core/impl/WtLogger.cpp
-75
View File
@@ -1,75 +0,0 @@
/*
* Copyright (C) 2019 Emeric Poupon
*
* This file is part of LMS.
*
* LMS is free software: you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
* the Free Software Foundation, either version 3 of the License, or
* (at your option) any later version.
*
* LMS is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with LMS. If not, see <http://www.gnu.org/licenses/>.
*/
#include "core/WtLogger.hpp"
#include <sstream>
#include <thread>
#include <Wt/WLogger.h>
#include <Wt/WServer.h>
#include "core/Exception.hpp"
namespace lms::core::logging
{
namespace
{
std::string to_string(std::thread::id id)
{
std::ostringstream oss;
oss << id;
return oss.str();
}
} // namespace
WtLogger::WtLogger(Severity minSeverity)
: _minSeverity{ minSeverity }
{
}
std::string WtLogger::computeLogConfig(Severity minSeverity)
{
switch (minSeverity)
{
case Severity::DEBUG:
return "*";
case Severity::INFO:
return "* -debug";
case Severity::WARNING:
return "* -debug -info";
case Severity::ERROR:
return "* -debug -info -warning";
case Severity::FATAL:
return "* -debug -info -warning -error";
}
throw LmsException{ "Unhandled severity" };
}
bool WtLogger::isSeverityActive(Severity severity) const
{
return static_cast<int>(severity) <= static_cast<int>(_minSeverity);
}
void WtLogger::processLog(const Log& log)
{
Wt::log(getSeverityName(log.getSeverity())) << Wt::WLogger::sep << to_string(std::this_thread::get_id()) << Wt::WLogger::sep << "[" << getModuleName(log.getModule()) << "]" << Wt::WLogger::sep << log.getMessage();
}
} // namespace lms::core::logging
src/libs/core/include/core/ILogger.hpp
+7 -1
View File
@@ -19,11 +19,12 @@
#pragma once
#include <filesystem>
#include <memory>
#include <sstream>
#include <string>
#include "core/Service.hpp"
#include "core/String.hpp"
namespace lms::core::logging
{
@@ -57,6 +58,7 @@ namespace lms::core::logging
TRANSCODING,
UI,
UTILS,
WT,
};
const char* getModuleName(Module mod);
@@ -92,7 +94,11 @@ namespace lms::core::logging
virtual bool isSeverityActive(Severity severity) const = 0;
virtual void processLog(const Log& log) = 0;
virtual void processLog(Module module, Severity severity, std::string_view message) = 0;
};
static constexpr Severity defaultMinSeverity{ Severity::INFO };
std::unique_ptr<ILogger> createLogger(Severity minSeverity = defaultMinSeverity, const std::filesystem::path& logFilePath = {});
} // namespace lms::core::logging
#define LMS_LOG(module, severity, message) \
src/libs/core/include/core/StreamLogger.hpp
-42
View File
@@ -1,42 +0,0 @@
/*
* Copyright (C) 2019 Emeric Poupon
*
* This file is part of LMS.
*
* LMS is free software: you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
* the Free Software Foundation, either version 3 of the License, or
* (at your option) any later version.
*
* LMS is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with LMS. If not, see <http://www.gnu.org/licenses/>.
*/
#pragma once
#include "core/EnumSet.hpp"
#include "core/ILogger.hpp"
namespace lms::core::logging
{
class StreamLogger final : public ILogger
{
public:
static constexpr EnumSet<Severity> allSeverities{ Severity::FATAL, Severity::ERROR, Severity::WARNING, Severity::INFO, Severity::DEBUG };
static constexpr EnumSet<Severity> defaultSeverities{ Severity::FATAL, Severity::ERROR, Severity::WARNING, Severity::INFO };
StreamLogger(std::ostream& oss, EnumSet<Severity> severities = defaultSeverities);
bool isSeverityActive(Severity severity) const override { return _severities.contains(severity); }
void processLog(const Log& log) override;
private:
std::ostream& _os;
const EnumSet<Severity> _severities;
};
} // namespace lms::core::logging
src/libs/services/scrobbling/test/Scrobbling.cpp
+1 -2
View File
@@ -21,13 +21,12 @@
#include "core/ILogger.hpp"
#include "core/Service.hpp"
#include "core/StreamLogger.hpp"
int main(int argc, char** argv)
{
using namespace lms;
// log to stdout
core::Service<core::logging::ILogger> logger{ std::make_unique<core::logging::StreamLogger>(std::cout, core::EnumSet<core::logging::Severity>{ core::logging::Severity::FATAL, core::logging::Severity::ERROR }) };
core::Service<core::logging::ILogger> logger{ core::logging::createLogger(core::logging::Severity::ERROR) };
::testing::InitGoogleTest(&argc, argv);
return RUN_ALL_TESTS();
src/lms/main.cpp
+84 -33
View File
@@ -20,18 +20,19 @@
#include <thread>
#include <Wt/WApplication.h>
#include <Wt/WLogSink.h>
#include <Wt/WServer.h>
#include <boost/asio/io_context.hpp>
#include <boost/property_tree/xml_parser.hpp>
#include "core/IChildProcessManager.hpp"
#include "core/IConfig.hpp"
#include "core/ILogger.hpp"
#include "core/IOContextRunner.hpp"
#include "core/ITraceLogger.hpp"
#include "core/Service.hpp"
#include "core/String.hpp"
#include "core/SystemPaths.hpp"
#include "core/WtLogger.hpp"
#include "database/IDb.hpp"
#include "database/IQueryPlanRecorder.hpp"
#include "database/Session.hpp"
@@ -64,24 +65,6 @@ namespace lms
return configHttpServerThreadCount ? configHttpServerThreadCount : std::max<unsigned long>(2, std::thread::hardware_concurrency());
}
core::logging::Severity getLogMinSeverity()
{
std::string_view minSeverity{ core::Service<core::IConfig>::get()->getString("log-min-severity", "info") };
if (minSeverity == "debug")
return core::logging::Severity::DEBUG;
else if (minSeverity == "info")
return core::logging::Severity::INFO;
else if (minSeverity == "warning")
return core::logging::Severity::WARNING;
else if (minSeverity == "error")
return core::logging::Severity::ERROR;
else if (minSeverity == "fatal")
return core::logging::Severity::FATAL;
throw core::LmsException{ "Invalid config value for 'log-min-severity'" };
}
ui::AuthenticationBackend getUIAuthenticationBackend()
{
const std::string backend{ core::stringUtils::stringToLower(core::Service<core::IConfig>::get()->getString("authentication-backend", "internal")) };
@@ -109,15 +92,13 @@ namespace lms
throw core::LmsException{ "Invalid config value for 'tracing-level'" };
}
std::vector<std::string> generateWtConfig(std::string execPath, core::logging::Severity minSeverity)
std::vector<std::string> generateWtConfig(std::string execPath)
{
core::IConfig& config{ *core::Service<core::IConfig>::get() };
std::vector<std::string> args;
const std::filesystem::path wtConfigPath{ config.getPath("working-dir", "/var/lms") / "wt_config.xml" };
const std::filesystem::path wtLogFilePath{ config.getPath("log-file", "") };
const std::filesystem::path wtAccessLogFilePath{ config.getPath("access-log-file", "") };
const std::filesystem::path wtResourcesPath{ config.getPath("wt-resources", "/usr/share/Wt/resources") };
args.push_back(execPath);
@@ -142,19 +123,12 @@ namespace lms
args.push_back("--http-address=" + std::string{ config.getString("listen-addr", "0.0.0.0") });
}
if (!wtAccessLogFilePath.empty())
args.push_back("--accesslog=" + wtAccessLogFilePath.string());
args.push_back("--threads=" + std::to_string(getThreadCount()));
// Generate the wt_config.xml file
boost::property_tree::ptree pt;
pt.put("server.application-settings.<xmlattr>.location", "*");
pt.put("server.application-settings.log-file", wtLogFilePath.string());
// log-config
pt.put("server.application-settings.log-config", core::logging::WtLogger::computeLogConfig(minSeverity));
// Reverse proxy
if (config.getBool("behind-reverse-proxy", false))
@@ -238,6 +212,82 @@ namespace lms
});
});
}
core::logging::Severity getLogMinSeverity()
{
std::string_view minSeverity{ core::Service<core::IConfig>::get()->getString("log-min-severity", "info") };
if (minSeverity == "debug")
return core::logging::Severity::DEBUG;
else if (minSeverity == "info")
return core::logging::Severity::INFO;
else if (minSeverity == "warning")
return core::logging::Severity::WARNING;
else if (minSeverity == "error")
return core::logging::Severity::ERROR;
else if (minSeverity == "fatal")
return core::logging::Severity::FATAL;
throw core::LmsException{ "Invalid config value for 'log-min-severity'" };
}
class LmsLogSink : public Wt::WLogSink
{
public:
LmsLogSink(core::logging::ILogger& logger)
: _logger{ logger }
{
}
private:
void log(const std::string& type, const std::string& scope, const std::string& message) const noexcept override
{
// Some wt code path may go here without testing logging()
if (logging(type, scope))
{
const core::logging::Severity severity{ getSeverity(type, scope) };
_logger.processLog(core::logging::Module::WT, severity, message);
}
}
bool logging(const std::string& type, const std::string& scope) const noexcept override
{
const core::logging::Severity severity{ getSeverity(type, scope) };
return _logger.isSeverityActive(severity);
}
static core::logging::Severity getSeverity(const std::string& type, const std::string& scope)
{
return adjustSeverity(getSeverityFromString(type), scope);
}
static core::logging::Severity adjustSeverity(core::logging::Severity initialSeverity, std::string_view scope)
{
if (initialSeverity == core::logging::Severity::INFO && (scope == "WebRequest" || scope == "wthttp"))
return core::logging::Severity::DEBUG;
return initialSeverity;
}
static core::logging::Severity getSeverityFromString(std::string_view type)
{
if (type == "debug")
return core::logging::Severity::DEBUG;
if (type == "info")
return core::logging::Severity::INFO;
if (type == "warning")
return core::logging::Severity::WARNING;
if (type == "error")
return core::logging::Severity::ERROR;
if (type == "fatal")
return core::logging::Severity::FATAL;
return core::logging::Severity::INFO;
}
core::logging::ILogger& _logger;
};
} // namespace
int main(int argc, char* argv[])
@@ -275,8 +325,7 @@ namespace lms
close(STDIN_FILENO);
core::Service<core::IConfig> config{ core::createConfig(configFilePath) };
const core::logging::Severity minLogSeverity{ getLogMinSeverity() };
core::Service<core::logging::ILogger> logger{ std::make_unique<core::logging::WtLogger>(minLogSeverity) };
core::Service<core::logging::ILogger> logger{ createLogger(getLogMinSeverity(), config->getPath("log-file", "")) };
core::Service<core::tracing::ITraceLogger> traceLogger;
if (const auto level{ getTracingLevel() })
traceLogger.assign(core::tracing::createTraceLogger(level.value(), config->getULong("tracing-buffer-size", core::tracing::MinBufferSizeInMBytes)));
@@ -292,7 +341,7 @@ namespace lms
std::filesystem::create_directories(config->getPath("working-dir", "/var/lms") / "cache");
// Construct WT configuration and get the argc/argv back
const std::vector<std::string> wtServerArgs{ generateWtConfig(argv[0], minLogSeverity) };
const std::vector<std::string> wtServerArgs{ generateWtConfig(argv[0]) };
std::vector<const char*> wtArgv(wtServerArgs.size());
for (std::size_t i = 0; i < wtServerArgs.size(); ++i)
@@ -301,8 +350,9 @@ namespace lms
wtArgv[i] = wtServerArgs[i].c_str();
}
boost::asio::io_context ioContext; // ioContext used to dispatch all the services that are out of the Wt event loop
LmsLogSink lmsLogSink{ *logger };
Wt::WServer server{ argv[0] };
server.setCustomLogger(lmsLogSink);
server.setServerConfiguration(wtServerArgs.size(), const_cast<char**>(&wtArgv[0]));
// As initialization can take a while (db migration, analyze, etc.), we bind a temporary init entry point to warn the user
@@ -314,6 +364,7 @@ namespace lms
LMS_LOG(MAIN, INFO, "Starting init web server...");
server.start();
boost::asio::io_context ioContext; // ioContext used to dispatch all the services that are out of the Wt event loop
core::IOContextRunner ioContextRunner{ ioContext, getThreadCount(), "Misc" };
core::Service<db::IQueryPlanRecorder> queryPlanRecorder;
src/tools/db-generator/LmsDbGenerator.cpp
+2 -2
View File
@@ -28,9 +28,9 @@
#include <boost/program_options.hpp>
#include "core/IConfig.hpp"
#include "core/ILogger.hpp"
#include "core/Random.hpp"
#include "core/Service.hpp"
#include "core/StreamLogger.hpp"
#include "core/SystemPaths.hpp"
#include "database/IDb.hpp"
#include "database/Session.hpp"
@@ -184,7 +184,7 @@ int main(int argc, char* argv[])
namespace program_options = boost::program_options;
// log to stdout
core::Service<core::logging::ILogger> logger{ std::make_unique<core::logging::StreamLogger>(std::cout) };
core::Service<core::logging::ILogger> logger{ core::logging::createLogger() };
const GeneratorParameters defaultParams;
src/tools/metadata/LmsMetadata.cpp
+2 -2
View File
@@ -28,7 +28,7 @@
#include <boost/program_options.hpp>
#include "core/EnumSet.hpp"
#include "core/StreamLogger.hpp"
#include "core/ILogger.hpp"
#include "core/String.hpp"
#include "metadata/Exception.hpp"
#include "metadata/IAudioFileParser.hpp"
@@ -456,7 +456,7 @@ int main(int argc, char* argv[])
}
// log to stdout
core::Service<core::logging::ILogger> logger{ std::make_unique<core::logging::StreamLogger>(std::cout, core::logging::StreamLogger::allSeverities) };
core::Service<core::logging::ILogger> logger{ core::logging::createLogger(core::logging::Severity::DEBUG) };
for (const std::string& inputFile : inputFiles)
{
src/tools/recommendation/LmsRecommendation.cpp
+2 -2
View File
@@ -24,8 +24,8 @@
#include <boost/program_options.hpp>
#include "core/IConfig.hpp"
#include "core/ILogger.hpp"
#include "core/Service.hpp"
#include "core/StreamLogger.hpp"
#include "core/SystemPaths.hpp"
#include "database/IDb.hpp"
#include "database/Session.hpp"
@@ -129,7 +129,7 @@ int main(int argc, char* argv[])
namespace po = boost::program_options;
// log to stdout
core::Service<core::logging::ILogger> logger{ std::make_unique<core::logging::StreamLogger>(std::cout) };
core::Service<core::logging::ILogger> logger{ core::logging::createLogger() };
po::options_description desc{ "Allowed options" };
desc.add_options()("help,h", "print usage message")("conf,c", po::value<std::string>()->default_value(core::sysconfDirectory / "lms.conf"), "LMS config file")("artists,a", "Display recommendation for artists")("releases,r", "Display recommendation for releases")("tracks,t", "Display recommendation for tracks")("max,m", po::value<unsigned>()->default_value(3), "Max similarity result count");