Merge lp:~mrqtros/ubuntu-docviewer-app/ubuntu-docviewer-app-adv-logging into lp:ubuntu-docviewer-app

[Roman Shchekin]

New style of logging.

New style of logging.

[Jenkins Bot (ubuntu-core-apps-jenkins-bot)]

PASSED: Continuous integration, rev:261
https://core-apps-jenkins.ubuntu.com/job/run-ap-tests-ci/129/
Executed test runs:
    None: https://core-apps-jenkins.ubuntu.com/job/generic-update-mp/404/console

Click here to trigger a rebuild:
https://core-apps-jenkins.ubuntu.com/job/run-ap-tests-ci/129/rebuild

review: Approve (continuous-integration)

[Stefano Verzegnassi (verzegnassi-stefano)]

Hey Roman!
In order to go on with the review, I need to ask you some question.

1) I see you've kept the #ifdef's. Shouldn't they be removed?

   Having a look at the KDE wiki at:
       https://techbase.kde.org/Development/Tutorials/Debugging/Using_Error_Messages#Improving_Logging_Output

   It looks like we'd need two steps in order to enable debugging output:
       1) Uncomment a #define entry in config.h
       2) Enable logging for a specific category (by default they're all disabled)

    I'd suggest to remove all the #define's and #ifdef's, and eventually add e.g.:
        QLoggingCategory::setFilterRules(QStringLiteral("RenderEngine.debug = true"));

    somewhere inside the plugin.

2) How do we like to filter the debug log? By class as you propose (e.g. "RenderEngine", "LODocument", etc.) or by scope (e.g. "TileBenchmark", "TileManagement", "Zoom", etc.)

3) Some of the debug in LODocument
       e.g. qCDebug(LoDoc) << "Loading document...";

   is information output rather than debug (I badly used qDebug() instead of qInfo()).

   Do we still want to make it optional? Could we use qInfo() or qCInfo()?

   I'm thinking at a scenario where something unexpected happens, and a user opens a bug report on Launchpad and upload the application log.
   Those basic informations wouldn't be available, and we would have to ask her to enable logging[1] for being able to say which area could generate the issue, and then (eventually) asking to enable some further category again.

   I consider this output useful for orienting my focus at first. I might as well be wrong!

[1] How can that be easily done on Ubuntu Touch, since everything is so confined?

review: Needs Information

[Roman Shchekin (mrqtros)]

Let's discuss it then :)

1) I should explore possibilities... To be honest, I was satisfied with text in output during debug, I thought that it was enough for us...
2) Seems that we should filter our output with groups. RenderEngine itself is a good category, LoDocument and LoView can be rethinked... The using of class name can be very handy since we have not so much classes and all of them are "core".
3) There is a thin difference between info and debug, I think, so every case is discussable, but not critical

[Stefano Verzegnassi (verzegnassi-stefano)]

1) Yes! If we could remove those #ifdef's from the code, it would look more linear/less bulky(TM) and it would be a great "double win".
However, I'd like to have something similar to the current config.h, so that we can toggle a more verbose output by uncommenting a single line. Which could be a suitable place for that?

2) Agree! "RenderEngine" is a good category. Others could be:
   - "TileBenchmark" in LODocument paint functions
   - "TileManagement" in LOView, for providing output about creation/removal/changes about the tile map and the visible/buffer areas
   - "ZoomEvents" for the automatic zoom management and events triggered by a change in the zoom value[1]
   - "VerboseOutput" for general information (e.g. error warnings) and something else we could add in future

3) "Loading document ..." and "Document loaded successfully !" may stay always visible.
   LODocument::loadDocument() is the place where the magical things happen (all the LibreOffice stuff are loaded there, and many 'events' in the plugin depend on a successful/failure of its execution).
   Having those two lines at the beginning/end of the function is more confortable for me. :)

[1] See for example "Zoom value of tiles is different than the current zoom value. Erasing cache..."
    This string could also be filtered by a "TileManagement" category, but it's not possible to assign a string to multiple categories, for what I see.

Unmerged revisions

261. By Roman Shchekin on 2016-01-16

New style of logging.

=== modified file 'src/app/renderengine.cpp'
--- src/app/renderengine.cpp	2015-12-12 10:06:55 +0000
+++ src/app/renderengine.cpp	2016-01-16 13:18:10 +0000
@@ -2,6 +2,8 @@
 #include <QtConcurrent/QtConcurrent>
 #include <QThread>
 
+Q_LOGGING_CATEGORY(RndEng, "RenderEngine")
+
 RenderEngine* RenderEngine::s_instance = nullptr;
 
 RenderEngine::RenderEngine():
