Defensive Editor Diagnostics (#63)

Use defensive logging techniques to improve usability and perceived stability. Worked with Josh to create a new family of logging macros for validating assumptions and preconditions without aborting the application. We have provided a diagnostics output area where users can obtain logs of internal editor issues when they occur within RadialGM and report them back to us.

CMakeLists.txt

@@ -92,6 +92,7 @@ set(RGM_HEADERS
     Components/RecentFiles.h
     Components/Utility.h
     Components/QMenuView.h
+    Components/Logger.h
     Widgets/BackgroundView.h
     Widgets/CodeWidget.h
     Widgets/ColorPicker.h
@@ -136,6 +137,9 @@ else()
   add_executable(${EXE} ${RGM_UI} ${RGM_HEADERS} ${RGM_SOURCES} ${EDITOR_SOURCES} ${RGM_RC})
 endif(WIN32)
 
+# we do this even in release mode for "Editor Diagnostics"
+target_compile_definitions(${EXE} PUBLIC QT_MESSAGELOGCONTEXT)
+
 message(STATUS "Initial build flags:")
 set(CompilerFlags
 	  CMAKE_C_FLAGS_DEBUG

Components/Logger.h

@@ -0,0 +1,46 @@
+#ifndef LOGGER_H
+#define LOGGER_H
+
+#include <QDebug>
+#include <QtGlobal>
+
+class LogAndReturn {
+  QDebug logger;
+
+ public:
+  LogAndReturn(QtMsgType msgType) : logger(msgType) {}
+  LogAndReturn(const QDebug&& log) : logger(log) {}
+
+  template <typename T>
+  LogAndReturn& operator<<(T t) {
+    logger << t;
+    return *this;
+  }
+  struct Void {
+    void operator,(const LogAndReturn& /*log*/) {}
+  };
+};
+template <typename T>
+T operator,(T x, const LogAndReturn&) {
+  return x;
+}
+
+// check and log the condition, return value when failed
+#define R_EXPECT(cond, ret) \
+  if (cond) {               \
+  } else                    \
+    return ret, LogAndReturn(qWarning()) << "Check `" #cond "` failed."
+
+// check and log the condition, return void when failed
+#define R_EXPECT_V(cond) \
+  if (cond) {            \
+  } else                 \
+    return LogAndReturn::Void(), LogAndReturn(qWarning()) << "Check `" #cond "` failed."
+
+// check and log the condition, but continue on failure
+#define R_ASSESS(cond) \
+  if (cond) {          \
+  } else               \
+    LogAndReturn(qWarning()) << "Check `" #cond "` failed."
+
+#endif  // LOGGER_H

MainWindow.cpp

@@ -16,6 +16,7 @@
 #include "Editors/TimelineEditor.h"
 
 #include "Components/ArtManager.h"
+#include "Components/Logger.h"
 
 #include "Plugins/RGMPlugin.h"
 #include "Plugins/ServerPlugin.h"
@@ -36,6 +37,54 @@ MainWindow *MainWindow::m_instance = nullptr;
 QScopedPointer<ResourceModelMap> MainWindow::resourceMap;
 QScopedPointer<TreeModel> MainWindow::treeModel;
 
+static QTextEdit *diagnosticTextEdit = nullptr;
+static QAction *toggleDiagnosticsAction = nullptr;
+
+void diagnosticHandler(QtMsgType type, const QMessageLogContext &context, const QString &msg) {
+  if (toggleDiagnosticsAction && !toggleDiagnosticsAction->isChecked()) {
+    toggleDiagnosticsAction->setIcon(QIcon(":/actions/log-debug.png"));
+    toggleDiagnosticsAction->setToolTip(
+        QT_TR_NOOP("The editor encountered issues which have been logged in the diagnostics output."));
+  } else {
+    // this should never happen!
+    // NOTE: if we used R_EXPECT_V here it would be recursive
+    std::cerr << "Critical: Diagnostics toggle button does not exist!" << std::endl;
+  }
+
+  QByteArray localMsg = msg.toLocal8Bit();
+  QString file = context.file ? context.file : "";
+  QString function = context.function ? context.function : "";
+  QString msgFormat("%1 in %3:%4 aka %5:\n\t%2");
+  QString typeName = "Unknown:";
+  switch (type) {
+    case QtDebugMsg:
+      typeName = "Debug";
+      break;
+    case QtInfoMsg:
+      typeName = "Info";
+      break;
+    case QtWarningMsg:
+      typeName = "Warning";
+      break;
+    case QtCriticalMsg:
+      typeName = "Critical";
+      break;
+    case QtFatalMsg:
+      typeName = "Fatal";
+      break;
+  }
+  QString msgFormatted = msgFormat.arg(typeName, localMsg.constData(), file, QString::number(context.line), function);
+
+  std::cerr << msgFormatted.toStdString() << std::endl;
+
+  if (diagnosticTextEdit) {
+    diagnosticTextEdit->append(msgFormatted);
+  } else {
+    // this should never happen!
+    std::cerr << "Critical: Diagnostics text control does not exist!" << std::endl;
+  }
+}
+
 MainWindow::MainWindow(QWidget *parent) : QMainWindow(parent), ui(new Ui::MainWindow) {
   ArtManager::Init();
 
@@ -47,7 +96,38 @@ MainWindow::MainWindow(QWidget *parent) : QMainWindow(parent), ui(new Ui::MainWi
   setCorner(Qt::BottomRightCorner, Qt::RightDockWidgetArea);
 
   ui->setupUi(this);
-  this->readSettings();
+
+  QToolBar *outputTB = new QToolBar(this);
+  outputTB->setIconSize(QSize(24, 24));
+  toggleDiagnosticsAction = new QAction();
+  toggleDiagnosticsAction->setCheckable(true);
+  toggleDiagnosticsAction->setIcon(QIcon(":/actions/log.png"));
+  toggleDiagnosticsAction->setToolTip(tr("Toggle Editor Diagnostics"));
+  outputTB->addAction(toggleDiagnosticsAction);
+  outputTB->addSeparator();
+  // use tool button for clear because QAction always has tooltip
+  QToolButton *clearButton = new QToolButton();
+  clearButton->setText(tr("Clear"));
+  outputTB->addWidget(clearButton);
+  QVBoxLayout *outputLayout = static_cast<QVBoxLayout *>(ui->outputDockWidgetContents->layout());
+  outputLayout->insertWidget(0, outputTB);
+
+  // install editor diagnostics handler
+  diagnosticTextEdit = ui->debugTextBrowser;
+  qInstallMessageHandler(diagnosticHandler);
+
+  connect(clearButton, &QToolButton::clicked,
+          [=]() { (toggleDiagnosticsAction->isChecked() ? ui->debugTextBrowser : ui->outputTextBrowser)->clear(); });
+  connect(toggleDiagnosticsAction, &QAction::toggled, [=](bool checked) {
+    ui->outputStackedWidget->setCurrentIndex(checked);
+
+    // reset the log icon as soon as diagnostics is viewed
+    if (checked) {
+      toggleDiagnosticsAction->setIcon(QIcon(":/actions/log.png"));
+      toggleDiagnosticsAction->setToolTip(tr("Toggle Editor Diagnostics"));
+    }
+  });
+
   this->recentFiles = new RecentFiles(this, this->ui->menuRecent, this->ui->actionClearRecentMenu);
 
   ui->mdiArea->setBackground(QImage(":/banner.png"));

MainWindow.ui

@@ -288,6 +288,10 @@
    <addaction name="actionDocumentation"/>
   </widget>
   <widget class="QDockWidget" name="outputDockWidget">
+   <property name="windowIcon">
+    <iconset resource="images.qrc">
+     <normaloff>:/actions/debug.png</normaloff>:/actions/debug.png</iconset>
+   </property>
    <property name="floating">
     <bool>false</bool>
    </property>
@@ -321,7 +325,52 @@
       <number>2</number>
      </property>
      <item>
-      <widget class="QTextBrowser" name="outputTextBrowser"/>
+      <widget class="QStackedWidget" name="outputStackedWidget">
+       <widget class="QWidget" name="outputTextPage">
+        <layout class="QVBoxLayout" name="verticalLayout_4">
+         <property name="spacing">
+          <number>0</number>
+         </property>
+         <property name="leftMargin">
+          <number>0</number>
+         </property>
+         <property name="topMargin">
+          <number>0</number>
+         </property>
+         <property name="rightMargin">
+          <number>0</number>
+         </property>
+         <property name="bottomMargin">
+          <number>0</number>
+         </property>
+         <item>
+          <widget class="QTextBrowser" name="outputTextBrowser"/>
+         </item>
+        </layout>
+       </widget>
+       <widget class="QWidget" name="debugTextPage">
+        <layout class="QVBoxLayout" name="verticalLayout_5">
+         <property name="spacing">
+          <number>0</number>
+         </property>
+         <property name="leftMargin">
+          <number>0</number>
+         </property>
+         <property name="topMargin">
+          <number>0</number>
+         </property>
+         <property name="rightMargin">
+          <number>0</number>
+         </property>
+         <property name="bottomMargin">
+          <number>0</number>
+         </property>
+         <item>
+          <widget class="QTextBrowser" name="debugTextBrowser"/>
+         </item>
+        </layout>
+       </widget>
+      </widget>
      </item>
     </layout>
    </widget>

Models/ProtoModel.cpp

@@ -1,6 +1,8 @@
 #include "ProtoModel.h"
 #include "RepeatedProtoModel.h"
 
+#include "Components/Logger.h"
+
 #include <iostream>
 
 using namespace google::protobuf;
@@ -78,6 +80,8 @@ bool ProtoModel::IsDirty() { return dirty; }
 int ProtoModel::columnCount(const QModelIndex & /*parent*/) const { return 1; }
 
 bool ProtoModel::setData(const QModelIndex &index, const QVariant &value, int role) {
+  R_EXPECT(index.isValid(), false) << "Supplied index was invalid:" << index;
+
   const Descriptor *desc = protobuf->GetDescriptor();
   const Reflection *refl = protobuf->GetReflection();
   const FieldDescriptor *field = desc->FindFieldByNumber(index.row());
@@ -128,6 +132,7 @@ QVariant ProtoModel::data(int row, int column) const {
 }
 
 QVariant ProtoModel::data(const QModelIndex &index, int role) const {
+  R_EXPECT(index.isValid(), QVariant()) << "Supplied index was invalid:" << index;
   if (role != Qt::DisplayRole && role != Qt::EditRole) return QVariant();
 
   const Descriptor *desc = protobuf->GetDescriptor();

Models/RepeatedProtoModel.cpp

@@ -1,5 +1,6 @@
 #include "RepeatedProtoModel.h"
 #include "Components/ArtManager.h"
+#include "Components/Logger.h"
 #include "MainWindow.h"
 #include "ProtoModel.h"
 #include "ResourceModelMap.h"
@@ -26,6 +27,8 @@ QVariant RepeatedProtoModel::data(int row, int column) const {
 }
 
 QVariant RepeatedProtoModel::data(const QModelIndex &index, int role) const {
+  R_EXPECT(index.isValid(), QVariant()) << "Supplied index was invalid:" << index;
+
   ProtoModel *m = static_cast<ProtoModel *>(QObject::parent())->GetSubModel(field->number(), index.row());
   QVariant data = m->data(index.column());
   if (role == Qt::DecorationRole && field->name() == "instances" &&

Models/SpriteModel.cpp

@@ -1,5 +1,7 @@
 #include "SpriteModel.h"
 
+#include "Components/Logger.h"
+
 #include <QIcon>
 #include <QImageReader>
 #include <QMimeData>
@@ -20,8 +22,10 @@ void SpriteModel::SetMinIconSize(unsigned width, unsigned height) {
 QSize SpriteModel::GetIconSize() { return data(index(0), Qt::SizeHintRole).toSize(); }
 
 int SpriteModel::rowCount(const QModelIndex& /*parent*/) const { return protobuf->size(); }
+
 QVariant SpriteModel::data(const QModelIndex& index, int role) const {
-  if (!index.isValid()) return QVariant();
+  R_EXPECT(index.isValid(), QVariant()) << "Supplied index was invalid:" << index;
+
   if (role == Qt::DecorationRole)
     return QIcon(QString::fromStdString(protobuf->Get(index.row())));
   else if (role == Qt::BackgroundColorRole) {
@@ -50,6 +54,8 @@ QVariant SpriteModel::data(const QModelIndex& index, int role) const {
 }
 
 bool SpriteModel::setData(const QModelIndex& index, const QVariant& value, int role) {
+  R_EXPECT(index.isValid(), false) << "Supplied index was invalid:" << index;
+
   if (role == Qt::UserRole) {
     qDebug() << "setData()";
     qDebug() << value.toString();

Models/TreeModel.cpp

@@ -1,6 +1,7 @@
 #include "TreeModel.h"
 
 #include "Components/ArtManager.h"
+#include "Components/Logger.h"
 #include "Models/ResourceModelMap.h"
 
 #include <QCoreApplication>
@@ -37,7 +38,9 @@ void TreeModel::SetupParents(buffers::TreeNode *root) {
 int TreeModel::columnCount(const QModelIndex & /*parent*/) const { return 1; }
 
 bool TreeModel::setData(const QModelIndex &index, const QVariant &value, int role) {
-  if (!index.isValid() || role != Qt::EditRole) return false;
+  R_EXPECT(index.isValid(), false) << "Supplied index was invalid:" << index;
+  if (role != Qt::EditRole) return false;
+
   buffers::TreeNode *item = static_cast<buffers::TreeNode *>(index.internalPointer());
   const QString oldName = QString::fromStdString(item->name());
   const QString newName = value.toString();
@@ -49,7 +52,7 @@ bool TreeModel::setData(const QModelIndex &index, const QVariant &value, int rol
 }
 
 QVariant TreeModel::data(const QModelIndex &index, int role) const {
-  if (!index.isValid()) return QVariant();
+  R_EXPECT(index.isValid(), QVariant()) << "Supplied index was invalid:" << index;
 
   buffers::TreeNode *item = static_cast<buffers::TreeNode *>(index.internalPointer());
   if (role == Qt::DecorationRole) {

RadialGM.pro

@@ -30,6 +30,9 @@ rgm_disable_syntaxhighlight {
   CONFIG += qscintilla2
 }
 
+# we do this even in release mode for "Editor Diagnostics"
+DEFINES += QT_MESSAGELOGCONTEXT
+
 # The following define makes your compiler emit warnings if you use
 # any feature of Qt which has been marked as deprecated (the exact warnings
 # depend on your compiler). Please consult the documentation of the
@@ -108,6 +111,7 @@ HEADERS += \
     Widgets/AssetView.h \
     Widgets/RoomView.h \
     Models/TreeModel.h \
+    Components/Logger.h \
     Components/ArtManager.h \
     Models/ProtoModel.h \
     Models/ImmediateMapper.h \

images.qrc

@@ -46,6 +46,8 @@
         <file alias="function.png">Images/actions/function.png</file>
         <file alias="rename.png">Images/actions/rename.png</file>
         <file alias="folder-new.png">Images/actions/folder-new.png</file>
+        <file alias="log.png">Images/actions/log.png</file>
+        <file alias="log-debug.png">Images/actions/log-debug.png</file>
     </qresource>
     <qresource prefix="/resources">
         <file alias="background.png">Images/resources/background.png</file>