testlib: Feed test log messages to Apple Unified Logging

QtTestLib uses its own message handler for plain text logging, so it doesn't
go though the logic in qDefaultMessageHandler that dispatches logging to
alternate logging sinks.

Building on the approach of Android and Windows, we log to AUL from the
plain text logger. A future improvement in this area would be to make
QtTestLib make more use of the infrastructure in qlogging.cpp, but this
is a bigger task and requires a better overview of the requirements.

The AUL code has been isolated into a wrapper, to allow logging both
to AUl and to e.g. the QPlainTextLogger. This is needed so that we
short circuit the plain text logger in case AUL already has handled
printing to stderr.

Change-Id: Iee0c3902190bd081b7ffbaf77c41b3118ce7f6da
Reviewed-by: Simon Hausmann <simon.hausmann@qt.io>

src/testlib/qabstracttestlogger.cpp

@@ -39,6 +39,7 @@
 
 #include <QtTest/private/qabstracttestlogger_p.h>
 #include <QtTest/qtestassert.h>
+#include <qtestresult_p.h>
 
 #include <QtCore/qbytearray.h>
 #include <QtCore/qstring.h>
@@ -189,4 +190,26 @@ int qt_asprintf(QTestCharBuffer *str, const char *format, ...)
 
 }
 
+namespace QTestPrivate
+{
+
+void generateTestIdentifier(QTestCharBuffer *identifier, int parts)
+{
+    const char *testObject = parts & TestObject ? QTestResult::currentTestObjectName() : "";
+    const char *testFunction = parts & TestFunction ? (QTestResult::currentTestFunction() ? QTestResult::currentTestFunction() : "UnknownTestFunc") : "";
+    const char *objectFunctionFiller = parts & TestObject && parts & (TestFunction | TestDataTag) ? "::" : "";
+    const char *testFuctionStart = parts & TestFunction ? "(" : "";
+    const char *testFuctionEnd = parts & TestFunction ? ")" : "";
+
+    const char *dataTag = (parts & TestDataTag) && QTestResult::currentDataTag() ? QTestResult::currentDataTag() : "";
+    const char *globalDataTag = (parts & TestDataTag) && QTestResult::currentGlobalDataTag() ? QTestResult::currentGlobalDataTag() : "";
+    const char *tagFiller = (dataTag[0] && globalDataTag[0]) ? ":" : "";
+
+    QTest::qt_asprintf(identifier, "%s%s%s%s%s%s%s%s",
+        testObject, objectFunctionFiller, testFunction, testFuctionStart,
+        globalDataTag, tagFiller, dataTag, testFuctionEnd);
+}
+
+}
+
 QT_END_NAMESPACE

src/testlib/qabstracttestlogger_p.h

@@ -175,6 +175,11 @@ namespace QTest
     int qt_asprintf(QTestCharBuffer *buf, const char *format, ...);
 }
 
+namespace QTestPrivate
+{
+    enum IdentifierPart { TestObject = 0x1, TestFunction = 0x2, TestDataTag = 0x4, AllParts = 0xFFFF };
+    void generateTestIdentifier(QTestCharBuffer *identifier, int parts = AllParts);
+}
 
 QT_END_NAMESPACE
 

src/testlib/qappletestlogger.cpp