@@ -65,7 +67,7 @@
 void RenderEngine::doNextTask()
 {
 #ifdef DEBUG_VERBOSE
-    qDebug() << " ---- doNextTask" << m_activeTaskCount << m_queue.count();
+    qCDebug(RndEng) << " ---- doNextTask" << m_activeTaskCount << m_queue.count();
 #endif
 
     // Check for too much threads or empty queue.
 
=== modified file 'src/app/renderengine.h'
--- src/app/renderengine.h	2015-12-12 10:06:55 +0000
+++ src/app/renderengine.h	2016-01-16 13:18:10 +0000
@@ -8,10 +8,13 @@
 #include <QQueue>
 #include <QAtomicInt>
 #include <QList>
+#include <QLoggingCategory>
 
 //#include "lodocument.h"
 #include "rendertask.h"
 
+Q_DECLARE_LOGGING_CATEGORY(RndEng)
+
 class RenderEngine : public QObject
 {
     Q_OBJECT
 
=== modified file 'src/plugin/libreofficetoolkit-qml-plugin/lodocument.cpp'
--- src/plugin/libreofficetoolkit-qml-plugin/lodocument.cpp	2015-12-14 00:40:55 +0000
+++ src/plugin/libreofficetoolkit-qml-plugin/lodocument.cpp	2016-01-16 13:18:10 +0000
@@ -30,6 +30,8 @@
 #include <QElapsedTimer>
 #endif
 
+Q_LOGGING_CATEGORY(LoDoc, "LODocument")
+
 lok::Office *LODocument::s_office = nullptr;
 
 LODocument::LODocument()
@@ -62,11 +64,11 @@
 // Load the document
 void LODocument::loadDocument(const QString &pathName)
 {
-    qDebug() << "Loading document...";
+    qCDebug(LoDoc) << "Loading document...";
     setError(LibreOfficeError::NoError);
 
     if (pathName.isEmpty()) {
-        qDebug() << "Can't load the document, path is empty.";
+        qCWarning(LoDoc) << "Can't load the document, path is empty.";
         return;
     }
 
@@ -86,7 +88,7 @@
 
     if (!s_office) {
         setError(LibreOfficeError::LibreOfficeNotInitialized);
-        qDebug() << "[lok-qml]: LibreOffice not initialized.";
+        qCWarning(LoDoc) << "[lok-qml]: LibreOffice not initialized.";
         return;
     }
 
@@ -96,7 +98,7 @@
 
     if (!m_lokDocument) {
         setError(LibreOfficeError::DocumentNotLoaded);
-        qDebug() << "[lok-qml]: Document not loaded.";
+        qCWarning(LoDoc) << "[lok-qml]: Document not loaded.";
         return;
     }
 
@@ -106,7 +108,7 @@
     Q_EMIT documentTypeChanged();
 
     m_lokDocument->initializeForRendering();
-    qDebug() << "Document loaded successfully !";
+    qCDebug(LoDoc) << "Document loaded successfully !";
 
     return;
 }
@@ -173,7 +175,7 @@
                           Twips::convertPixelsToTwips(tileSize.height(), zoom));
 
 #ifdef DEBUG_TILE_BENCHMARK
-    qDebug() << "Time to render the tile:" << renderTimer.elapsed() << "ms";
+    qCDebug(LoDoc) << "Time to render the tile:" << renderTimer.elapsed() << "ms";
 #endif
 
     return result.rgbSwapped();
@@ -209,7 +211,7 @@
                           0, 0, tWidth, tHeight);
 
 #ifdef DEBUG_TILE_BENCHMARK
-    qDebug() << "Time to render the thumbnail:" << renderTimer.elapsed() << "ms";
+    qCDebug(LoDoc) << "Time to render the thumbnail:" << renderTimer.elapsed() << "ms";
 #endif
 
     return result.rgbSwapped();
@@ -241,7 +243,7 @@
 bool LODocument::saveAs(QString url, QString format = QString(), QString filterOptions = QString())
 {
     if (!m_lokDocument) {
-        qDebug() << "No loaded document. It's not possible to save this file.";
+        qCWarning(LoDoc) << "No loaded document. It's not possible to save this file.";
         return false;
     }
 
@@ -254,6 +256,6 @@
 {
     delete m_lokDocument;
 #ifdef DEBUG_VERBOSE
-    qDebug() << " ---- ~LODocument";
+    qCDebug(LoDoc) << " ---- ~LODocument";
 #endif
 }
 
=== modified file 'src/plugin/libreofficetoolkit-qml-plugin/lodocument.h'
--- src/plugin/libreofficetoolkit-qml-plugin/lodocument.h	2015-12-14 00:40:55 +0000
+++ src/plugin/libreofficetoolkit-qml-plugin/lodocument.h	2016-01-16 13:18:10 +0000
@@ -19,6 +19,9 @@
 #define LODOCUMENT_H
 
 #include <QObject>
+#include <QLoggingCategory>
+
+Q_DECLARE_LOGGING_CATEGORY(LoDoc)
 
 #include "loerror.h"
 
 
=== modified file 'src/plugin/libreofficetoolkit-qml-plugin/loview.cpp'
--- src/plugin/libreofficetoolkit-qml-plugin/loview.cpp	2015-12-14 00:40:55 +0000
+++ src/plugin/libreofficetoolkit-qml-plugin/loview.cpp	2016-01-16 13:18:10 +0000
@@ -24,6 +24,8 @@
 #include <QTimer>
 #include <QtCore/qmath.h>
 
+Q_LOGGING_CATEGORY(LoVi, "LOView")
+
 static qreal zoomValueToFitWidth;
 
 static qreal getZoomToFitWidth(const qreal &width, int documentWidth)
@@ -210,7 +212,7 @@
                                             m_document->documentSize().width());
 
     setZoomFactor(zoomValueToFitWidth);
