From 2d06de854819de0f2d6f488b64d5a4b09c2b9668 Mon Sep 17 00:00:00 2001 From: NamedKitten Date: Sun, 9 Dec 2018 02:35:08 +0000 Subject: [PATCH] [Logging] Improved logging using spdlog. Also increased build time by 5x! --- CMakeLists.txt | 18 +++++++- src/MpvPlayerBackend.cpp | 32 +++++++++++--- src/logger.cpp | 21 +++++++++ src/logger.h | 20 +++++++++ src/main.cpp | 55 +++++++++++++++++++++--- src/qml/ControlsBar.qml | 2 +- src/qml/UIComponents/PlayPauseButton.qml | 1 - src/qml/UIComponents/VolumeButton.qml | 3 -- src/qml/main.qml | 2 + src/utils.cpp | 31 ++++++++----- 10 files changed, 157 insertions(+), 28 deletions(-) create mode 100644 src/logger.cpp create mode 100644 src/logger.h diff --git a/CMakeLists.txt b/CMakeLists.txt index bd3df40..e20aae8 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -4,8 +4,13 @@ project(KittehPlayer) include_directories(${CMAKE_SOURCE_DIR} ${CMAKE_BINARY_DIR}) set(CMAKE_AUTOMOC ON) +include(ExternalProject) + + find_package(Qt5Core REQUIRED) find_package(Qt5Gui REQUIRED) +find_package(Qt5Concurrent REQUIRED) + find_package(Qt5 CONFIG REQUIRED COMPONENTS Qml Quick Gui Widgets Core X11Extras) find_package(Qt5QuickCompiler) @@ -16,6 +21,16 @@ pkg_check_modules(MPV REQUIRED mpv) pkg_check_modules(X11 x11) pkg_check_modules(Xext xext) + +execute_process( + COMMAND git clone --depth 1 https://github.com/gabime/spdlog.git + WORKING_DIRECTORY ${CMAKE_BINARY_DIR} +) + +include_directories(${CMAKE_BINARY_DIR}/spdlog/include) + + + if(X11_FOUND AND Xext_FOUND) add_definitions(-DENABLE_X11) endif(X11_FOUND AND Xext_FOUND) @@ -27,6 +42,7 @@ set(SOURCES src/enums.hpp src/Process.cpp src/ThumbnailCache.cpp + src/logger.cpp ) if(MPV_VERSION VERSION_GREATER_EQUAL "1.28.0") @@ -58,7 +74,7 @@ add_executable(KittehPlayer ${SOURCES} ${qml_QRC}) # Use the Qml/Quick modules from Qt 5. target_link_libraries(KittehPlayer ${MPV_LIBRARIES} ${X11_LIBRARIES} ${Xext_LIBRARIES} Qt5::X11Extras) -include_directories(${Qt5Gui_PRIVATE_INCLUDE_DIRS}) +include_directories(${Qt5Gui_PRIVATE_INCLUDE_DIRS} ${Qt5Concurrent_INCLUDE_DIRS}) qt5_use_modules(KittehPlayer Qml Quick Core Gui Widgets X11Extras) install (TARGETS ${PROJECT_NAME} DESTINATION bin) diff --git a/src/MpvPlayerBackend.cpp b/src/MpvPlayerBackend.cpp index c8480e3..2f5079e 100644 --- a/src/MpvPlayerBackend.cpp +++ b/src/MpvPlayerBackend.cpp @@ -1,8 +1,5 @@ #include "MpvPlayerBackend.h" -#include -#include -#include - +#include "logger.h" #include "utils.hpp" #include #include @@ -10,7 +7,10 @@ #include #include #include +#include #include +#include +#include #ifdef __linux__ #include @@ -20,6 +20,8 @@ #include #endif +auto mpvLogger = initLogger("mpv"); + namespace { void @@ -80,13 +82,11 @@ public: if (QGuiApplication::platformName().contains("xcb")) { params[2].type = MPV_RENDER_PARAM_X11_DISPLAY; params[2].data = QX11Info::display(); - qDebug() << "On Xorg."; } else if (QGuiApplication::platformName().contains("wayland")) { QPlatformNativeInterface* native = QGuiApplication::platformNativeInterface(); params[2].type = MPV_RENDER_PARAM_WL_DISPLAY; params[2].data = native->nativeResourceForWindow("display", nullptr); - qDebug() << "On wayland."; } #endif @@ -129,10 +129,11 @@ MpvPlayerBackend::MpvPlayerBackend(QQuickItem* parent) , mpv{ mpv_create() } , mpv_gl(nullptr) { + mpvLogger->set_pattern("%^[%d-%m-%Y %T.%e][%l][%n]%v%$"); if (!mpv) throw std::runtime_error("could not create mpv context"); - mpv_set_option_string(mpv, "terminal", "off"); + mpv_set_option_string(mpv, "terminal", "on"); mpv_set_option_string(mpv, "msg-level", "all=v"); // Fix? @@ -161,6 +162,9 @@ MpvPlayerBackend::MpvPlayerBackend(QQuickItem* parent) mpv_observe_property(mpv, 0, "pause", MPV_FORMAT_NODE); mpv_observe_property(mpv, 0, "playlist", MPV_FORMAT_NODE); mpv_observe_property(mpv, 0, "speed", MPV_FORMAT_DOUBLE); + + mpv_request_log_messages(mpv, "debug"); + mpv_set_wakeup_callback(mpv, wakeup, this); if (mpv_initialize(mpv) < 0) @@ -550,6 +554,20 @@ MpvPlayerBackend::handle_mpv_event(mpv_event* event) } break; } + + case MPV_EVENT_LOG_MESSAGE: { + struct mpv_event_log_message* msg = + (struct mpv_event_log_message*)event->data; + QString logMsg = "[" + QString(msg->prefix) + "] " + QString(msg->text); + QString msgLevel = QString(msg->level); + if (msgLevel.startsWith("d")) { + mpvLogger->debug("{}", logMsg.toUtf8().constData()); + } else if (msgLevel.startsWith("v") || msgLevel.startsWith("i")) { + mpvLogger->info("{}", logMsg.toUtf8().constData()); + } + + break; + } case MPV_EVENT_SHUTDOWN: { qApp->exit(); break; diff --git a/src/logger.cpp b/src/logger.cpp new file mode 100644 index 0000000..9b3c4dc --- /dev/null +++ b/src/logger.cpp @@ -0,0 +1,21 @@ +#include "logger.h" + +#include +#include +#include + +std::shared_ptr +initLogger(std::string name) +{ + std::vector sinks; + sinks.push_back(std::make_shared()); + sinks.push_back(std::make_shared( + "/tmp/KittehPlayer.log")); + auto console = + std::make_shared(name, begin(sinks), end(sinks)); + console->set_pattern("%^[%d-%m-%Y %T.%e][%l][%n] %v%$"); + + spdlog::register_logger(console); + + return spdlog::get(name); +} diff --git a/src/logger.h b/src/logger.h new file mode 100644 index 0000000..9d1f657 --- /dev/null +++ b/src/logger.h @@ -0,0 +1,20 @@ +#ifndef LOGGER_HPP +#define LOGGER_HPP +#include + +#include +#include +#include + +#include +#include +#include +#include +#include +#include +#include + +std::shared_ptr +initLogger(std::string name); + +#endif diff --git a/src/main.cpp b/src/main.cpp index 6794853..63a9bd6 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -4,6 +4,7 @@ #endif #include "enums.hpp" +#include "logger.h" #include "utils.hpp" #include @@ -12,6 +13,7 @@ #include #include #include +#include #include #include #include @@ -45,10 +47,50 @@ catchUnixSignals(std::initializer_list quitSignals) } #endif +auto qmlLogger = initLogger("qml"); +auto miscLogger = initLogger("misc"); + +void +spdLogger(QtMsgType type, const QMessageLogContext& context, const QString& msg) +{ + std::string localMsg = msg.toUtf8().constData(); + std::shared_ptr logger; + if (QString(context.category).startsWith(QString("qml"))) { + logger = qmlLogger; + } else { + logger = miscLogger; + } + + switch (type) { + case QtDebugMsg: + logger->debug("{}", localMsg); + break; + case QtInfoMsg: + logger->info("{}", localMsg); + break; + case QtWarningMsg: + logger->warn("{}", localMsg); + break; + case QtCriticalMsg: + logger->critical("{}", localMsg); + break; + case QtFatalMsg: + logger->critical("{}", localMsg); + abort(); + } +} + int main(int argc, char* argv[]) { + qInstallMessageHandler(spdLogger); + + auto launcherLogger = initLogger("launcher"); + + launcherLogger->info("Starting up!"); + + QString backendString; #ifdef DISABLE_MpvPlayerBackend Enums::Backends backend = Enums::Backends::DirectMpvBackend; #else @@ -66,7 +108,6 @@ main(int argc, char* argv[]) QSettings settings; -#ifdef GIT_COMMIT_HASH bool checkForUpdates = settings.value("Backend/checkForUpdatesOnLaunch", false).toBool(); for (int i = 1; i < argc; ++i) { @@ -76,9 +117,8 @@ main(int argc, char* argv[]) } if (checkForUpdates) { - Utils::checkForUpdates(); + QtConcurrent::run(Utils::checkForUpdates); } -#endif QString backendSetting = settings.value("Backend/backend", "").toString(); if (backendSetting.length() == 0) { @@ -88,20 +128,23 @@ main(int argc, char* argv[]) settings.setValue("Backend/backend", "direct-mpv"); #endif } - - qDebug() << backendSetting; + backendString = backendSetting; for (int i = 1; i < argc; ++i) { if (!qstrcmp(argv[i], "--update")) { Utils::updateAppImage(); } else if (!qstrcmp(argv[i], "--backend=mpv") || backendSetting == "mpv") { backend = Enums::Backends::MpvBackend; + backendString = QString("mpv"); } else if (!qstrcmp(argv[i], "--backend=direct-mpv") || backendSetting == "direct-mpv") { + backendString = QString("direct-mpv"); backend = Enums::Backends::DirectMpvBackend; } } + launcherLogger->info("Using backend={}", backendString.toUtf8().constData()); + Utils::SetDPMS(false); QString newpath = @@ -116,6 +159,7 @@ main(int argc, char* argv[]) qRegisterMetaType("Enums.Backends"); qRegisterMetaType("Enums.Commands"); qmlRegisterType("player", 1, 0, "Process"); + qmlRegisterType("player", 1, 0, "ThumbnailCache"); qmlRegisterType("player", 1, 0, "Utils"); @@ -139,6 +183,7 @@ main(int argc, char* argv[]) } std::setlocale(LC_NUMERIC, "C"); + launcherLogger->info("Loading player..."); QQmlApplicationEngine engine; engine.load(QUrl(QStringLiteral("qrc:///main.qml"))); diff --git a/src/qml/ControlsBar.qml b/src/qml/ControlsBar.qml index 7d3a9e3..780bdbe 100644 --- a/src/qml/ControlsBar.qml +++ b/src/qml/ControlsBar.qml @@ -36,7 +36,7 @@ Item { var component = Qt.createComponent(themeName + "ButtonLayout.qml") if (component.status == Component.Error) { - console.log("Error loading component:", component.errorString()) + console.error("Error loading component: " + component.errorString()) } component.createObject(controlsBar, { diff --git a/src/qml/UIComponents/PlayPauseButton.qml b/src/qml/UIComponents/PlayPauseButton.qml index c092694..e0b3652 100644 --- a/src/qml/UIComponents/PlayPauseButton.qml +++ b/src/qml/UIComponents/PlayPauseButton.qml @@ -25,7 +25,6 @@ Button { target: player enabled: true onPlayStatusChanged: function (status) { - console.log(icon.height) if (status == Enums.PlayStatus.Playing) { icon.source = "qrc:/icons/" + appearance.themeName + "/pause.svg" } else if (status == Enums.PlayStatus.Paused) { diff --git a/src/qml/UIComponents/VolumeButton.qml b/src/qml/UIComponents/VolumeButton.qml index 2866c82..5c68e1d 100644 --- a/src/qml/UIComponents/VolumeButton.qml +++ b/src/qml/UIComponents/VolumeButton.qml @@ -24,9 +24,6 @@ Button { } function updateStatus(status) { - if (volumeButton == null) - console.log("OwO") - if (status == Enums.VolumeStatus.Muted) { volumeButton.icon.source = "qrc:/icons/" + appearance.themeName + "/volume-mute.svg" } else if (status == Enums.VolumeStatus.Low) { diff --git a/src/qml/main.qml b/src/qml/main.qml index 4e0cd8a..9457ddb 100644 --- a/src/qml/main.qml +++ b/src/qml/main.qml @@ -202,6 +202,8 @@ Window { } function startPlayer() { + console.info("OwO!") + var args = Qt.application.arguments var len = Qt.application.arguments.length var argNo = 0 diff --git a/src/utils.cpp b/src/utils.cpp index 5e92ad4..261cbd8 100644 --- a/src/utils.cpp +++ b/src/utils.cpp @@ -1,4 +1,6 @@ #include "utils.hpp" +#include "logger.h" + #include #include @@ -20,6 +22,9 @@ #endif #endif +auto utilsLogger = initLogger("utils"); +auto updaterLogger = initLogger("updater"); + namespace Utils { QString getPlatformName() @@ -45,7 +50,8 @@ checkForUpdates() #else QString current_version = QString("Unknown"); #endif - qDebug() << "Current Version: " << current_version; + updaterLogger->info("Current Version: {}", + current_version.toUtf8().constData()); QNetworkRequest request(QUrl("https://api.github.com/repos/NamedKitten/" "KittehPlayer/releases/tags/continuous")); @@ -61,8 +67,10 @@ checkForUpdates() if (json["target_commitish"].toString().length() != 0) { if (json["target_commitish"].toString().endsWith(current_version) == 0) { - qDebug() << "Latest Version: " << json["target_commitish"].toString(); - qDebug() << "Update Available. Please update ASAP."; + updaterLogger->info( + "Latest Version: {}", + json["target_commitish"].toString().toUtf8().constData()); + updaterLogger->info("Update Available. Please update ASAP."); QProcess notifier; notifier.setProcessChannelMode(QProcess::ForwardedChannels); notifier.start("notify-send", @@ -72,13 +80,14 @@ checkForUpdates() notifier.waitForFinished(); } } else { - qDebug() << "Couldn't check for new version."; + updaterLogger->error("Couldn't check for new version."); } } void updateAppImage() { + updaterLogger->info("Launching updater"); QString program = QProcessEnvironment::systemEnvironment().value("APPDIR", "") + "/usr/bin/appimageupdatetool"; @@ -119,11 +128,11 @@ SetScreensaver(WId wid, bool on) QProcess xdgScreensaver; xdgScreensaver.setProcessChannelMode(QProcess::ForwardedChannels); if (on) { - qDebug() << "Enabling screensaver."; + utilsLogger->info("Enabling screensaver."); xdgScreensaver.start("xdg-screensaver", QStringList() << "resume" << QString::number(wid)); } else { - qDebug() << "Disabling screensaver."; + utilsLogger->info("Disabling screensaver."); xdgScreensaver.start("xdg-screensaver", QStringList() << "suspend" << QString::number(wid)); } @@ -140,13 +149,13 @@ SetDPMS(bool on) QProcess xsetProcess; xsetProcess.setProcessChannelMode(QProcess::ForwardedChannels); if (on) { - qDebug() << "Enabled DPMS."; + utilsLogger->info("Enabled DPMS."); xsetProcess.start("xset", QStringList() << "s" << "on" << "+dpms"); } else { - qDebug() << "Disabled DPMS."; + utilsLogger->info("Disabled DPMS."); xsetProcess.start("xset", QStringList() << "s" << "off" @@ -154,7 +163,8 @@ SetDPMS(bool on) } xsetProcess.waitForFinished(); #else - qDebug() << "Can't set DPMS for platform: " << getPlatformName(); + utilsLogger->error("Can't set DPMS for platform: {}", + getPlatformName().toUtf8().constData()); #endif } @@ -186,7 +196,8 @@ AlwaysOnTop(WId wid, bool on) &event); #endif #else - qDebug() << "Can't set on top for platform: " << getPlatformName(); + utilsLogger->error("Can't set on top for platform: {}", + getPlatformName().toUtf8().constData()); #endif } }