Refactored logging enhancements

logging.h/logging.cpp is now a full-fledged pair for all things logging. Two more categories added, EPHEMERAL and SYNCJOB, that control logging for ephemeral events and SyncJob, respectively (in particular, switching off EPHEMERAL greatly reduces the logspam about moving read markers and how many users have read up to which event).

15 files changed, 137 insertions, 104 deletions

diff --git a/CMakeLists.txt b/CMakeLists.txt
index 4692605c..11cf015d 100644
--- a/CMakeLists.txt
+++ b/CMakeLists.txt
@@ -47,7 +47,7 @@ message( STATUS )
 set(libqmatrixclient_SRCS
    connectiondata.cpp
    connection.cpp
-   debug.cpp
+   logging.cpp
    room.cpp
    user.cpp
    state.cpp
diff --git a/connectiondata.cpp b/connectiondata.cpp
index 483d2f0c..6c7eff8c 100644
--- a/connectiondata.cpp
+++ b/connectiondata.cpp
@@ -17,9 +17,9 @@
  */
 
 #include "connectiondata.h"
-#include "util.h"
 
-#include <QtCore/QDebug>
+#include "logging.h"
+
 #include <QtNetwork/QNetworkAccessManager>
 
 using namespace QMatrixClient;
diff --git a/events/event.cpp b/events/event.cpp
index b3f75ca9..07649b02 100644
--- a/events/event.cpp
+++ b/events/event.cpp
@@ -20,10 +20,7 @@
 
 #include <QtCore/QJsonArray>
 #include <QtCore/QJsonDocument>
-#include <QtCore/QDateTime>
-#include <QtCore/QDebug>
 
-#include "util.h"
 #include "roommessageevent.h"
 #include "roomnameevent.h"
 #include "roomaliasesevent.h"
@@ -33,6 +30,8 @@
 #include "typingevent.h"
 #include "receiptevent.h"
 #include "unknownevent.h"
+#include "logging.h"
+#include "util.h"
 
 using namespace QMatrixClient;
 
diff --git a/events/receiptevent.cpp b/events/receiptevent.cpp
index 5d11a0dd..c163424f 100644
--- a/events/receiptevent.cpp
+++ b/events/receiptevent.cpp
@@ -34,10 +34,10 @@ Example of a Receipt Event:
 */
 
 #include "receiptevent.h"
-#include "util.h"
+
+#include "logging.h"
 
 #include <QtCore/QJsonArray>
-#include <QtCore/QDebug>
 
 using namespace QMatrixClient;
 
@@ -73,8 +73,8 @@ ReceiptEvent* ReceiptEvent::fromJson(const QJsonObject& obj)
     {
         if (eventIt.key().isEmpty())
         {
-            qCWarning(EVENTS) << "ReceiptEvent has an empty event id, skipping";
-            qCDebug(EVENTS) << "ReceiptEvent content follows:\n" << contents;
+            qCWarning(EPHEMERAL) << "ReceiptEvent has an empty event id, skipping";
+            qCDebug(EPHEMERAL) << "ReceiptEvent content follows:\n" << contents;
             continue;
         }
         const QJsonObject reads = eventIt.value().toObject().value("m.read").toObject();
diff --git a/events/roomaliasesevent.cpp b/events/roomaliasesevent.cpp
index e0dbdb38..ab414498 100644
--- a/events/roomaliasesevent.cpp
+++ b/events/roomaliasesevent.cpp
@@ -33,10 +33,10 @@
 // }
 
 #include "roomaliasesevent.h"
-#include "util.h"
+
+#include "logging.h"
 
 #include <QtCore/QJsonArray>
-#include <QtCore/QDebug>
 
 using namespace QMatrixClient;
 
diff --git a/events/roommemberevent.cpp b/events/roommemberevent.cpp
index 0dafd303..51dbbbab 100644
--- a/events/roommemberevent.cpp
+++ b/events/roommemberevent.cpp
@@ -17,9 +17,8 @@
  */
 
 #include "roommemberevent.h"
-#include "util.h"
 
-#include <QtCore/QDebug>
+#include "logging.h"
 
 using namespace QMatrixClient;
 
diff --git a/events/roommessageevent.cpp b/events/roommessageevent.cpp
index fd6de464..677bb79f 100644
--- a/events/roommessageevent.cpp
+++ b/events/roommessageevent.cpp
@@ -17,10 +17,11 @@
  */
 
 #include "roommessageevent.h"
+
+#include "logging.h"
 #include "util.h"
 
 #include <QtCore/QMimeDatabase>
-#include <QtCore/QDebug>
 
 using namespace QMatrixClient;
 
diff --git a/events/typingevent.cpp b/events/typingevent.cpp
index 11c3a565..009059af 100644
--- a/events/typingevent.cpp
+++ b/events/typingevent.cpp
@@ -17,10 +17,10 @@
  */
 
 #include "typingevent.h"
-#include "util.h"
+
+#include "logging.h"
 
 #include <QtCore/QJsonArray>
-#include <QtCore/QDebug>
 
 using namespace QMatrixClient;
 
@@ -55,6 +55,6 @@ TypingEvent* TypingEvent::fromJson(const QJsonObject& obj)
     {
         e->d->users << user.toString();
     }
-    qCDebug(EVENTS) << "Typing:" << e->d->users;
+    qCDebug(EPHEMERAL) << "Typing:" << e->d->users;
     return e;
 }
diff --git a/events/unknownevent.cpp b/events/unknownevent.cpp
index b2947bf7..1670ff1d 100644
--- a/events/unknownevent.cpp
+++ b/events/unknownevent.cpp
@@ -18,10 +18,9 @@
 
 #include "unknownevent.h"
 
-#include <QtCore/QJsonDocument>
-#include <QtCore/QDebug>
+#include "logging.h"
 
-#include "util.h"
+#include <QtCore/QJsonDocument>
 
 using namespace QMatrixClient;
 
diff --git a/jobs/basejob.cpp b/jobs/basejob.cpp
index f5de75f4..77f90596 100644
--- a/jobs/basejob.cpp
+++ b/jobs/basejob.cpp
@@ -17,16 +17,15 @@
  */
 
 #include "basejob.h"
-#include "util.h"
 
-#include <array>
+#include "connectiondata.h"
 
 #include <QtNetwork/QNetworkAccessManager>
 #include <QtNetwork/QNetworkRequest>
 #include <QtNetwork/QNetworkReply>
 #include <QtCore/QTimer>
 
-#include "../connectiondata.h"
+#include <array>
 
 using namespace QMatrixClient;
 
@@ -49,10 +48,10 @@ class BaseJob::Private
                 QString endpoint, QUrlQuery q, Data data, bool nt)
             : connection(c), verb(v), apiEndpoint(std::move(endpoint))
             , requestQuery(std::move(q)), requestData(std::move(data))
