Qt Logging tool multithreading, calling signal and slot with variable number of arguments form another thread, mixing C and C++

Question

This is my Logging class:

#include "log.h"
#include "ui_log.h"

#include <QDebug>
#include <QMutex>


bool Log::logOpen = false;

Log::Log(QWidget *parent) : QDialog(parent), ui(new Ui::Log)
{
    ui->setupUi(this);
    text = new QString;
    this->bar = this->ui->logText->verticalScrollBar();
    connect(this, SIGNAL(call_write(char*)), this, SLOT(write(char*)));
}

Log::~Log()
{
    delete ui;
}

void Log::on_buttonClose_clicked()
{
    Log::logOpen = false;
    close();
}

void Log::on_buttonClear_clicked()
{
    this->text->clear();
    this->ui->logText->clear();
}

void Log::write(char *msg)
{
    this->text->append(msg);
    this->ui->logText->setPlainText(*this->text);
    this->bar->setValue(bar->maximum());
    free(msg);
}

void write_c(Log *ptr, char *msg) {
    emit ptr->call_write(msg);
}

void r_printf(char *format, ...) {
    char *buf = (char*) malloc(4096);
    va_list argList;
    va_start(argList, format);
    vsnprintf(buf, 4096,format, argList);
    va_end(argList);
    write_c(logptr, buf);
}

This is, by far, THE most complicated piece of code I have ever written. This is how it works: r_printf(char *format, ...) can be called from either C or C++, it takes the format and va_list arguments, and formats them. Then, it calls write_c, which sends a signal the Logger, which is connected to itself, so the Qt scheduler schedules an update to the window by calling write(), so that Qt does not freak out. Crazy, right?

Here is the log header, log.h

#ifndef LOG_H
#define LOG_H

#include <stdarg.h>

#ifdef __cplusplus

#include <QDialog>
#include <QString>
#include <QScrollBar>

namespace Ui {
class Log;
}

class Log : public QDialog
{
    Q_OBJECT

public:
    static bool logOpen;
    explicit Log(QWidget *parent = 0);

    ~Log();
    Ui::Log *ui;
    QString *text;
    QScrollBar *bar;

private slots:
    void on_buttonClose_clicked();
    void on_buttonClear_clicked();
    void write(char *msg);

signals:
    void call_write(char *msg);

};

#else

typedef struct Log Log;

#endif // __cplusplus

#ifdef __cplusplus
#define EXPORT_C extern "C"
#else
#define EXPORT_C
#endif

extern Log *logptr;

EXPORT_C void write_c(Log *ptr, char *msg);
EXPORT_C void r_printf(char *format, ...);

#endif // LOG_H

logptr is the pointer to a Log object inside the Main window.

While this does work, and it does not corrupt memory, is there a better solution to this huge mess? Is this a good solution? Can it be improved?

The goal is to have something like printf(char *format, ...) which can be called from either thread, from either C or C++. It should always work.

Answer 1

Here are my nitpicks, arranged in the order of how I thought about it.

1. The declaration and definition of r_printf differ. Both must be EXPORT_C.

2. EXPORT_C is likely to clash with some errant library code. Prefer a more unique name, like LOG_H_EXPORT_C.

3. A signal can have zero or more recipients. The message allocated in r_printf can in principle leak or be multiply deleted. There's no reason to do manual memory management here, use a shared pointer or an implicitly shared data structure like QByteArray instead.

4. For portability, you could use qvsnprintf.

5. You're allocating a huge buffer. This is a tradeoff between allocation size and performance. You have an option of calling qvsnprintf with zero size to get the needed buffer size, then allocate a correctly-sized buffer, and call qvsnprintf again. You'd need to profile this to make an informed choice. At the very least, don't allocate a page-sized buffer since on some platforms this pessimizes and allocates more than a page, at a 100% overhead. A 0xFE0 size would be a safer bet.

6. Prefer QString::asprintf, and simply pass a QString through the slots. This guarantees that the string will be converted from 8-bit to UTF-16 encoding only once.

