Log HTTP requests and responses

Issue: #7873

src/libsync/CMakeLists.txt

@@ -26,6 +26,7 @@ set(libsync_SRCS
     discoveryphase.cpp
     encryptfolderjob.cpp
     filesystem.cpp
+    httplogger.cpp
     logger.cpp
     accessmanager.cpp
     configfile.cpp

src/libsync/abstractnetworkjob.cpp

@@ -28,11 +28,13 @@
 #include <QCoreApplication>
 #include <QAuthenticator>
 #include <QMetaEnum>
+#include <QRegularExpression>
 
 #include "common/asserts.h"
 #include "networkjobs.h"
 #include "account.h"
 #include "owncloudpropagator.h"
+#include "httplogger.h"
 
 #include "creds/abstractcredentials.h"
 
@@ -162,10 +164,9 @@ void AbstractNetworkJob::slotFinished()
     if (_reply->error() == QNetworkReply::SslHandshakeFailedError) {
         qCWarning(lcNetworkJob) << "SslHandshakeFailedError: " << errorString() << " : can be caused by a webserver wanting SSL client certificates";
     }
-
     // Qt doesn't yet transparently resend HTTP2 requests, do so here
     const auto maxHttp2Resends = 3;
-    QByteArray verb = requestVerb(*reply());
+    QByteArray verb = HttpLogger::requestVerb(*reply());
     if (_reply->error() == QNetworkReply::ContentReSendError
         && _reply->attribute(QNetworkRequest::HTTP2WasUsedAttribute).toBool()) {
 
@@ -414,27 +415,6 @@ QString errorMessage(const QString &baseError, const QByteArray &body)
     return msg;
 }
 
-QByteArray requestVerb(const QNetworkReply &reply)
-{
-    switch (reply.operation()) {
-    case QNetworkAccessManager::HeadOperation:
-        return "HEAD";
-    case QNetworkAccessManager::GetOperation:
-        return "GET";
-    case QNetworkAccessManager::PutOperation:
-        return "PUT";
-    case QNetworkAccessManager::PostOperation:
-        return "POST";
-    case QNetworkAccessManager::DeleteOperation:
-        return "DELETE";
-    case QNetworkAccessManager::CustomOperation:
-        return reply.request().attribute(QNetworkRequest::CustomVerbAttribute).toByteArray();
-    case QNetworkAccessManager::UnknownOperation:
-        break;
-    }
-    return QByteArray();
-}
-
 QString networkReplyErrorString(const QNetworkReply &reply)
 {
     QString base = reply.errorString();
@@ -446,7 +426,7 @@ QString networkReplyErrorString(const QNetworkReply &reply)
         return base;
     }
 
-    return AbstractNetworkJob::tr(R"(Server replied "%1 %2" to "%3 %4")").arg(QString::number(httpStatus), httpReason, requestVerb(reply), reply.request().url().toDisplayString());
+    return AbstractNetworkJob::tr(R"(Server replied "%1 %2" to "%3 %4")").arg(QString::number(httpStatus), httpReason, HttpLogger::requestVerb(reply), reply.request().url().toDisplayString());
 }
 
 void AbstractNetworkJob::retry()
@@ -454,7 +434,7 @@ void AbstractNetworkJob::retry()
     ENFORCE(_reply);
     auto req = _reply->request();
     QUrl requestedUrl = req.url();