-            , needsToken(nt), reply(nullptr), status(NoError)
+            , needsToken(nt)
         { }
         
-        inline void sendRequest();
+        void sendRequest();
 
         const ConnectionData* connection;
 
@@ -64,13 +63,15 @@ class BaseJob::Private
         bool needsToken;
 
         QScopedPointer<QNetworkReply, NetworkReplyDeleter> reply;
-        Status status;
+        Status status = NoError;
 
         QTimer timer;
         QTimer retryTimer;
 
         size_t maxRetries = 3;
         size_t retriesTaken = 0;
+
+        LoggingCategory logCat = JOBS;
 };
 
 inline QDebug operator<<(QDebug dbg, const BaseJob* j)
@@ -88,13 +89,13 @@ BaseJob::BaseJob(const ConnectionData* connection, HttpVerb verb,
     connect (&d->timer, &QTimer::timeout, this, &BaseJob::timeout);
     d->retryTimer.setSingleShot(true);
     connect (&d->retryTimer, &QTimer::timeout, this, &BaseJob::start);
-    qCDebug(JOBS) << this << "created";
+    qCDebug(d->logCat) << this << "created";
 }
 
 BaseJob::~BaseJob()
 {
     stop();
-    qCDebug(JOBS) << this << "destroyed";
+    qCDebug(d->logCat) << this << "destroyed";
 }
 
 const ConnectionData* BaseJob::connection() const
