From 9ff04e98d62f93a7a6003fc80d189e96c6835f84 Mon Sep 17 00:00:00 2001 From: Kitsune Ral Date: Wed, 28 Feb 2018 17:11:10 +0900 Subject: Skip retry interval if the last job attempt timed out Closes #175. --- jobs/basejob.cpp | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) (limited to 'jobs/basejob.cpp') diff --git a/jobs/basejob.cpp b/jobs/basejob.cpp index c3b110f0..7669d1d4 100644 --- a/jobs/basejob.cpp +++ b/jobs/basejob.cpp @@ -373,7 +373,8 @@ void BaseJob::finishJob() // TODO: The whole retrying thing should be put to ConnectionManager // otherwise independently retrying jobs make a bit of notification // storm towards the UI. - const auto retryInterval = getNextRetryInterval(); + const auto retryInterval = + error() == TimeoutError ? 0 : getNextRetryInterval(); ++d->retriesTaken; qCWarning(d->logCat) << this << "will take retry" << d->retriesTaken << "in" << retryInterval/1000 << "s"; -- cgit v1.2.3 From 4e78035d03817c29ceac46bdf9cb045e4ba3a101 Mon Sep 17 00:00:00 2001 From: Krombel Date: Tue, 20 Mar 2018 23:33:42 +0100 Subject: ignore possible appendixes from content type Currently libqmatrixclient fails checking the `Content-Type` header when there is an appendix like "charset". That is allowed e.g. in [rfc7231](https://tools.ietf.org/html/rfc7231#section-3.1.1.5)) One example is a Content-Type `application/json` vs `application/json;charset=UTF-8` Setting of the charset appendis is currently not supported. It fails with libqmatrixclient.jobs: "LoginJob" status 106 : "Incorrect content type of the response" This PR aims to just drop that appendix as it is currently not handled somewhere else. --- jobs/basejob.cpp | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) (limited to 'jobs/basejob.cpp') diff --git a/jobs/basejob.cpp b/jobs/basejob.cpp index 7669d1d4..981b75b1 100644 --- a/jobs/basejob.cpp +++ b/jobs/basejob.cpp @@ -282,9 +282,12 @@ bool checkContentType(const QByteArray& type, const QByteArrayList& patterns) if (patterns.isEmpty()) return true; + // ignore possible appendixes of the content type + const auto ctype = type.split(';').front(); + for (const auto& pattern: patterns) { - if (pattern.startsWith('*') || type == pattern) // Fast lane + if (pattern.startsWith('*') || ctype == pattern) // Fast lane return true; auto patternParts = pattern.split('/'); @@ -292,7 +295,7 @@ bool checkContentType(const QByteArray& type, const QByteArrayList& patterns) "BaseJob: Expected content type should have up to two" " /-separated parts; violating pattern: " + pattern); - if (type.split('/').front() == patternParts.front() && + if (ctype.split('/').front() == patternParts.front() && patternParts.back() == "*") return true; // Exact match already went on fast lane } -- cgit v1.2.3 From bac178f488299ec37ebe86aa91053cf1133d1c12 Mon Sep 17 00:00:00 2001 From: Kitsune Ral Date: Fri, 23 Mar 2018 10:43:39 +0900 Subject: BaseJob::start(): self-destruct if not succesfully started Closes #193. --- jobs/basejob.cpp | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) (limited to 'jobs/basejob.cpp') diff --git a/jobs/basejob.cpp b/jobs/basejob.cpp index 981b75b1..eb250723 100644 --- a/jobs/basejob.cpp +++ b/jobs/basejob.cpp @@ -235,8 +235,12 @@ void BaseJob::start(const ConnectionData* connData) { d->connection = connData; beforeStart(connData); - sendRequest(); - afterStart(connData, d->reply.data()); + if (status().good()) + sendRequest(); + if (status().good()) + afterStart(connData, d->reply.data()); + if (!status().good()) + QTimer::singleShot(0, this, &BaseJob::finishJob); } void BaseJob::sendRequest() -- cgit v1.2.3 From 503957c86a84f1be190719a17984df1bb1267658 Mon Sep 17 00:00:00 2001 From: Kitsune Ral Date: Wed, 28 Mar 2018 11:29:41 +0900 Subject: BaseJob: small refactoring and cleanup in logging code --- jobs/basejob.cpp | 17 +++-------------- jobs/basejob.h | 12 +++++++++++- 2 files changed, 14 insertions(+), 15 deletions(-) (limited to 'jobs/basejob.cpp') diff --git a/jobs/basejob.cpp b/jobs/basejob.cpp index eb250723..5198c45c 100644 --- a/jobs/basejob.cpp +++ b/jobs/basejob.cpp @@ -84,18 +84,6 @@ class BaseJob::Private LoggingCategory logCat = JOBS; }; -inline QDebug operator<<(QDebug dbg, const BaseJob* j) -{ - return dbg << j->objectName(); -} - -QDebug QMatrixClient::operator<<(QDebug dbg, const BaseJob::Status& s) -{ - QRegularExpression filter { "(access_token)(=|: )[-_A-Za-z0-9]+" }; - return dbg << s.code << ':' - << QString(s.message).replace(filter, "\\1 HIDDEN"); -} - BaseJob::BaseJob(HttpVerb verb, const QString& name, const QString& endpoint, bool needsToken) : BaseJob(verb, name, endpoint, Query { }, Data { }, needsToken) { } @@ -319,7 +307,7 @@ BaseJob::Status BaseJob::checkReply(QNetworkReply* reply) const if (checkContentType(reply->rawHeader("Content-Type"), d->expectedContentTypes)) return NoError; - else + else // A warning in the logs might be more proper instead return { IncorrectResponseError, "Incorrect content type of the response" }; @@ -383,7 +371,7 @@ void BaseJob::finishJob() const auto retryInterval = error() == TimeoutError ? 0 : getNextRetryInterval(); ++d->retriesTaken; - qCWarning(d->logCat) << this << "will take retry" << d->retriesTaken + qCWarning(d->logCat) << this << "will retry" << d->retriesTaken << "in" << retryInterval/1000 << "s"; d->retryTimer.start(retryInterval); emit retryScheduled(d->retriesTaken, retryInterval); @@ -456,6 +444,7 @@ void BaseJob::setStatus(Status s) void BaseJob::setStatus(int code, QString message) { + message.replace(d->connection->accessToken(), "(REDACTED)"); setStatus({ code, message }); } diff --git a/jobs/basejob.h b/jobs/basejob.h index a5b457c5..fa253d96 100644 --- a/jobs/basejob.h +++ b/jobs/basejob.h @@ -98,7 +98,12 @@ namespace QMatrixClient Status(int c, QString m) : code(c), message(std::move(m)) { } bool good() const { return code < ErrorLevel; } - friend QDebug operator<<(QDebug dbg, const Status& s); + friend QDebug operator<<(QDebug dbg, const Status& s) + { + QDebug(dbg).noquote().nospace() + << s.code << ": " << s.message; + return dbg; + } int code; QString message; @@ -124,6 +129,11 @@ namespace QMatrixClient Q_INVOKABLE duration_t getNextRetryInterval() const; Q_INVOKABLE duration_t millisToRetry() const; + friend QDebug operator<<(QDebug dbg, const BaseJob* j) + { + return dbg << j->objectName(); + } + public slots: void start(const ConnectionData* connData); -- cgit v1.2.3 From d602de60433da80fc66a7152881d3dfe934eca62 Mon Sep 17 00:00:00 2001 From: Kitsune Ral Date: Wed, 28 Mar 2018 11:33:06 +0900 Subject: BaseJob: Process error 429 (Too Many Requests) The job will retry after the period either advised by the server or the default retry period. Closes #186. --- jobs/basejob.cpp | 24 ++++++++++++++++++++++++ jobs/basejob.h | 1 + 2 files changed, 25 insertions(+) (limited to 'jobs/basejob.cpp') diff --git a/jobs/basejob.cpp b/jobs/basejob.cpp index 5198c45c..37345338 100644 --- a/jobs/basejob.cpp +++ b/jobs/basejob.cpp @@ -263,7 +263,28 @@ void BaseJob::gotReply() { auto json = QJsonDocument::fromJson(d->reply->readAll()).object(); if (!json.isEmpty()) + { + if (error() == TooManyRequestsError) + { + QString msg = tr("Too many requests"); + auto retryInterval = json.value("retry_after_ms").toInt(-1); + if (retryInterval != -1) + msg += tr(", next retry advised after %1 ms") + .arg(retryInterval); + else // We still have to figure some reasonable interval + retryInterval = getNextRetryInterval(); + + setStatus(TooManyRequestsError, msg); + + // Shortcut to retry instead of executing the whole finishJob() + stop(); + qCWarning(d->logCat) << this << "will retry in" << retryInterval; + d->retryTimer.start(retryInterval); + emit retryScheduled(d->retriesTaken, retryInterval); + return; + } setStatus(IncorrectRequestError, json.value("error").toString()); + } } finishJob(); @@ -324,6 +345,9 @@ BaseJob::Status BaseJob::checkReply(QNetworkReply* reply) const return { NotFoundError, reply->errorString() }; default: + if (reply->attribute(QNetworkRequest::HttpStatusCodeAttribute) + .toInt() == 429) // Qt doesn't know about it yet + return { TooManyRequestsError, tr("Too many requests") }; return { NetworkError, reply->errorString() }; } } diff --git a/jobs/basejob.h b/jobs/basejob.h index fa253d96..ed630a67 100644 --- a/jobs/basejob.h +++ b/jobs/basejob.h @@ -62,6 +62,7 @@ namespace QMatrixClient , NotFoundError , IncorrectRequestError , IncorrectResponseError + , TooManyRequestsError , UserDefinedError = 200 }; -- cgit v1.2.3 From b2d22d7ce9d7235cf9ab61268e48102ff06cb727 Mon Sep 17 00:00:00 2001 From: Kitsune Ral Date: Wed, 28 Mar 2018 12:26:31 +0900 Subject: BaseJob: more improvements in logging and errors detection --- jobs/basejob.cpp | 16 +++++++++++----- 1 file changed, 11 insertions(+), 5 deletions(-) (limited to 'jobs/basejob.cpp') diff --git a/jobs/basejob.cpp b/jobs/basejob.cpp index 37345338..79cfb9e0 100644 --- a/jobs/basejob.cpp +++ b/jobs/basejob.cpp @@ -264,7 +264,8 @@ void BaseJob::gotReply() auto json = QJsonDocument::fromJson(d->reply->readAll()).object(); if (!json.isEmpty()) { - if (error() == TooManyRequestsError) + if (error() == TooManyRequestsError || + json.value("errcode").toString() == "M_LIMIT_EXCEEDED") { QString msg = tr("Too many requests"); auto retryInterval = json.value("retry_after_ms").toInt(-1); @@ -318,10 +319,16 @@ bool checkContentType(const QByteArray& type, const QByteArrayList& patterns) BaseJob::Status BaseJob::checkReply(QNetworkReply* reply) const { - qCDebug(d->logCat) << this << "returned" + const auto httpCode = + reply->attribute(QNetworkRequest::HttpStatusCodeAttribute).toInt(); + qCDebug(d->logCat).nospace().noquote() << this << " returned HTTP code " + << httpCode << ": " << (reply->error() == QNetworkReply::NoError ? "Success" : reply->errorString()) - << "from" << reply->url().toDisplayString(); + << " (URL: " << reply->url().toDisplayString() << ")"; + + // Should we check httpCode instead? Maybe even use it in BaseJob::Status? + // That would make codes logs slightly more readable. switch( reply->error() ) { case QNetworkReply::NoError: @@ -345,8 +352,7 @@ BaseJob::Status BaseJob::checkReply(QNetworkReply* reply) const return { NotFoundError, reply->errorString() }; default: - if (reply->attribute(QNetworkRequest::HttpStatusCodeAttribute) - .toInt() == 429) // Qt doesn't know about it yet + if (httpCode == 429) // Qt doesn't know about it yet return { TooManyRequestsError, tr("Too many requests") }; return { NetworkError, reply->errorString() }; } -- cgit v1.2.3 From 244fa53c10ee8697ff30e4135f6ac4cb4abb4506 Mon Sep 17 00:00:00 2001 From: Kitsune Ral Date: Wed, 28 Mar 2018 13:19:21 +0900 Subject: BaseJob: Dump error body (if there's any) to logs; detect error 429 more reliably --- jobs/basejob.cpp | 58 ++++++++++++++++++++++++++++++++------------------------ 1 file changed, 33 insertions(+), 25 deletions(-) (limited to 'jobs/basejob.cpp') diff --git a/jobs/basejob.cpp b/jobs/basejob.cpp index 79cfb9e0..3cde7c50 100644 --- a/jobs/basejob.cpp +++ b/jobs/basejob.cpp @@ -261,30 +261,37 @@ void BaseJob::gotReply() setStatus(parseReply(d->reply.data())); else { - auto json = QJsonDocument::fromJson(d->reply->readAll()).object(); - if (!json.isEmpty()) + const auto body = d->reply->readAll(); + if (!body.isEmpty()) { - if (error() == TooManyRequestsError || - json.value("errcode").toString() == "M_LIMIT_EXCEEDED") - { - QString msg = tr("Too many requests"); - auto retryInterval = json.value("retry_after_ms").toInt(-1); - if (retryInterval != -1) - msg += tr(", next retry advised after %1 ms") - .arg(retryInterval); - else // We still have to figure some reasonable interval - retryInterval = getNextRetryInterval(); - - setStatus(TooManyRequestsError, msg); - - // Shortcut to retry instead of executing the whole finishJob() - stop(); - qCWarning(d->logCat) << this << "will retry in" << retryInterval; - d->retryTimer.start(retryInterval); - emit retryScheduled(d->retriesTaken, retryInterval); - return; + qCDebug(d->logCat).noquote() << "Error body:" << body; + auto json = QJsonDocument::fromJson(body).object(); + if (json.isEmpty()) + setStatus(IncorrectRequestError, body); + else { + if (error() == TooManyRequestsError || + json.value("errcode").toString() == "M_LIMIT_EXCEEDED") + { + QString msg = tr("Too many requests"); + auto retryInterval = json.value("retry_after_ms").toInt(-1); + if (retryInterval != -1) + msg += tr(", next retry advised after %1 ms") + .arg(retryInterval); + else // We still have to figure some reasonable interval + retryInterval = getNextRetryInterval(); + + setStatus(TooManyRequestsError, msg); + + // Shortcut to retry instead of executing finishJob() + stop(); + qCWarning(d->logCat) + << this << "will retry in" << retryInterval; + d->retryTimer.start(retryInterval); + emit retryScheduled(d->retriesTaken, retryInterval); + return; + } + setStatus(IncorrectRequestError, json.value("error").toString()); } - setStatus(IncorrectRequestError, json.value("error").toString()); } } @@ -327,8 +334,11 @@ BaseJob::Status BaseJob::checkReply(QNetworkReply* reply) const "Success" : reply->errorString()) << " (URL: " << reply->url().toDisplayString() << ")"; + if (httpCode == 429) // Qt doesn't know about it yet + return { TooManyRequestsError, tr("Too many requests") }; + // Should we check httpCode instead? Maybe even use it in BaseJob::Status? - // That would make codes logs slightly more readable. + // That would make codes in logs slightly more readable. switch( reply->error() ) { case QNetworkReply::NoError: @@ -352,8 +362,6 @@ BaseJob::Status BaseJob::checkReply(QNetworkReply* reply) const return { NotFoundError, reply->errorString() }; default: - if (httpCode == 429) // Qt doesn't know about it yet - return { TooManyRequestsError, tr("Too many requests") }; return { NetworkError, reply->errorString() }; } } -- cgit v1.2.3