-    QByteArray verb = requestVerb(*_reply);
+    QByteArray verb = HttpLogger::requestVerb(*_reply);
     qCInfo(lcNetworkJob) << "Restarting" << verb << requestedUrl;
     resetTimeout();
     if (_requestBody) {

src/libsync/abstractnetworkjob.h

@@ -230,12 +230,6 @@ QString OWNCLOUDSYNC_EXPORT extractErrorMessage(const QByteArray &errorResponse)
 /** Builds a error message based on the error and the reply body. */
 QString OWNCLOUDSYNC_EXPORT errorMessage(const QString &baseError, const QByteArray &body);
 
-/** Helper to construct the HTTP verb used in the request
- *
- * Returns an empty QByteArray for UnknownOperation.
- */
-QByteArray OWNCLOUDSYNC_EXPORT requestVerb(const QNetworkReply &reply);
-
 /** Nicer errorString() for QNetworkReply
  *
  * By default QNetworkReply::errorString() often produces messages like

src/libsync/accessmanager.cpp

@@ -26,6 +26,7 @@
 #include "cookiejar.h"
 #include "accessmanager.h"
 #include "common/utility.h"
+#include "httplogger.h"
 
 namespace OCC {
 
@@ -89,7 +90,10 @@ QNetworkReply *AccessManager::createRequest(QNetworkAccessManager::Operation op,
     }
 #endif
 
-    return QNetworkAccessManager::createRequest(op, newRequest, outgoingData);
+    HttpLogger::logRequest(newRequest, op, outgoingData);
+    const auto reply = QNetworkAccessManager::createRequest(op, newRequest, outgoingData);
+    HttpLogger::logReplyOnFinished(reply);
+    return reply;
 }
 
 } // namespace OCC

src/libsync/httplogger.cpp

@@ -0,0 +1,142 @@
+/*
+ * Copyright (C) by Hannah von Reth <hannah.vonreth@owncloud.com>
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program 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 General Public License
+ * for more details.
+ */
+
+#include "httplogger.h"
+
+#include <QRegularExpression>
+#include <QLoggingCategory>
+#include <QBuffer>
+
+namespace {
+Q_LOGGING_CATEGORY(lcNetworkHttp, "sync.httplogger", QtWarningMsg)
+
+const qint64 PeekSize = 1024 * 1024;
+
+const QByteArray XRequestId(){
+    return QByteArrayLiteral("X-Request-ID");
+}
+
+bool isTextBody(const QString &s)
+{
+    static const QRegularExpression regexp(QStringLiteral("^(text/.*|(application/(xml|json|x-www-form-urlencoded)(;|$)))"));
+    return regexp.match(s).hasMatch();
+}
+
+void logHttp(bool isRequest, const QByteArray &verb, const QString &url, const QByteArray &id, const QString &contentType, const qint64 &contentLength, const QList<QNetworkReply::RawHeaderPair> &header, QIODevice *device)
+{
+    QString msg;
+    QTextStream stream(&msg);
+    stream << id << ": ";
+    if (isRequest) {
+        stream << "Request: ";
+    } else {
+        stream << "Response: ";
+    }
+    stream << verb << " " << url << " Header: { ";
+    for (const auto &it : header) {
+        stream << it.first << ": ";
+        if (it.first == "Authorization") {
+            stream << "[redacted]";
+        } else {
+            stream << it.second;
+        }
+        stream << ", ";
+    }
+    stream << "} Data: [";
+    if (contentLength > 0) {
+        if (isTextBody(contentType)) {
+            if (!device->isOpen()) {
+                Q_ASSERT(dynamic_cast<QBuffer *>(device));
+                // should we close it again?
+                device->open(QIODevice::ReadOnly);
+            }
+            Q_ASSERT(device->pos() == 0);
+            stream << device->peek(PeekSize);
+            if (PeekSize < contentLength)
+            {
+                stream << "...(" << (contentLength - PeekSize) << "bytes elided)";
+            }
+        } else {
+            stream << contentLength << " bytes of " << contentType << " data";
+        }
+    }
+    stream << "]";
+    qCInfo(lcNetworkHttp) << msg;
+}
+}
+
+
+namespace OCC {
+
+
+void HttpLogger::logReplyOnFinished(const QNetworkReply *reply)
+{
+    if (!lcNetworkHttp().isInfoEnabled()) {
+        return;
+    }
+    QObject::connect(reply, &QNetworkReply::finished, reply, [reply] {
+        logHttp(false,
+            requestVerb(*reply),
+            reply->url().toString(),
+            reply->request().rawHeader(XRequestId()),
+            reply->header(QNetworkRequest::ContentTypeHeader).toString(),
+            reply->header(QNetworkRequest::ContentLengthHeader).toInt(),
+            reply->rawHeaderPairs(),
+            const_cast<QNetworkReply *>(reply));
+    });
+}
+
+void HttpLogger::logRequest(const QNetworkRequest &request, QNetworkAccessManager::Operation operation, QIODevice *device)
+{
+    if (!lcNetworkHttp().isInfoEnabled()) {
+        return;
+    }
+    const auto keys = request.rawHeaderList();
+    QList<QNetworkReply::RawHeaderPair> header;
+    header.reserve(keys.size());
+    for (const auto &key : keys) {
+        header << qMakePair(key, request.rawHeader(key));
+    }
+    logHttp(true,
+        requestVerb(operation, request),
+        request.url().toString(),
+        request.rawHeader(XRequestId()),
+        request.header(QNetworkRequest::ContentTypeHeader).toString(),
+        device ? device->size() : 0,
+        header,
+        device);
+}
+
+QByteArray HttpLogger::requestVerb(QNetworkAccessManager::Operation operation, const QNetworkRequest &request)
+{
+    switch (operation) {
+    case QNetworkAccessManager::HeadOperation:
+        return QByteArrayLiteral("HEAD");
+    case QNetworkAccessManager::GetOperation:
+        return QByteArrayLiteral("GET");
+    case QNetworkAccessManager::PutOperation:
+        return QByteArrayLiteral("PUT");
+    case QNetworkAccessManager::PostOperation:
+        return QByteArrayLiteral("POST");
+    case QNetworkAccessManager::DeleteOperation:
+        return QByteArrayLiteral("DELETE");
+    case QNetworkAccessManager::CustomOperation:
+        return request.attribute(QNetworkRequest::CustomVerbAttribute).toByteArray();
+    case QNetworkAccessManager::UnknownOperation:
+        break;
+    }
+    Q_UNREACHABLE();
+}
+
+}

src/libsync/httplogger.h

@@ -0,0 +1,35 @@
+/*
+ * Copyright (C) by Hannah von Reth <hannah.vonreth@owncloud.com>
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program 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 General Public License
+ * for more details.
+ */
+#pragma once
+
+#include "owncloudlib.h"
+
+#include <QNetworkReply>
+#include <QUrl>
+
+namespace OCC {
+namespace HttpLogger {
+    void OWNCLOUDSYNC_EXPORT logReplyOnFinished(const QNetworkReply *reply);
+    void OWNCLOUDSYNC_EXPORT logRequest(const QNetworkRequest &request, QNetworkAccessManager::Operation operation, QIODevice *device);
+
+    /**
+    * Helper to construct the HTTP verb used in the request
+    */
+    QByteArray OWNCLOUDSYNC_EXPORT requestVerb(QNetworkAccessManager::Operation operation, const QNetworkRequest &request);
+    inline QByteArray requestVerb(const QNetworkReply &reply)
+    {
+        return requestVerb(reply.operation(), reply.request());
+    }
+}
+}