From d76e0ec6d8a730b34e1f522b377f20a9d0e0aa70 Mon Sep 17 00:00:00 2001 From: ckamm Date: Fri, 13 Jan 2017 14:44:45 +0100 Subject: [PATCH] Reset stuck chunked uploads eventually #5344 (#5443) Previously this wasn't happening for errors that were not NormalErrors because they don't end up in the blacklist. This revises the resetting logic to be independent of the error blacklist and make use of UploadInfo::errorCount instead. 412 errors should reset chunked uploads because they might be indicative of a checksum error. Additionally, server bugs might require that additional errors cause an upload reset. To allow that, a new capability is added that can be used to advise the client about this. --- src/libsync/capabilities.cpp | 9 ++++ src/libsync/capabilities.h | 19 +++++++ src/libsync/owncloudpropagator.cpp | 19 ++++--- src/libsync/propagateupload.cpp | 21 ++++++++ src/libsync/propagateupload.h | 7 +++ src/libsync/propagateuploadng.cpp | 27 +++++++--- src/libsync/propagateuploadv1.cpp | 9 +++- src/libsync/syncjournalfilerecord.cpp | 3 +- test/CMakeLists.txt | 1 + test/syncenginetestutils.h | 11 ++++ test/testuploadreset.cpp | 75 +++++++++++++++++++++++++++ 11 files changed, 182 insertions(+), 19 deletions(-) create mode 100644 test/testuploadreset.cpp diff --git a/src/libsync/capabilities.cpp b/src/libsync/capabilities.cpp index 5bd5d1c4c..cee5f1aeb 100644 --- a/src/libsync/capabilities.cpp +++ b/src/libsync/capabilities.cpp @@ -121,4 +121,13 @@ bool Capabilities::chunkingParallelUploadDisabled() const return _capabilities["dav"].toMap()["chunkingParallelUploadDisabled"].toBool(); } +QList Capabilities::httpErrorCodesThatResetFailingChunkedUploads() const +{ + QList list; + foreach (const auto & t, _capabilities["dav"].toMap()["httpErrorCodesThatResetFailingChunkedUploads"].toList()) { + list.push_back(t.toInt()); + } + return list; +} + } diff --git a/src/libsync/capabilities.h b/src/libsync/capabilities.h index 76e2b6f22..e3d8c013c 100644 --- a/src/libsync/capabilities.h +++ b/src/libsync/capabilities.h @@ -81,6 +81,25 @@ public: */ QByteArray uploadChecksumType() const; + /** + * List of HTTP error codes should be guaranteed to eventually reset + * failing chunked uploads. + * + * The resetting works by tracking UploadInfo::errorCount. + * + * Note that other error codes than the ones listed here may reset the + * upload as well. + * + * Motivation: See #5344. They should always be reset on 412 (possibly + * checksum error), but broken servers may also require resets on + * unusual error codes such as 503. + * + * Path: dav/httpErrorCodesThatResetFailingChunkedUploads + * Default: [] + * Example: [503, 500] + */ + QList httpErrorCodesThatResetFailingChunkedUploads() const; + private: QVariantMap _capabilities; }; diff --git a/src/libsync/owncloudpropagator.cpp b/src/libsync/owncloudpropagator.cpp index e2ce6c5dd..86a9c16cb 100644 --- a/src/libsync/owncloudpropagator.cpp +++ b/src/libsync/owncloudpropagator.cpp @@ -99,7 +99,7 @@ int OwncloudPropagator::hardMaximumActiveJob() /** Updates, creates or removes a blacklist entry for the given item. * - * Returns whether the file is in the blacklist now. + * Returns whether the error should be suppressed. */ static bool blacklistCheck(SyncJournalDb* journal, const SyncFileItem& item) { @@ -108,16 +108,13 @@ static bool blacklistCheck(SyncJournalDb* journal, const SyncFileItem& item) if (newEntry.isValid()) { journal->updateErrorBlacklistEntry(newEntry); - // Also clear upload info if any so we don't resume from the same transfer-id if there was too many failures (#5344) - // (maybe the reason is that the state for this transfer id is broken on the server.) - if (newEntry._retryCount > 3) { - journal->setUploadInfo(item._file, SyncJournalDb::UploadInfo()); - } } else if (oldEntry.isValid()) { journal->wipeErrorBlacklistEntry(item._file); } - return newEntry.isValid(); + // In some cases we add errors to the blacklist for tracking, but don't + // want to actively suppress them. + return newEntry.isValid() && newEntry._ignoreDuration > 0; } void PropagateItemJob::done(SyncFileItem::Status status, const QString &errorString) @@ -144,10 +141,12 @@ void PropagateItemJob::done(SyncFileItem::Status status, const QString &errorStr switch( status ) { case SyncFileItem::SoftError: case SyncFileItem::FatalError: - // do not blacklist in case of soft error or fatal error. - break; case SyncFileItem::NormalError: - if (blacklistCheck(_propagator->_journal, *_item) && _item->_hasBlacklistEntry) { + // For normal errors, we blacklist aggressively, otherwise only on + // explicit request. + if ((status == SyncFileItem::NormalError || _item->_errorMayBeBlacklisted) + && blacklistCheck(_propagator->_journal, *_item) + && _item->_hasBlacklistEntry) { // do not error if the item was, and continues to be, blacklisted status = SyncFileItem::FileIgnored; _item->_errorString.prepend(tr("Continue blacklisting:") + " "); diff --git a/src/libsync/propagateupload.cpp b/src/libsync/propagateupload.cpp index 388752ad9..5b699d933 100644 --- a/src/libsync/propagateupload.cpp +++ b/src/libsync/propagateupload.cpp @@ -493,6 +493,27 @@ void PropagateUploadFileCommon::slotPollFinished() finalize(); } +void PropagateUploadFileCommon::checkResettingErrors() +{ + if (_item->_httpErrorCode == 412 + || _propagator->account()->capabilities().httpErrorCodesThatResetFailingChunkedUploads() + .contains(_item->_httpErrorCode)) { + auto uploadInfo = _propagator->_journal->getUploadInfo(_item->_file); + uploadInfo._errorCount += 1; + if (uploadInfo._errorCount > 3) { + qDebug() << "Reset transfer of" << _item->_file + << "due to repeated error" << _item->_httpErrorCode; + uploadInfo = SyncJournalDb::UploadInfo(); + } else { + qDebug() << "Error count for maybe-reset error" << _item->_httpErrorCode + << "on file" << _item->_file + << "is" << uploadInfo._errorCount; + } + _propagator->_journal->setUploadInfo(_item->_file, uploadInfo); + _propagator->_journal->commit("Upload info"); + } +} + void PropagateUploadFileCommon::slotJobDestroyed(QObject* job) { _jobs.erase(std::remove(_jobs.begin(), _jobs.end(), job) , _jobs.end()); diff --git a/src/libsync/propagateupload.h b/src/libsync/propagateupload.h index bac3e112b..23737ea77 100644 --- a/src/libsync/propagateupload.h +++ b/src/libsync/propagateupload.h @@ -232,6 +232,13 @@ private slots: void slotPollFinished(); protected: + /** + * Checks whether the current error is one that should reset the whole + * transfer if it happens too often. If so: Bump UploadInfo::errorCount + * and maybe perform the reset. + */ + void checkResettingErrors(); + // Bases headers that need to be sent with every chunk QMap headers(); diff --git a/src/libsync/propagateuploadng.cpp b/src/libsync/propagateuploadng.cpp index ed4e702c0..578c06745 100644 --- a/src/libsync/propagateuploadng.cpp +++ b/src/libsync/propagateuploadng.cpp @@ -373,13 +373,8 @@ void PropagateUploadFileNG::slotPutFinished() errorString = job->reply()->rawHeader("OC-ErrorString"); } - // FIXME! can this happen for the chunks? - if (_item->_httpErrorCode == 412) { - // Precondition Failed: Maybe the bad etag is in the database, we need to clear the - // parent folder etag so we won't read from DB next sync. - _propagator->_journal->avoidReadFromDbOnNextSync(_item->_file); - _propagator->_anotherSyncNeeded = true; - } + // Ensure errors that should eventually reset the chunked upload are tracked. + checkResettingErrors(); SyncFileItem::Status status = classifyError(err, _item->_httpErrorCode, &_propagator->_anotherSyncNeeded); @@ -416,6 +411,12 @@ void PropagateUploadFileNG::slotPutFinished() _propagator->_journal->wipeErrorBlacklistEntry(_item->_file); _item->_hasBlacklistEntry = false; } + + // Reset the error count on successful chunk upload + auto uploadInfo = _propagator->_journal->getUploadInfo(_item->_file); + uploadInfo._errorCount = 0; + _propagator->_journal->setUploadInfo(_item->_file, uploadInfo); + _propagator->_journal->commit("Upload info"); } startNextChunk(); } @@ -429,6 +430,18 @@ void PropagateUploadFileNG::slotMoveJobFinished() _item->_httpErrorCode = job->reply()->attribute(QNetworkRequest::HttpStatusCodeAttribute).toInt(); if (err != QNetworkReply::NoError) { + if (_item->_httpErrorCode == 412) { + // Precondition Failed: Either an etag or a checksum mismatch. + + // Maybe the bad etag is in the database, we need to clear the + // parent folder etag so we won't read from DB next sync. + _propagator->_journal->avoidReadFromDbOnNextSync(_item->_file); + _propagator->_anotherSyncNeeded = true; + } + + // Ensure errors that should eventually reset the chunked upload are tracked. + checkResettingErrors(); + SyncFileItem::Status status = classifyError(err, _item->_httpErrorCode, &_propagator->_anotherSyncNeeded); QString errorString = errorMessage(job->errorString(), job->reply()->readAll()); diff --git a/src/libsync/propagateuploadv1.cpp b/src/libsync/propagateuploadv1.cpp index 2e68fe529..7425a259f 100644 --- a/src/libsync/propagateuploadv1.cpp +++ b/src/libsync/propagateuploadv1.cpp @@ -101,6 +101,7 @@ void PropagateUploadFileV1::startNextChunk() // if there's only one chunk, it's the final one isFinalChunk = true; } + qDebug() << _chunkCount << isFinalChunk << chunkStart << currentChunkSize; if (isFinalChunk && !_transmissionChecksumType.isEmpty()) { headers[checkSumHeaderC] = makeChecksumHeader( @@ -215,12 +216,17 @@ void PropagateUploadFileV1::slotPutFinished() } if (_item->_httpErrorCode == 412) { - // Precondition Failed: Maybe the bad etag is in the database, we need to clear the + // Precondition Failed: Either an etag or a checksum mismatch. + + // Maybe the bad etag is in the database, we need to clear the // parent folder etag so we won't read from DB next sync. _propagator->_journal->avoidReadFromDbOnNextSync(_item->_file); _propagator->_anotherSyncNeeded = true; } + // Ensure errors that should eventually reset the chunked upload are tracked. + checkResettingErrors(); + SyncFileItem::Status status = classifyError(err, _item->_httpErrorCode, &_propagator->_anotherSyncNeeded); abortWithError(status, errorString); @@ -304,6 +310,7 @@ void PropagateUploadFileV1::slotPutFinished() pi._chunk = (currentChunk + _startChunk + 1) % _chunkCount ; // next chunk to start with pi._transferid = _transferId; pi._modtime = Utility::qDateTimeFromTime_t(_item->_modtime); + pi._errorCount = 0; // successful chunk upload resets _propagator->_journal->setUploadInfo(_item->_file, pi); _propagator->_journal->commit("Upload info"); startNextChunk(); diff --git a/src/libsync/syncjournalfilerecord.cpp b/src/libsync/syncjournalfilerecord.cpp index e60569adf..cbab1b479 100644 --- a/src/libsync/syncjournalfilerecord.cpp +++ b/src/libsync/syncjournalfilerecord.cpp @@ -121,7 +121,7 @@ bool SyncJournalErrorBlacklistRecord::isValid() const { return ! _file.isEmpty() && (!_lastTryEtag.isEmpty() || _lastTryModtime != 0) - && _lastTryTime > 0 && _ignoreDuration > 0; + && _lastTryTime > 0; } SyncJournalErrorBlacklistRecord SyncJournalErrorBlacklistRecord::update( @@ -163,6 +163,7 @@ SyncJournalErrorBlacklistRecord SyncJournalErrorBlacklistRecord::update( qDebug() << "Fatal Error condition" << item._httpErrorCode << ", maximum blacklist ignore time!"; entry._ignoreDuration = maxBlacklistTime; } + entry._ignoreDuration = qBound(minBlacklistTime, entry._ignoreDuration, maxBlacklistTime); qDebug() << "blacklisting " << item._file diff --git a/test/CMakeLists.txt b/test/CMakeLists.txt index fd817c734..3732deaa1 100644 --- a/test/CMakeLists.txt +++ b/test/CMakeLists.txt @@ -48,6 +48,7 @@ if(HAVE_QT5 AND NOT BUILD_WITH_QT4) owncloud_add_test(SyncEngine "syncenginetestutils.h") owncloud_add_test(SyncFileStatusTracker "syncenginetestutils.h") owncloud_add_test(ChunkingNg "syncenginetestutils.h") + owncloud_add_test(UploadReset "syncenginetestutils.h") endif(HAVE_QT5 AND NOT BUILD_WITH_QT4) SET(FolderMan_SRC ../src/gui/folderman.cpp) diff --git a/test/syncenginetestutils.h b/test/syncenginetestutils.h index 88e30216c..665dc2016 100644 --- a/test/syncenginetestutils.h +++ b/test/syncenginetestutils.h @@ -64,6 +64,7 @@ public: virtual void appendByte(const QString &relativePath) = 0; virtual void mkdir(const QString &relativePath) = 0; virtual void rename(const QString &relativePath, const QString &relativeDestinationDirectory) = 0; + virtual void setModTime(const QString &relativePath, const QDateTime &modTime) = 0; }; class DiskFileModifier : public FileModifier @@ -114,6 +115,9 @@ public: QVERIFY(_rootDir.exists(from)); QVERIFY(_rootDir.rename(from, to)); } + void setModTime(const QString &relativePath, const QDateTime &modTime) override { + OCC::FileSystem::setModTime(_rootDir.filePath(relativePath), OCC::Utility::qDateTimeToTime_t(modTime)); + } }; class FileInfo : public FileModifier @@ -201,6 +205,12 @@ public: dir->children.insert(newPathComponents.fileName(), std::move(fi)); } + void setModTime(const QString &relativePath, const QDateTime &modTime) override { + FileInfo *file = findInvalidatingEtags(relativePath); + Q_ASSERT(file); + file->lastModified = modTime; + } + FileInfo *find(const PathComponents &pathComponents, const bool invalidateEtags = false) { if (pathComponents.isEmpty()) { if (invalidateEtags) @@ -641,6 +651,7 @@ public: Q_INVOKABLE void respond() { setAttribute(QNetworkRequest::HttpStatusCodeAttribute, 500); + setError(InternalServerError, "Internal Server Fake Error"); emit metaDataChanged(); emit finished(); } diff --git a/test/testuploadreset.cpp b/test/testuploadreset.cpp new file mode 100644 index 000000000..bf077ddee --- /dev/null +++ b/test/testuploadreset.cpp @@ -0,0 +1,75 @@ +/* + * This software is in the public domain, furnished "as is", without technical + * support, and with no warranty, express or implied, as to its usefulness for + * any purpose. + * + */ + +#include +#include "syncenginetestutils.h" +#include +#include + +using namespace OCC; + +class TestUploadReset : public QObject +{ + Q_OBJECT + +private slots: + + // Verify that the chunked transfer eventually gets reset with the new chunking + void testFileUploadNg() { + FakeFolder fakeFolder{FileInfo::A12_B12_C12_S12()}; + + fakeFolder.syncEngine().account()->setCapabilities({ { "dav", QVariantMap{ + {"chunking", "1.0"}, + {"httpErrorCodesThatResetFailingChunkedUploads", QVariantList{500} } } } }); + + const int size = 100 * 1000 * 1000; // 100 MB + fakeFolder.localModifier().insert("A/a0", size); + QDateTime modTime = QDateTime::currentDateTime(); + fakeFolder.localModifier().setModTime("A/a0", modTime); + + // Create a transfer id, so we can make the final MOVE fail + SyncJournalDb::UploadInfo uploadInfo; + uploadInfo._transferid = 1; + uploadInfo._valid = true; + uploadInfo._modtime = modTime; + fakeFolder.syncEngine().journal()->setUploadInfo("A/a0", uploadInfo); + + fakeFolder.uploadState().mkdir("1"); + fakeFolder.serverErrorPaths().append("1/.file"); + + QVERIFY(!fakeFolder.syncOnce()); + + uploadInfo = fakeFolder.syncEngine().journal()->getUploadInfo("A/a0"); + QCOMPARE(uploadInfo._errorCount, 1); + QCOMPARE(uploadInfo._transferid, 1); + + fakeFolder.syncEngine().journal()->wipeErrorBlacklist(); + QVERIFY(!fakeFolder.syncOnce()); + + uploadInfo = fakeFolder.syncEngine().journal()->getUploadInfo("A/a0"); + QCOMPARE(uploadInfo._errorCount, 2); + QCOMPARE(uploadInfo._transferid, 1); + + fakeFolder.syncEngine().journal()->wipeErrorBlacklist(); + QVERIFY(!fakeFolder.syncOnce()); + + uploadInfo = fakeFolder.syncEngine().journal()->getUploadInfo("A/a0"); + QCOMPARE(uploadInfo._errorCount, 3); + QCOMPARE(uploadInfo._transferid, 1); + + fakeFolder.syncEngine().journal()->wipeErrorBlacklist(); + QVERIFY(!fakeFolder.syncOnce()); + + uploadInfo = fakeFolder.syncEngine().journal()->getUploadInfo("A/a0"); + QCOMPARE(uploadInfo._errorCount, 0); + QCOMPARE(uploadInfo._transferid, 0); + QVERIFY(!uploadInfo._valid); + } +}; + +QTEST_GUILESS_MAIN(TestUploadReset) +#include "testuploadreset.moc" -- 2.30.2