Simplified logger configuration, it no longer depends on Wt

This commit is contained in:
emeric
2023-11-24 16:23:31 +01:00
parent 6f47c32ac2
commit 9060c0d925
104 changed files with 2603 additions and 2598 deletions
@@ -26,7 +26,7 @@
#include "services/database/Session.hpp"
#include "services/database/Track.hpp"
#include "services/database/User.hpp"
#include "utils/Logger.hpp"
#include "utils/ILogger.hpp"
#include "internal/InternalBackend.hpp"
#include "listenbrainz/ListenBrainzBackend.hpp"
@@ -43,15 +43,15 @@ namespace Scrobbling
ScrobblingService::ScrobblingService(boost::asio::io_context& ioContext, Db& db)
: _db{ db }
{
LMS_LOG(SCROBBLING, INFO) << "Starting service...";
LMS_LOG(SCROBBLING, INFO, "Starting service...");
_scrobblingBackends.emplace(ScrobblingBackend::Internal, std::make_unique<InternalBackend>(_db));
_scrobblingBackends.emplace(ScrobblingBackend::ListenBrainz, std::make_unique<ListenBrainz::ListenBrainzBackend>(ioContext, _db));
LMS_LOG(SCROBBLING, INFO) << "Service started!";
LMS_LOG(SCROBBLING, INFO, "Service started!");
}
ScrobblingService::~ScrobblingService()
{
LMS_LOG(SCROBBLING, INFO) << "Service stopped!";
LMS_LOG(SCROBBLING, INFO, "Service stopped!");
}
void ScrobblingService::listenStarted(const Listen& listen)
@@ -24,7 +24,7 @@
#include "services/database/Track.hpp"
#include "utils/IConfig.hpp"
#include "utils/http/IClient.hpp"
#include "utils/Logger.hpp"
#include "utils/ILogger.hpp"
#include "utils/Service.hpp"
#include "Utils.hpp"
@@ -44,7 +44,7 @@ namespace Scrobbling::ListenBrainz
const bool res{ duration >= std::chrono::minutes(4) || (duration >= track->getDuration() / 2) };
if (!res)
LOG(DEBUG) << "Track cannot be scrobbled since played duration is too short: " << duration.count() << "s, total duration = " << std::chrono::duration_cast<std::chrono::seconds>(track->getDuration()).count() << "s";
LOG(DEBUG, "Track cannot be scrobbled since played duration is too short: " << duration.count() << "s, total duration = " << std::chrono::duration_cast<std::chrono::seconds>(track->getDuration()).count() << "s");
return res;
}
@@ -57,12 +57,12 @@ namespace Scrobbling::ListenBrainz
, _client{ Http::createClient(_ioContext, _baseAPIUrl) }
, _listensSynchronizer{ _ioContext, db, *_client }
{
LOG(INFO) << "Starting ListenBrainz backend... API endpoint = '" << _baseAPIUrl << "'";
LOG(INFO, "Starting ListenBrainz backend... API endpoint = '" << _baseAPIUrl << "'");
}
ListenBrainzBackend::~ListenBrainzBackend()
{
LOG(INFO) << "Stopped ListenBrainz backend!";
LOG(INFO, "Stopped ListenBrainz backend!");
}
void ListenBrainzBackend::listenStarted(const Listen& listen)
@@ -24,86 +24,82 @@
#include <Wt/Json/Value.h>
#include <Wt/Json/Parser.h>
#include "utils/Logger.hpp"
#include "utils/ILogger.hpp"
#include "Utils.hpp"
namespace
{
using namespace Scrobbling::ListenBrainz;
Listen
parseListen(const Wt::Json::Object& listenObject)
{
Listen listen;
// Mandatory fields
const Wt::Json::Object& metadata = listenObject.get("track_metadata");
listen.trackName = static_cast<std::string>(metadata.get("track_name"));
listen.artistName = static_cast<std::string>(metadata.get("artist_name"));
// Optional fields
listen.releaseName = static_cast<std::string>(metadata.get("release_name").orIfNull(""));
if (listenObject.type("listened_at") == Wt::Json::Type::Number)
listen.listenedAt = Wt::WDateTime::fromTime_t(static_cast<int>(listenObject.get("listened_at")));
if (!listen.listenedAt.isValid())
LOG(ERROR) << "Invalid or missing 'listened_at' field!";
if (metadata.type("additional_info") == Wt::Json::Type::Object)
{
const Wt::Json::Object& additionalInfo = metadata.get("additional_info");
listen.trackMBID = UUID::fromString(additionalInfo.get("track_mbid").orIfNull(""));
listen.recordingMBID = UUID::fromString(additionalInfo.get("recording_mbid").orIfNull(""));
listen.releaseMBID = UUID::fromString(additionalInfo.get("release_mbid").orIfNull(""));
// tracknumber should be an integer but some players encode as strings
int trackNumber {additionalInfo.get("tracknumber").toNumber().orIfNull(-1)};
if (trackNumber > 0)
listen.trackNumber = trackNumber;
}
return listen;
}
} // namespace
namespace Scrobbling::ListenBrainz
{
ListensParser::Result
ListensParser::parse(std::string_view msgBody)
{
Result result;
namespace
{
Listen parseListen(const Wt::Json::Object& listenObject)
{
Listen listen;
try
{
Wt::Json::Object root;
Wt::Json::parse(std::string {msgBody}, root);
// Mandatory fields
const Wt::Json::Object& metadata = listenObject.get("track_metadata");
listen.trackName = static_cast<std::string>(metadata.get("track_name"));
listen.artistName = static_cast<std::string>(metadata.get("artist_name"));
const Wt::Json::Object& payload = root.get("payload");
const Wt::Json::Array& listens = payload.get("listens");
// Optional fields
listen.releaseName = static_cast<std::string>(metadata.get("release_name").orIfNull(""));
if (listenObject.type("listened_at") == Wt::Json::Type::Number)
listen.listenedAt = Wt::WDateTime::fromTime_t(static_cast<int>(listenObject.get("listened_at")));
if (!listen.listenedAt.isValid())
LOG(ERROR, "Invalid or missing 'listened_at' field!");
LOG(DEBUG) << "Parsing " << listens.size() << " listens...";
result.listenCount = listens.size();
if (metadata.type("additional_info") == Wt::Json::Type::Object)
{
const Wt::Json::Object& additionalInfo = metadata.get("additional_info");
listen.trackMBID = UUID::fromString(additionalInfo.get("track_mbid").orIfNull(""));
listen.recordingMBID = UUID::fromString(additionalInfo.get("recording_mbid").orIfNull(""));
listen.releaseMBID = UUID::fromString(additionalInfo.get("release_mbid").orIfNull(""));
if (listens.empty())
return result;
// tracknumber should be an integer but some players encode as strings
int trackNumber{ additionalInfo.get("tracknumber").toNumber().orIfNull(-1) };
if (trackNumber > 0)
listen.trackNumber = trackNumber;
}
for (const Wt::Json::Value& value : listens)
{
try
{
const Wt::Json::Object& listen = value;
result.listens.push_back(parseListen(listen));
}
catch (const Wt::WException& error)
{
LOG(ERROR) << "Cannot parse 'listen': " << error.what();
}
}
}
catch (const Wt::WException& error)
{
LOG(ERROR) << "Cannot parse 'listens': " << error.what();
}
return listen;
}
} // namespace
return result;
}
ListensParser::Result ListensParser::parse(std::string_view msgBody)
{
Result result;
try
{
Wt::Json::Object root;
Wt::Json::parse(std::string{ msgBody }, root);
const Wt::Json::Object& payload = root.get("payload");
const Wt::Json::Array& listens = payload.get("listens");
LOG(DEBUG, "Parsing " << listens.size() << " listens...");
result.listenCount = listens.size();
if (listens.empty())
return result;
for (const Wt::Json::Value& value : listens)
{
try
{
const Wt::Json::Object& listen = value;
result.listens.push_back(parseListen(listen));
}
catch (const Wt::WException& error)
{
LOG(ERROR, "Cannot parse 'listen': " << error.what());
}
}
}
catch (const Wt::WException& error)
{
LOG(ERROR, "Cannot parse 'listens': " << error.what());
}
return result;
}
} // Scrobbling::ListenBrainz
@@ -58,7 +58,7 @@ namespace
if (artists.empty())
{
LOG(DEBUG) << "Track cannot be scrobbled since it does not have any artist";
LOG(DEBUG, "Track cannot be scrobbled since it does not have any artist");
return std::nullopt;
}
@@ -134,7 +134,7 @@ namespace
}
catch (const Wt::WException& e)
{
LOG(ERROR) << "Cannot parse listen count response: " << e.what();
LOG(ERROR, "Cannot parse listen count response: " << e.what());
return std::nullopt;
}
}
@@ -152,12 +152,12 @@ namespace
// if duplicated files, do not record it (let the user correct its database)
if (tracks.size() == 1)
{
LOG(DEBUG) << "Matched listen '" << listen << "' using track MBID";
LOG(DEBUG, "Matched listen '" << listen << "' using track MBID");
return tracks.front()->getId();
}
else if (tracks.size() > 1)
{
LOG(DEBUG) << "Too many matches for listen '" << listen << "' using track MBID!";
LOG(DEBUG, "Too many matches for listen '" << listen << "' using track MBID!");
return {};
}
}
@@ -168,12 +168,12 @@ namespace
// if duplicated files, do not record it (let the user correct its database)
if (tracks.size() == 1)
{
LOG(DEBUG) << "Matched listen '" << listen << "' using recording MBID";
LOG(DEBUG, "Matched listen '" << listen << "' using recording MBID");
return tracks.front()->getId();
}
else if (tracks.size() > 1)
{
LOG(DEBUG) << "Too many matches for listen '" << listen << "' using recording MBID!";
LOG(DEBUG, "Too many matches for listen '" << listen << "' using recording MBID!");
return {};
}
}
@@ -192,16 +192,16 @@ namespace
// conservative behavior: in case of multiple matches: reject
if (tracks.results.size() == 1)
{
LOG(DEBUG) << "Matched listen '" << listen << "' using metadata";
LOG(DEBUG, "Matched listen '" << listen << "' using metadata");
return tracks.results.front();
}
else if (tracks.results.size() > 1)
{
LOG(DEBUG) << "Too many matches for listen '" << listen << "' using metadata";
LOG(DEBUG, "Too many matches for listen '" << listen << "' using metadata");
return {};
}
LOG(DEBUG) << "No match for listen '" << listen << "'";
LOG(DEBUG, "No match for listen '" << listen << "'");
return {};
}
}
@@ -215,7 +215,7 @@ namespace Scrobbling::ListenBrainz
, _maxSyncListenCount{ Service<IConfig>::get()->getULong("listenbrainz-max-sync-listen-count", 1000) }
, _syncListensPeriod{ Service<IConfig>::get()->getULong("listenbrainz-sync-listens-period-hours", 1) }
{
LOG(INFO) << "Starting Listens synchronizer, maxSyncListenCount = " << _maxSyncListenCount << ", _syncListensPeriod = " << _syncListensPeriod.count() << " hours";
LOG(INFO, "Starting Listens synchronizer, maxSyncListenCount = " << _maxSyncListenCount << ", _syncListensPeriod = " << _syncListensPeriod.count() << " hours");
scheduleSync(std::chrono::seconds{ 30 });
}
@@ -267,14 +267,14 @@ namespace Scrobbling::ListenBrainz
std::string bodyText{ listenToJsonString(_db.getTLSSession(), listen, timePoint, timePoint.isValid() ? "single" : "playing_now") };
if (bodyText.empty())
{
LOG(DEBUG) << "Cannot convert listen to json: skipping";
LOG(DEBUG, "Cannot convert listen to json: skipping");
return;
}
const std::optional<UUID> listenBrainzToken{ Utils::getListenBrainzToken(_db.getTLSSession(), listen.userId) };
if (!listenBrainzToken)
{
LOG(DEBUG) << "No listenbrainz token found: skipping";
LOG(DEBUG, "No listenbrainz token found: skipping");
return;
}
@@ -305,7 +305,7 @@ namespace Scrobbling::ListenBrainz
dbListen = session.create<Database::Listen>(user, track, Database::ScrobblingBackend::ListenBrainz, listen.listenedAt);
dbListen.modify()->setSyncState(scrobblingState);
LOG(DEBUG) << "LISTEN CREATED for user " << user->getLoginName() << ", track '" << track->getName() << "' AT " << listen.listenedAt.toString();
LOG(DEBUG, "LISTEN CREATED for user " << user->getLoginName() << ", track '" << track->getName() << "' AT " << listen.listenedAt.toString());
return true;
}
@@ -347,7 +347,7 @@ namespace Scrobbling::ListenBrainz
}
}
LOG(DEBUG) << "Queing " << pendingListens.size() << " pending listen";
LOG(DEBUG, "Queing " << pendingListens.size() << " pending listen");
for (const TimedListen& pendingListen : pendingListens)
enqueListen(pendingListen);
@@ -379,13 +379,13 @@ namespace Scrobbling::ListenBrainz
if (_syncListensPeriod.count() == 0 || _maxSyncListenCount == 0)
return;
LOG(DEBUG) << "Scheduled sync in " << fromNow.count() << " seconds...";
LOG(DEBUG, "Scheduled sync in " << fromNow.count() << " seconds...");
_syncTimer.expires_after(fromNow);
_syncTimer.async_wait(boost::asio::bind_executor(_strand, [this](const boost::system::error_code& ec)
{
if (ec == boost::asio::error::operation_aborted)
{
LOG(DEBUG) << "getListens aborted";
LOG(DEBUG, "getListens aborted");
return;
}
else if (ec)
@@ -399,7 +399,7 @@ namespace Scrobbling::ListenBrainz
void ListensSynchronizer::startSync()
{
LOG(DEBUG) << "Starting sync!";
LOG(DEBUG, "Starting sync!");
assert(!isSyncing());
@@ -435,7 +435,7 @@ namespace Scrobbling::ListenBrainz
{
_strand.dispatch([this, &context]
{
LOG(INFO) << "Sync done for user '" << context.listenBrainzUserName << "', fetched: " << context.fetchedListenCount << ", matched: " << context.matchedListenCount << ", imported: " << context.importedListenCount;
LOG(INFO, "Sync done for user '" << context.listenBrainzUserName << "', fetched: " << context.fetchedListenCount << ", matched: " << context.matchedListenCount << ", imported: " << context.importedListenCount);
context.syncing = false;
if (!isSyncing())
@@ -489,7 +489,7 @@ namespace Scrobbling::ListenBrainz
{
const auto listenCount = parseListenCount(msgBody);
if (listenCount)
LOG(DEBUG) << "Listen count for listenbrainz user '" << context.listenBrainzUserName << "' = " << *listenCount;
LOG(DEBUG, "Listen count for listenbrainz user '" << context.listenBrainzUserName << "' = " << *listenCount);
bool needSync{ listenCount && (!context.listenCount || *context.listenCount != *listenCount) };
context.listenCount = listenCount;
@@ -551,7 +551,7 @@ namespace Scrobbling::ListenBrainz
// update oldest listen for the next query
if (!parsedListen.listenedAt.isValid())
{
LOG(DEBUG) << "Skipping entry due to invalid listenedAt";
LOG(DEBUG, "Skipping entry due to invalid listenedAt");
continue;
}
@@ -27,38 +27,36 @@
namespace Scrobbling::ListenBrainz::Utils
{
std::optional<UUID>
getListenBrainzToken(Database::Session& session, Database::UserId userId)
{
auto transaction {session.createReadTransaction()};
std::optional<UUID> getListenBrainzToken(Database::Session& session, Database::UserId userId)
{
auto transaction{ session.createReadTransaction() };
const Database::User::pointer user {Database::User::find(session, userId)};
if (!user)
return std::nullopt;
const Database::User::pointer user{ Database::User::find(session, userId) };
if (!user)
return std::nullopt;
return user->getListenBrainzToken();
}
return user->getListenBrainzToken();
}
std::string
parseValidateToken(std::string_view msgBody)
{
std::string listenBrainzUserName;
std::string parseValidateToken(std::string_view msgBody)
{
std::string listenBrainzUserName;
Wt::Json::ParseError error;
Wt::Json::Object root;
if (!Wt::Json::parse(std::string {msgBody}, root, error))
{
LOG(ERROR) << "Cannot parse 'validate-token' result: " << error.what();
return listenBrainzUserName;
}
Wt::Json::ParseError error;
Wt::Json::Object root;
if (!Wt::Json::parse(std::string{ msgBody }, root, error))
{
LOG(ERROR, "Cannot parse 'validate-token' result: " << error.what());
return listenBrainzUserName;
}
if (!root.get("valid").orIfNull(false))
{
LOG(INFO) << "Invalid listenbrainz user";
return listenBrainzUserName;
}
if (!root.get("valid").orIfNull(false))
{
LOG(INFO, "Invalid listenbrainz user");
return listenBrainzUserName;
}
listenBrainzUserName = root.get("user_name").orIfNull("");
return listenBrainzUserName;
}
listenBrainzUserName = root.get("user_name").orIfNull("");
return listenBrainzUserName;
}
}
@@ -20,10 +20,10 @@
#pragma once
#include "services/database/UserId.hpp"
#include "utils/Logger.hpp"
#include "utils/ILogger.hpp"
#include "utils/UUID.hpp"
#define LOG(sev) LMS_LOG(SCROBBLING, sev) << "[listenbrainz] "
#define LOG(sev, message) LMS_LOG(SCROBBLING, sev, message << "[listenbrainz] ")
namespace Database
{
@@ -19,16 +19,16 @@
#include <gtest/gtest.h>
#include "utils/Logger.hpp"
#include "utils/ILogger.hpp"
#include "utils/Service.hpp"
#include "utils/StreamLogger.hpp"
int main(int argc, char **argv)
int main(int argc, char** argv)
{
// log to stdout
Service<Logger> logger {std::make_unique<StreamLogger>(std::cout, EnumSet<Severity> {Severity::FATAL, Severity::ERROR})};
// log to stdout
Service<ILogger> logger{ std::make_unique<StreamLogger>(std::cout, EnumSet<Severity> {Severity::FATAL, Severity::ERROR}) };
::testing::InitGoogleTest(&argc, argv);
return RUN_ALL_TESTS();
::testing::InitGoogleTest(&argc, argv);
return RUN_ALL_TESTS();
}