@@ -176,7 +177,7 @@ void BaseJob::gotReply()
 BaseJob::Status BaseJob::checkReply(QNetworkReply* reply) const
 {
     if (reply->error() != QNetworkReply::NoError)
-        qCDebug(JOBS) << this << "returned" << reply->error();
+        qCDebug(d->logCat) << this << "returned" << reply->error();
     switch( reply->error() )
     {
     case QNetworkReply::NoError:
@@ -219,11 +220,11 @@ void BaseJob::stop()
     d->timer.stop();
     if (!d->reply)
     {
-        qCWarning(JOBS) << this << "stopped with empty network reply";
+        qCWarning(d->logCat) << this << "stopped with empty network reply";
     }
     else if (d->reply->isRunning())
     {
-        qCWarning(JOBS) << this << "stopped without ready network reply";
+        qCWarning(d->logCat) << this << "stopped without ready network reply";
         d->reply->disconnect(this); // Ignore whatever comes from the reply
         d->reply->abort();
     }
@@ -237,7 +238,7 @@ void BaseJob::finishJob()
     {
         const auto retryInterval = getNextRetryInterval();
         ++d->retriesTaken;
-        qCWarning(JOBS) << this << "will take retry" << d->retriesTaken
+        qCWarning(d->logCat) << this << "will take retry" << d->retriesTaken
                    << "in" << retryInterval/1000 << "s";
         d->retryTimer.start(retryInterval);
         emit retryScheduled(d->retriesTaken, retryInterval);
@@ -303,7 +304,8 @@ void BaseJob::setStatus(Status s)
     d->status = s;
     if (!s.good())
     {
-        qCWarning(JOBS) << this << "status" << s.code << ":" << s.message;
+        qCWarning(d->logCat) << this << "status" << s.code
+                                     << ":" << s.message;
     }
 }
 
@@ -326,7 +328,13 @@ void BaseJob::timeout()
 void BaseJob::sslErrors(const QList<QSslError>& errors)
 {
     foreach (const QSslError &error, errors) {
-        qCWarning(JOBS) << "SSL ERROR" << error.errorString();
+        qCWarning(d->logCat) << "SSL ERROR" << error.errorString();
     }
     d->reply->ignoreSslErrors(); // TODO: insecure! should prompt user first
 }
+
+void BaseJob::setLoggingCategory(LoggingCategory lcf)
+{
+    d->logCat = lcf;
+}
+
diff --git a/jobs/basejob.h b/jobs/basejob.h
index 460af0fc..2be4577f 100644
--- a/jobs/basejob.h
+++ b/jobs/basejob.h
@@ -18,6 +18,8 @@
 
 #pragma once
 
+#include "logging.h"
+
 #include <QtCore/QObject>
 #include <QtCore/QJsonDocument>
 #include <QtCore/QJsonObject>
@@ -241,6 +243,11 @@ namespace QMatrixClient
             void setStatus(Status s);
             void setStatus(int code, QString message);
 
+            // Q_DECLARE_LOGGING_CATEGORY return different function types
+            // in different versions
+            using LoggingCategory = decltype(JOBS)*;
+            void setLoggingCategory(LoggingCategory lcf);
+
             // Job objects should only be deleted via QObject::deleteLater
             virtual ~BaseJob();
         protected slots:
@@ -257,4 +264,4 @@ namespace QMatrixClient
             class Private;
             QScopedPointer<Private> d;
     };
-}
+}  // namespace QMatrixClient
diff --git a/jobs/syncjob.cpp b/jobs/syncjob.cpp
index 17c637b0..fb6bb9b9 100644
--- a/jobs/syncjob.cpp
+++ b/jobs/syncjob.cpp
@@ -19,7 +19,7 @@
 #include "syncjob.h"
 
 #include <QtCore/QJsonArray>
-#include <QtCore/QDebug>
+#include <QtCore/QElapsedTimer>
 
 using namespace QMatrixClient;
 
@@ -38,6 +38,7 @@ SyncJob::SyncJob(const ConnectionData* connection, const QString& since,
               "_matrix/client/r0/sync")
     , d(new Private)
 {
+    setLoggingCategory(SYNCJOB);
     QUrlQuery query;
     if( !filter.isEmpty() )
         query.addQueryItem("filter", filter);
@@ -69,6 +70,7 @@ SyncData& SyncJob::roomData()
 
 BaseJob::Status SyncJob::parseJson(const QJsonDocument& data)
 {
+    QElapsedTimer et; et.start();
     QJsonObject json = data.object();
     d->nextBatch = json.value("next_batch").toString();
     // TODO: presence
@@ -89,6 +91,7 @@ BaseJob::Status SyncJob::parseJson(const QJsonDocument& data)
         for( auto rkey: rs.keys() )
             d->roomData.emplace_back(rkey, roomState.enumVal, rs[rkey].toObject());
     }
+    qCDebug(PROFILER) << "*** SyncJob::parseJson():" << et.elapsed() << "ms";
 
     return Success;
 }