@@ -0,0 +1,144 @@
+/****************************************************************************
+**
+** Copyright (C) 2018 The Qt Company Ltd.
+** Contact: https://www.qt.io/licensing/
+**
+** This file is part of the QtTest module of the Qt Toolkit.
+**
+** $QT_BEGIN_LICENSE:LGPL$
+** Commercial License Usage
+** Licensees holding valid commercial Qt licenses may use this file in
+** accordance with the commercial license agreement provided with the
+** Software or, alternatively, in accordance with the terms contained in
+** a written agreement between you and The Qt Company. For licensing terms
+** and conditions see https://www.qt.io/terms-conditions. For further
+** information use the contact form at https://www.qt.io/contact-us.
+**
+** GNU Lesser General Public License Usage
+** Alternatively, this file may be used under the terms of the GNU Lesser
+** General Public License version 3 as published by the Free Software
+** Foundation and appearing in the file LICENSE.LGPL3 included in the
+** packaging of this file. Please review the following information to
+** ensure the GNU Lesser General Public License version 3 requirements
+** will be met: https://www.gnu.org/licenses/lgpl-3.0.html.
+**
+** GNU General Public License Usage
+** Alternatively, this file may be used under the terms of the GNU
+** General Public License version 2.0 or (at your option) the GNU General
+** Public license version 3 or any later version approved by the KDE Free
+** Qt Foundation. The licenses are as published by the Free Software
+** Foundation and appearing in the file LICENSE.GPL2 and LICENSE.GPL3
+** included in the packaging of this file. Please review the following
+** information to ensure the GNU General Public License requirements will
+** be met: https://www.gnu.org/licenses/gpl-2.0.html and
+** https://www.gnu.org/licenses/gpl-3.0.html.
+**
+** $QT_END_LICENSE$
+**
+****************************************************************************/
+
+#include "qappletestlogger_p.h"
+
+QT_BEGIN_NAMESPACE
+
+#if defined(QT_USE_APPLE_UNIFIED_LOGGING)
+
+using namespace QTestPrivate;
+
+bool QAppleTestLogger::debugLoggingEnabled()
+{
+    // Debug-level messages are only captured in memory when debug logging is
+    // enabled through a configuration change, which can happen automatically
+    // when running inside Xcode, or with the Console application open.
+    if (__builtin_available(macOS 10.12, iOS 10, tvOS 10, watchOS 3, *))
+        return os_log_type_enabled(OS_LOG_DEFAULT, OS_LOG_TYPE_DEBUG);
+
+    return false;
+}
+
+QAppleTestLogger::QAppleTestLogger(QAbstractTestLogger *logger)
+    : QAbstractTestLogger(nullptr)
+    , m_logger(logger)
+{
+}
+
+void QAppleTestLogger::enterTestFunction(const char *function)
+{
+    if (__builtin_available(macOS 10.12, iOS 10, tvOS 10, watchOS 3, *)) {
+        QTestCharBuffer testIdentifier;
+        QTestPrivate::generateTestIdentifier(&testIdentifier);
+        QString identifier = QString::fromLatin1(testIdentifier.data());
+        QMessageLogContext context(nullptr, 0, nullptr, "qt.test.enter");
+        QString message = identifier;
+        if (AppleUnifiedLogger::messageHandler(QtDebugMsg, context, message, identifier))
+            return; // AUL already printed to stderr
+    }
+
+    m_logger->enterTestFunction(function);
+}
+
+typedef QPair<QtMsgType, const char *> IncidentClassification;
+static IncidentClassification incidentTypeToClassification(QAbstractTestLogger::IncidentTypes type)
+{
+    switch (type) {
+    case QAbstractTestLogger::Pass:
+        return IncidentClassification(QtInfoMsg, "pass");
+    case QAbstractTestLogger::XFail:
+        return IncidentClassification(QtInfoMsg, "xpass");
+    case QAbstractTestLogger::Fail:
+        return IncidentClassification(QtCriticalMsg, "fail");
+    case QAbstractTestLogger::XPass:
+        return IncidentClassification(QtInfoMsg, "xpass");
+    case QAbstractTestLogger::BlacklistedPass:
+        return IncidentClassification(QtWarningMsg, "bpass");
+    case QAbstractTestLogger::BlacklistedFail:
+        return IncidentClassification(QtInfoMsg, "bfail");
+    }
+    return IncidentClassification(QtFatalMsg, nullptr);
+}
+
+void QAppleTestLogger::addIncident(IncidentTypes type, const char *description,
+                                   const char *file, int line)
+{
+    if (__builtin_available(macOS 10.12, iOS 10, tvOS 10, watchOS 3, *)) {
+        IncidentClassification incidentClassification = incidentTypeToClassification(type);
+
+        QTestCharBuffer category;
+        QTest::qt_asprintf(&category, "qt.test.%s", incidentClassification.second);
+        QMessageLogContext context(file, line, /* function = */ nullptr, category.data());
+
+        QTestCharBuffer subsystemBuffer;
+        // It would be nice to have the data tag as part of the subsystem too, but that
+        // will for some tests results in hundreds of thousands of log objects being
+        // created, so we limit the subsystem to test functions, which we can hope
+        // are reasonably limited.
+        generateTestIdentifier(&subsystemBuffer, TestObject | TestFunction);
+        QString subsystem = QString::fromLatin1(subsystemBuffer.data());
+
+        // We still want the full identifier as part of the message though
+        QTestCharBuffer testIdentifier;
+        generateTestIdentifier(&testIdentifier);
+        QString message = QString::fromLatin1(testIdentifier.data());
+        if (qstrlen(description))
+            message += QLatin1Char('\n') % QString::fromLatin1(description);
+
+        if (AppleUnifiedLogger::messageHandler(incidentClassification.first, context, message, subsystem))
+            return; // AUL already printed to stderr
+    }
+
+    m_logger->addIncident(type, description, file, line);
+}
+
+void QAppleTestLogger::addMessage(QtMsgType type, const QMessageLogContext &context, const QString &message)
+{
+    if (__builtin_available(macOS 10.12, iOS 10, tvOS 10, watchOS 3, *)) {
+        if (AppleUnifiedLogger::messageHandler(type, context, message))
+            return; // AUL already printed to stderr
+    }
+
+    m_logger->addMessage(type, context, message);
+}
+
+#endif // QT_USE_APPLE_UNIFIED_LOGGING
+
+QT_END_NAMESPACE