-    qDebug() << "Adjust zoom to width - value:" << zoomValueToFitWidth;
+    qCDebug(LoVi) << "Adjust zoom to width - value:" << zoomValueToFitWidth;
 }
 
 void LOView::updateViewSize()
@@ -247,7 +249,7 @@
         if (m_zoomFactor != zoomValueToFitWidth) {
             setZoomFactor(zoomValueToFitWidth);
 
-            qDebug() << "Adjust automatic zoom to width - value:" << zoomValueToFitWidth;
+            qCDebug(LoVi) << "Adjust automatic zoom to width - value:" << zoomValueToFitWidth;
             return;
         }
     }
@@ -260,7 +262,7 @@
             clearView();
 
 #ifdef DEBUG_VERBOSE
-            qDebug() << "Zoom value of tiles is different than the current zoom value. Erasing cache...";
+            qCDebug(LoVi) << "Zoom value of tiles is different than the current zoom value. Erasing cache...";
 #endif
         }
     }
@@ -298,7 +300,7 @@
 
             // Out of buffer - we should delete this item.
 #ifdef DEBUG_VERBOSE
-            qDebug() << "Removing tile indexed as" << i.key();
+            qCDebug(LoVi) << "Removing tile indexed as" << i.key();
 #endif
 
             RenderEngine::instance()->dequeueTask(sgtile->id());
@@ -324,8 +326,8 @@
     int bufferToHeight          = qCeil(qreal(m_bufferArea.bottom()) / TILE_SIZE);
 
 #ifdef DEBUG_VERBOSE
-    qDebug() << "Visible area - Left:" << visiblesFromWidth << "Right:" << visiblesToWidth << "Top:" << visiblesFromHeight << "Bottom:" << visiblesToHeight;
-    qDebug() << "Buffer area  - Left:" << bufferFromWidth   << "Right:" << bufferToWidth   << "Top:" << bufferFromHeight   << "Bottom:" << bufferToHeight;
+    qCDebug(LoVi) << "Visible area - Left:" << visiblesFromWidth << "Right:" << visiblesToWidth << "Top:" << visiblesFromHeight << "Bottom:" << visiblesToHeight;
+    qCDebug(LoVi) << "Buffer area  - Left:" << bufferFromWidth   << "Right:" << bufferToWidth   << "Top:" << bufferFromHeight   << "Bottom:" << bufferToHeight;
 #endif
 
     this->generateTiles(visiblesFromWidth, visiblesFromHeight, visiblesToWidth, visiblesToHeight, tilesPerWidth, tilesPerHeight);
@@ -350,7 +352,7 @@
             createTile(index, tileRect);
 
 #ifdef DEBUG_VERBOSE
-            qDebug() << "Generating tile - Index:" << index << "X:" << x << "Y:" << y;
+            qCDebug(LoVi) << "Generating tile - Index:" << index << "X:" << x << "Y:" << y;
 #endif
         }
     }
@@ -375,7 +377,7 @@
 {
     if (!m_tiles.contains(index)) {
 #ifdef DEBUG_VERBOSE
-        qDebug() << "Creating tile indexed as" << index << "- Rect:" << rect;
+        qCDebug(LoVi) << "Creating tile indexed as" << index << "- Rect:" << rect;
 #endif
 
         auto tile = new SGTileItem(rect, m_zoomFactor, RenderEngine::getNextId(), this);
@@ -384,7 +386,7 @@
     }
 #ifdef DEBUG_VERBOSE
     else {
-        qDebug() << "tile" << index << "already exists";
+        qCDebug(LoVi) << "tile" << index << "already exists";
     }
 #endif
 }
 
=== modified file 'src/plugin/libreofficetoolkit-qml-plugin/loview.h'
--- src/plugin/libreofficetoolkit-qml-plugin/loview.h	2016-01-07 11:23:50 +0000
+++ src/plugin/libreofficetoolkit-qml-plugin/loview.h	2016-01-16 13:18:10 +0000
@@ -22,6 +22,9 @@
 #include <QSharedPointer>
 #include <QQmlContext>
 #include <QQmlEngine>
+#include <QLoggingCategory>
+
+Q_DECLARE_LOGGING_CATEGORY(LoVi)
 
 #include "loerror.h"
 #include "lorendertask.h"