@@ -123,7 +126,7 @@ SyncRoomData::SyncRoomData(const QString& roomId_, JoinState joinState_,
             timeline.fromJson(room_);
             break;
     default:
-        qCWarning(JOBS) << "SyncRoomData: Unknown JoinState value, ignoring:" << int(joinState);
+        qCWarning(SYNCJOB) << "SyncRoomData: Unknown JoinState value, ignoring:" << int(joinState);
     }
 
     QJsonObject timeline = room_.value("timeline").toObject();
@@ -133,5 +136,5 @@ SyncRoomData::SyncRoomData(const QString& roomId_, JoinState joinState_,
     QJsonObject unread = room_.value("unread_notifications").toObject();
     highlightCount = unread.value("highlight_count").toInt();
     notificationCount = unread.value("notification_count").toInt();
-    qCDebug(JOBS) << "Highlights: " << highlightCount << " Notifications:" << notificationCount;
+    qCDebug(SYNCJOB) << "Highlights: " << highlightCount << " Notifications:" << notificationCount;
 }
diff --git a/debug.cpp b/logging.cpp
index b80438e5..97540dd4 100644
--- a/debug.cpp
+++ b/logging.cpp
@@ -16,15 +16,11 @@
  * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301  USA
  */
 
-#include "util.h"
-
-#if QT_VERSION >= QT_VERSION_CHECK(5, 4, 0)
-Q_LOGGING_CATEGORY(MAIN, "libqmatrixclient.main", QtInfoMsg)
-Q_LOGGING_CATEGORY(EVENTS, "libqmatrixclient.events", QtInfoMsg)
-Q_LOGGING_CATEGORY(JOBS, "libqmatrixclient.jobs", QtInfoMsg)
-#else
-Q_LOGGING_CATEGORY(MAIN, "libqmatrixclient.main")
-Q_LOGGING_CATEGORY(EVENTS, "libqmatrixclient.events")
-Q_LOGGING_CATEGORY(JOBS, "libqmatrixclient.jobs")
-#endif
+#include "logging.h"
 
+LOGGING_CATEGORY(MAIN, "libqmatrixclient.main")
+LOGGING_CATEGORY(PROFILER, "libqmatrixclient.profiler")
+LOGGING_CATEGORY(EVENTS, "libqmatrixclient.events")
+LOGGING_CATEGORY(EPHEMERAL, "libqmatrixclient.events.ephemeral")
+LOGGING_CATEGORY(JOBS, "libqmatrixclient.jobs")
+LOGGING_CATEGORY(SYNCJOB, "libqmatrixclient.jobs.sync")
diff --git a/logging.h b/logging.h
new file mode 100644
index 00000000..a769568c
--- /dev/null
+++ b/logging.h
@@ -0,0 +1,74 @@
+/******************************************************************************
+ * Copyright (C) 2017 Kitsune Ral <kitsune-ral@users.sf.net>
+ *
+ * This library is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU Lesser General Public
+ * License as published by the Free Software Foundation; either
+ * version 2.1 of the License, or (at your option) any later version.
+ *
+ * This library 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
+ * Lesser General Public License for more details.
+ *
+ * You should have received a copy of the GNU Lesser General Public
+ * License along with this library; if not, write to the Free Software
+ * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301  USA
+ */
+
+#pragma once
+
+#include <QtCore/QLoggingCategory>
+
+Q_DECLARE_LOGGING_CATEGORY(MAIN)
+Q_DECLARE_LOGGING_CATEGORY(PROFILER)
+Q_DECLARE_LOGGING_CATEGORY(EVENTS)
+Q_DECLARE_LOGGING_CATEGORY(EPHEMERAL)
+Q_DECLARE_LOGGING_CATEGORY(JOBS)
+Q_DECLARE_LOGGING_CATEGORY(SYNCJOB)
+
+// Use LOGGING_CATEGORY instead of Q_LOGGING_CATEGORY in the rest of the code
+#if QT_VERSION >= QT_VERSION_CHECK(5, 4, 0)
+#define LOGGING_CATEGORY(Name, Id) Q_LOGGING_CATEGORY((Name), (Id), QtInfoMsg)
+#else
+#define LOGGING_CATEGORY(Name, Id) Q_LOGGING_CATEGORY((Name), (Id))
+#endif
+
+namespace QMatrixClient
+{
+    // QDebug manipulators
+
+    using QDebugManip = QDebug (*)(QDebug);
+
+    /**
+     * @brief QDebug manipulator to setup the stream for JSON output
+     *
+     * Originally made to encapsulate the change in QDebug behavior in Qt 5.4
+     * and the respective addition of QDebug::noquote().
+     * Together with the operator<<() helper, the proposed usage is
+     * (similar to std:: I/O manipulators):
+     *
+     * @example qCDebug() << formatJson << json_object; // (QJsonObject, etc.)
+     */
+    inline QDebug formatJson(QDebug debug_object)
+    {
+#if QT_VERSION < QT_VERSION_CHECK(5, 4, 0)
+            return debug_object;
+#else
+            return debug_object.noquote();
+#endif
+    };
+
+    /**
+     * @brief A helper operator to facilitate usage of formatJson (and possibly
+     * other manipulators)
+     *
+     * @param debug_object to output the json to
+     * @param qdm a QDebug manipulator
+     * @return a copy of debug_object that has its mode altered by qdm
+     */
+    inline QDebug operator<< (QDebug debug_object, QDebugManip qdm)
+    {
+        return qdm(debug_object);
+    }
+}
diff --git a/util.h b/util.h
index 29e623c9..79f76860 100644
--- a/util.h
+++ b/util.h
@@ -18,51 +18,8 @@
 
 #pragma once
 