src/testlib/qappletestlogger_p.h

@@ -0,0 +1,96 @@
+/****************************************************************************
+**
+** Copyright (C) 2018 The Qt Company Ltd.
+** Contact: https://www.qt.io/licensing/
+**
+** This file is part of the QtTest module of the Qt Toolkit.
+**
+** $QT_BEGIN_LICENSE:LGPL$
+** Commercial License Usage
+** Licensees holding valid commercial Qt licenses may use this file in
+** accordance with the commercial license agreement provided with the
+** Software or, alternatively, in accordance with the terms contained in
+** a written agreement between you and The Qt Company. For licensing terms
+** and conditions see https://www.qt.io/terms-conditions. For further
+** information use the contact form at https://www.qt.io/contact-us.
+**
+** GNU Lesser General Public License Usage
+** Alternatively, this file may be used under the terms of the GNU Lesser
+** General Public License version 3 as published by the Free Software
+** Foundation and appearing in the file LICENSE.LGPL3 included in the
+** packaging of this file. Please review the following information to
+** ensure the GNU Lesser General Public License version 3 requirements
+** will be met: https://www.gnu.org/licenses/lgpl-3.0.html.
+**
+** GNU General Public License Usage
+** Alternatively, this file may be used under the terms of the GNU
+** General Public License version 2.0 or (at your option) the GNU General
+** Public license version 3 or any later version approved by the KDE Free
+** Qt Foundation. The licenses are as published by the Free Software
+** Foundation and appearing in the file LICENSE.GPL2 and LICENSE.GPL3
+** included in the packaging of this file. Please review the following
+** information to ensure the GNU General Public License requirements will
+** be met: https://www.gnu.org/licenses/gpl-2.0.html and
+** https://www.gnu.org/licenses/gpl-3.0.html.
+**
+** $QT_END_LICENSE$
+**
+****************************************************************************/
+
+#ifndef QAPPLETESTLOGGER_P_H
+#define QAPPLETESTLOGGER_P_H
+
+//
+//  W A R N I N G
+//  -------------
+//
+// This file is not part of the Qt API.  It exists purely as an
+// implementation detail.  This header file may change from version to
+// version without notice, or even be removed.
+//
+// We mean it.
+//
+
+#include <QtTest/private/qabstracttestlogger_p.h>
+
+#include <QtCore/private/qcore_mac_p.h>
+
+QT_BEGIN_NAMESPACE
+
+#if defined(QT_USE_APPLE_UNIFIED_LOGGING)
+class QAppleTestLogger : public QAbstractTestLogger
+{
+public:
+    static bool debugLoggingEnabled();
+
+    QAppleTestLogger(QAbstractTestLogger *logger);
+
+    void startLogging() override
+    { m_logger->startLogging(); }
+    void stopLogging() override
+    { m_logger->stopLogging(); }
+
+    void enterTestFunction(const char *function) override;
+     void leaveTestFunction() override
+    { m_logger->leaveTestFunction(); }
+
+    void addIncident(IncidentTypes type, const char *description,
+                     const char *file = 0, int line = 0) override;
+    void addMessage(QtMsgType, const QMessageLogContext &,
+            const QString &) override;
+
+    void addBenchmarkResult(const QBenchmarkResult &result) override
+    { m_logger->addBenchmarkResult(result); }
+
+    void addMessage(MessageTypes type, const QString &message,
+                            const char *file = 0, int line = 0) override
+    { m_logger->addMessage(type, message, file, line); }
+
+private:
+    QScopedPointer<QAbstractTestLogger> m_logger;
+};
+#endif
+
+QT_END_NAMESPACE
+
+#endif // QAPPLETESTLOGGER_P_H