7. Since you're now emitting a container like QString or QByteArray, you could factor out the log message source into a separate object. It could be connected to zero or more views, then.

8. Do not reset the log text. Instead, use QPlainText::appendPlainText. This will avoid the need to re-parse the entire log every time you add to it.

9. The QPlainTextEdit is abysmally slow and unsuitable for logging. You should use a QListView or a custom widget instead.

10. You may wish to keep the log scrolled to the bottom if it already is so. See this question for details.

Here's an example:

Log.h

#ifndef LOG_H
#define LOG_H

#ifdef __cplusplus
#include <QObject>
class Log : public QObject {
    Q_OBJECT
public:
    /// Indicates that a new message is available to be logged.
    Q_SIGNAL void newMessage(const QString &);
    /// Sends a new message signal from the global singleton. This method is thread-safe.
    static void sendMessage(const QString &);
    /// Returns a global singleton. This method is thread-safe.
    static Log * instance();
};
#define LOG_H_EXPORT_C extern "C"
#else
#define LOG_H_EXPORT_C
#endif

LOG_H_EXPORT_C void r_printf(const char * format, ...);

#endif // LOG_H

Log.cpp

#include "Log.h"
#include <cstdarg>

Q_GLOBAL_STATIC(Log, log)

Log * Log::instance() { return log; }

void Log::sendMessage(const QString & msg) {
    emit log->newMessage(msg);
}

LOG_H_EXPORT_C void r_printf(const char * format, ...) {
    va_list argList;
    va_start(argList, format);
    auto msg = QString::vasprintf(format, argList);
    va_end(argList);
    Log::sendMessage(msg);
}

main.cpp

// https://github.com/KubaO/stackoverflown/tree/master/questions/simplelog-38793887
#include <QtWidgets>
#include <QtConcurrent>
#include "Log.h"

int main(int argc, char ** argv) {
   using Q = QObject;
   QApplication app{argc, argv};
   QStringListModel model;
   Q::connect(Log::instance(), &Log::newMessage, &model, [&](const QString & msg) {
      auto row = model.rowCount();
      model.insertRow(row);
      model.setData(model.index(row), msg);
   });
   QWidget w;
   QVBoxLayout layout{&w};
   QListView view;
   bool viewAtBottom = false;
   QPushButton clear{"Clear"};
   layout.addWidget(&view);
   layout.addWidget(&clear);
   Q::connect(&clear, &QPushButton::clicked,
              &model, [&]{ model.setStringList(QStringList{}); });
   view.setModel(&model);
   view.setUniformItemSizes(true);
   Q::connect(view.model(), &QAbstractItemModel::rowsAboutToBeInserted, &view, [&] {
      auto bar = view.verticalScrollBar();
      viewAtBottom = bar ? (bar->value() == bar->maximum()) : false;
   });
   Q::connect(view.model(), &QAbstractItemModel::rowsInserted,
              &view, [&]{ if (viewAtBottom) view.scrollToBottom(); });

   QtConcurrent::run([]{
      auto delay = 10;
      for (int ms = 0; ms <= 500; ms += delay) {
         r_printf("%d ms", ms);
         QThread::msleep(ms);
      }
   });
   w.show();
   return app.exec();
}

Answer 2

Kuba's answer didn't compile for me, probably due to a name collision with the mathematical function log(). I got it to compile and run by replacing log in Log.cpp with e.g. global_log_instance.

Note I tested using Qt 5.6.1 on Ubuntu 16.04, with this .pro-file:

QT += widgets concurrent
SOURCES += main.cpp Log.cpp
HEADERS += Log.h

I mention this because as perhaps Kuba was intending to use some library setting or flag to avoid conflict with the log()-function.

Note: Something is strange with the solution though. E.g., if exiting the window early, it still takes about 12 seconds in total for the prompt to return. Further, log messages are visibly being added at a slower and slower rate. On my system I do get a warning about "IBUS", maybe that's related somehow.

$ time ./main

(main:11094): IBUS-WARNING **: Unable to connect to ibus: Could not connect: Connection refused

real    0m12.825s
user    0m0.168s
sys     0m0.012s