-#include <QtCore/QLoggingCategory>
-
-Q_DECLARE_LOGGING_CATEGORY(EVENTS)
-Q_DECLARE_LOGGING_CATEGORY(JOBS)
-Q_DECLARE_LOGGING_CATEGORY(MAIN)
-
 namespace QMatrixClient
 {
-
-    // QDebug manipulators
-
-    using QDebugManip = QDebug (*)(QDebug);
-
-    /**
-     * @brief QDebug manipulator to setup the stream for JSON output
-     *
-     * Originally made to encapsulate the change in QDebug behavior in Qt 5.4
-     * and the respective addition of QDebug::noquote().
-     * Together with the operator<<() helper, the proposed usage is
-     * (similar to std:: I/O manipulators):
-     *
-     * @example qCDebug() << formatJson << json_object; // (QJsonObject, etc.)
-     */
-    inline QDebug formatJson(QDebug debug_object)
-    {
-#if QT_VERSION < QT_VERSION_CHECK(5, 4, 0)
-            return debug_object;
-#else
-            return debug_object.noquote();
-#endif
-    };
-
-    /**
-     * @brief A helper operator to facilitate usage of formatJson (and possibly
-     * other manipulators)
-     *
-     * @param debug_object to output the json to
-     * @param qdm a QDebug manipulator
-     * @return a copy of debug_object that has its mode altered by qdm
-     */
-    inline QDebug operator<< (QDebug debug_object, QDebugManip qdm)
-    {
-        return qdm(debug_object);
-    }
-
     /**
      * @brief A crude wrapper around a container of pointers that owns pointers
      * to contained objects
@@ -77,17 +34,8 @@ namespace QMatrixClient
     {
         public:
             Owning() = default;
-#if defined(_MSC_VER) && _MSC_VER < 1900
-            // Workaround: Dangerous (auto_ptr style) copy constructor because
-            // in case of Owning< QVector<> > VS2013 (unnecessarily) instantiates
-            // QVector<>::toList() which instantiates QList< Owning<> > which
-            // requires the contained object to have a copy constructor.
-            Owning(Owning& other) : ContainerT(other.release()) { }
-            Owning(Owning&& other) : ContainerT(other.release()) { }
-#else
             Owning(Owning&) = delete;
             Owning(Owning&& other) = default;
-#endif
             Owning& operator=(Owning&& other)
             {
                 assign(other.release());
@@ -166,6 +114,5 @@ namespace QMatrixClient
     {
         return fallback;
     }
-
-}
+}  // namespace QMatrixClient