src/testlib/qplaintestlogger.cpp

@@ -221,18 +221,6 @@ void QPlainTestLogger::outputMessage(const char *str)
     outputString(str);
 }
 
-static void testIdentifier(QTestCharBuffer *identifier)
-{
-    const char *testObject = QTestResult::currentTestObjectName();
-    const char *testFunction = QTestResult::currentTestFunction() ? QTestResult::currentTestFunction() : "UnknownTestFunc";
-
-    const char *dataTag = QTestResult::currentDataTag() ? QTestResult::currentDataTag() : "";
-    const char *globalDataTag = QTestResult::currentGlobalDataTag() ? QTestResult::currentGlobalDataTag() : "";
-    const char *tagFiller = (dataTag[0] && globalDataTag[0]) ? ":" : "";
-
-    QTest::qt_asprintf(identifier, "%s::%s(%s%s%s)", testObject, testFunction, globalDataTag, tagFiller, dataTag);
-}
-
 void QPlainTestLogger::printMessage(const char *type, const char *msg, const char *file, int line)
 {
     QTEST_ASSERT(type);
@@ -251,10 +239,10 @@ void QPlainTestLogger::printMessage(const char *type, const char *msg, const cha
     }
 
     const char *msgFiller = msg[0] ? " " : "";
-    QTestCharBuffer testIdent;
-    testIdentifier(&testIdent);
+    QTestCharBuffer testIdentifier;
+    QTestPrivate::generateTestIdentifier(&testIdentifier);
     QTest::qt_asprintf(&messagePrefix, "%s: %s%s%s%s\n",
-                       type, testIdent.data(), msgFiller, msg, failureLocation.data());
+                       type, testIdentifier.data(), msgFiller, msg, failureLocation.data());
 
     // In colored mode, printf above stripped our nonprintable control characters.
     // Put them back.

src/testlib/qtestlog.cpp

@@ -51,6 +51,10 @@
 #include <QtTest/private/qxctestlogger_p.h>
 #endif
 
+#if defined(Q_OS_DARWIN)
+#include <QtTest/private/qappletestlogger_p.h>
+#endif
+
 #include <QtCore/qatomic.h>
 #include <QtCore/qbytearray.h>
 #include <QtCore/QElapsedTimer>
@@ -502,6 +506,15 @@ void QTestLog::addLogger(LogMode mode, const char *filename)
         break;
 #endif
     }
+
+#if defined(QT_USE_APPLE_UNIFIED_LOGGING)
+    // Logger that also feeds messages to AUL. It needs to wrap the existing
+    // logger, as it needs to be able to short circuit the existing logger
+    // in case AUL prints to stderr.
+    if (QAppleTestLogger::debugLoggingEnabled())
+        logger = new QAppleTestLogger(logger);
+#endif
+
     QTEST_ASSERT(logger);
     QTest::TestLoggers::addLogger(logger);
 }

src/testlib/testlib.pro

@@ -78,6 +78,9 @@ embedded:QMAKE_CXXFLAGS += -fno-rtti
 mac {
     LIBS += -framework Security
 
+    SOURCES += qappletestlogger.cpp
+    HEADERS += qappletestlogger_p.h
+
     macos {
         HEADERS += qtestutil_macos_p.h
         OBJECTIVE_SOURCES += qtestutil_macos.mm