From ec5850b82bce689d482b3cacd956b512e2d6206e Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Mon, 10 Oct 2016 17:59:01 -0700 Subject: [PATCH 1/6] emit ReceivedMessage progress signals more frequently for new timeout --- libraries/networking/src/ReceivedMessage.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/libraries/networking/src/ReceivedMessage.cpp b/libraries/networking/src/ReceivedMessage.cpp index cd3eb03473..e860fa0829 100644 --- a/libraries/networking/src/ReceivedMessage.cpp +++ b/libraries/networking/src/ReceivedMessage.cpp @@ -54,7 +54,7 @@ void ReceivedMessage::appendPacket(NLPacket& packet) { "We should not be appending to a complete message"); // Limit progress signal to every X packets - const int EMIT_PROGRESS_EVERY_X_PACKETS = 100; + const int EMIT_PROGRESS_EVERY_X_PACKETS = 5; ++_numPackets; From 826c2f1a9febf132c8dabcced0c67ce81e2ac860 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Tue, 11 Oct 2016 09:53:02 -0700 Subject: [PATCH 2/6] push the AssetResourceRequest timeout to 15s --- libraries/networking/src/AssetResourceRequest.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/libraries/networking/src/AssetResourceRequest.cpp b/libraries/networking/src/AssetResourceRequest.cpp index f320f00dbb..3c53288dfb 100644 --- a/libraries/networking/src/AssetResourceRequest.cpp +++ b/libraries/networking/src/AssetResourceRequest.cpp @@ -39,7 +39,7 @@ bool AssetResourceRequest::urlIsAssetHash() const { void AssetResourceRequest::setupTimer() { Q_ASSERT(!_sendTimer); - static const int TIMEOUT_MS = 2000; + static const int TIMEOUT_MS = 15000; _sendTimer = new QTimer(this); connect(_sendTimer, &QTimer::timeout, this, &AssetResourceRequest::onTimeout); From a0c27e2130e788f417013136a44c251c7c893da5 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Tue, 11 Oct 2016 13:17:57 -0700 Subject: [PATCH 3/6] remove timer forced timeouts in ARR, occasionally ouput DL progress --- .../networking/src/AssetResourceRequest.cpp | 72 ++++++------------- .../networking/src/AssetResourceRequest.h | 10 ++- libraries/networking/src/ReceivedMessage.cpp | 2 +- 3 files changed, 26 insertions(+), 58 deletions(-) diff --git a/libraries/networking/src/AssetResourceRequest.cpp b/libraries/networking/src/AssetResourceRequest.cpp index 3c53288dfb..2be4145cd0 100644 --- a/libraries/networking/src/AssetResourceRequest.cpp +++ b/libraries/networking/src/AssetResourceRequest.cpp @@ -11,10 +11,12 @@ #include "AssetResourceRequest.h" +#include + #include "AssetClient.h" #include "AssetUtils.h" #include "MappingRequest.h" -#include +#include "NetworkLogging.h" AssetResourceRequest::~AssetResourceRequest() { if (_assetMappingRequest) { @@ -24,10 +26,6 @@ AssetResourceRequest::~AssetResourceRequest() { if (_assetRequest) { _assetRequest->deleteLater(); } - - if (_sendTimer) { - cleanupTimer(); - } } bool AssetResourceRequest::urlIsAssetHash() const { @@ -37,24 +35,6 @@ bool AssetResourceRequest::urlIsAssetHash() const { return hashRegex.exactMatch(_url.toString()); } -void AssetResourceRequest::setupTimer() { - Q_ASSERT(!_sendTimer); - static const int TIMEOUT_MS = 15000; - - _sendTimer = new QTimer(this); - connect(_sendTimer, &QTimer::timeout, this, &AssetResourceRequest::onTimeout); - - _sendTimer->setSingleShot(true); - _sendTimer->start(TIMEOUT_MS); -} - -void AssetResourceRequest::cleanupTimer() { - Q_ASSERT(_sendTimer); - disconnect(_sendTimer, 0, this, 0); - _sendTimer->deleteLater(); - _sendTimer = nullptr; -} - void AssetResourceRequest::doSend() { // We'll either have a hash or an ATP path to a file (that maps to a hash) if (urlIsAssetHash()) { @@ -81,8 +61,6 @@ void AssetResourceRequest::requestMappingForPath(const AssetPath& path) { Q_ASSERT(_state == InProgress); Q_ASSERT(request == _assetMappingRequest); - cleanupTimer(); - switch (request->getError()) { case MappingRequest::NoError: // we have no error, we should have a resulting hash - use that to send of a request for that asset @@ -118,7 +96,6 @@ void AssetResourceRequest::requestMappingForPath(const AssetPath& path) { _assetMappingRequest = nullptr; }); - setupTimer(); _assetMappingRequest->start(); } @@ -133,8 +110,6 @@ void AssetResourceRequest::requestHash(const AssetHash& hash) { Q_ASSERT(_state == InProgress); Q_ASSERT(req == _assetRequest); Q_ASSERT(req->getState() == AssetRequest::Finished); - - cleanupTimer(); switch (req->getError()) { case AssetRequest::Error::NoError: @@ -162,35 +137,30 @@ void AssetResourceRequest::requestHash(const AssetHash& hash) { _assetRequest = nullptr; }); - setupTimer(); _assetRequest->start(); } void AssetResourceRequest::onDownloadProgress(qint64 bytesReceived, qint64 bytesTotal) { Q_ASSERT(_state == InProgress); - // We've received data, so reset the timer - _sendTimer->start(); - emit progress(bytesReceived, bytesTotal); + + static const int DOWNLOAD_PROGRESS_LOG_INTERVAL_SECONDS = 5; + auto now = p_high_resolution_clock::now(); + + // if we haven't received the full asset check if it is time to output progress to log + // we do so every X seconds to assist with ATP download tracking + + if (bytesReceived != bytesTotal + && now - _lastProgressDebug > std::chrono::seconds(DOWNLOAD_PROGRESS_LOG_INTERVAL_SECONDS)) { + + int percentage = roundf((float) bytesReceived / (float) bytesTotal * 100.0f); + + qCDebug(networking).nospace() << "Progress for " << _url.path() << " - " + << bytesReceived << " bytes of " << bytesTotal << " - " << percentage << "%"; + + _lastProgressDebug = now; + } + } -void AssetResourceRequest::onTimeout() { - if (_state == InProgress) { - qWarning() << "Asset request timed out: " << _url; - if (_assetRequest) { - disconnect(_assetRequest, 0, this, 0); - _assetRequest->deleteLater(); - _assetRequest = nullptr; - } - if (_assetMappingRequest) { - disconnect(_assetMappingRequest, 0, this, 0); - _assetMappingRequest->deleteLater(); - _assetMappingRequest = nullptr; - } - _result = Timeout; - _state = Finished; - emit finished(); - } - cleanupTimer(); -} diff --git a/libraries/networking/src/AssetResourceRequest.h b/libraries/networking/src/AssetResourceRequest.h index c462fbc3f8..93f76cb154 100644 --- a/libraries/networking/src/AssetResourceRequest.h +++ b/libraries/networking/src/AssetResourceRequest.h @@ -14,6 +14,8 @@ #include +#include + #include "AssetRequest.h" #include "ResourceRequest.h" @@ -28,21 +30,17 @@ protected: private slots: void onDownloadProgress(qint64 bytesReceived, qint64 bytesTotal); - void onTimeout(); private: - void setupTimer(); - void cleanupTimer(); - bool urlIsAssetHash() const; void requestMappingForPath(const AssetPath& path); void requestHash(const AssetHash& hash); - QTimer* _sendTimer { nullptr }; - GetMappingRequest* _assetMappingRequest { nullptr }; AssetRequest* _assetRequest { nullptr }; + + p_high_resolution_clock::time_point _lastProgressDebug; }; #endif diff --git a/libraries/networking/src/ReceivedMessage.cpp b/libraries/networking/src/ReceivedMessage.cpp index e860fa0829..150ae5c91b 100644 --- a/libraries/networking/src/ReceivedMessage.cpp +++ b/libraries/networking/src/ReceivedMessage.cpp @@ -54,7 +54,7 @@ void ReceivedMessage::appendPacket(NLPacket& packet) { "We should not be appending to a complete message"); // Limit progress signal to every X packets - const int EMIT_PROGRESS_EVERY_X_PACKETS = 5; + const int EMIT_PROGRESS_EVERY_X_PACKETS = 50; ++_numPackets; From 07d0a038a56450188077874160cba46a163aae90 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Tue, 11 Oct 2016 13:21:15 -0700 Subject: [PATCH 4/6] set the initial last progress debug 5s back --- libraries/networking/src/AssetResourceRequest.cpp | 9 ++++++++- libraries/networking/src/AssetResourceRequest.h | 2 +- 2 files changed, 9 insertions(+), 2 deletions(-) diff --git a/libraries/networking/src/AssetResourceRequest.cpp b/libraries/networking/src/AssetResourceRequest.cpp index 2be4145cd0..f3e5f33507 100644 --- a/libraries/networking/src/AssetResourceRequest.cpp +++ b/libraries/networking/src/AssetResourceRequest.cpp @@ -18,6 +18,14 @@ #include "MappingRequest.h" #include "NetworkLogging.h" +static const int DOWNLOAD_PROGRESS_LOG_INTERVAL_SECONDS = 5; + +AssetResourceRequest::AssetResourceRequest(const QUrl& url) : + ResourceRequest(url) +{ + _lastProgressDebug = p_high_resolution_clock::now() - std::chrono::seconds(DOWNLOAD_PROGRESS_LOG_INTERVAL_SECONDS); +} + AssetResourceRequest::~AssetResourceRequest() { if (_assetMappingRequest) { _assetMappingRequest->deleteLater(); @@ -145,7 +153,6 @@ void AssetResourceRequest::onDownloadProgress(qint64 bytesReceived, qint64 bytes emit progress(bytesReceived, bytesTotal); - static const int DOWNLOAD_PROGRESS_LOG_INTERVAL_SECONDS = 5; auto now = p_high_resolution_clock::now(); // if we haven't received the full asset check if it is time to output progress to log diff --git a/libraries/networking/src/AssetResourceRequest.h b/libraries/networking/src/AssetResourceRequest.h index 93f76cb154..3f110fae17 100644 --- a/libraries/networking/src/AssetResourceRequest.h +++ b/libraries/networking/src/AssetResourceRequest.h @@ -22,7 +22,7 @@ class AssetResourceRequest : public ResourceRequest { Q_OBJECT public: - AssetResourceRequest(const QUrl& url) : ResourceRequest(url) { } + AssetResourceRequest(const QUrl& url); virtual ~AssetResourceRequest() override; protected: From 20ea7e6c987b7466e7d9ce275303b09e22c0eee3 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Tue, 11 Oct 2016 13:21:53 -0700 Subject: [PATCH 5/6] change QLoggingCategory include casing --- libraries/networking/src/AssetResourceRequest.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/libraries/networking/src/AssetResourceRequest.cpp b/libraries/networking/src/AssetResourceRequest.cpp index f3e5f33507..731803abcd 100644 --- a/libraries/networking/src/AssetResourceRequest.cpp +++ b/libraries/networking/src/AssetResourceRequest.cpp @@ -11,7 +11,7 @@ #include "AssetResourceRequest.h" -#include +#include #include "AssetClient.h" #include "AssetUtils.h" From 504e92607a71736f36edf48b3c3825eb727fbf85 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Tue, 11 Oct 2016 13:23:52 -0700 Subject: [PATCH 6/6] change format of debug message --- libraries/networking/src/AssetResourceRequest.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/libraries/networking/src/AssetResourceRequest.cpp b/libraries/networking/src/AssetResourceRequest.cpp index 731803abcd..11ced60ec4 100644 --- a/libraries/networking/src/AssetResourceRequest.cpp +++ b/libraries/networking/src/AssetResourceRequest.cpp @@ -164,7 +164,7 @@ void AssetResourceRequest::onDownloadProgress(qint64 bytesReceived, qint64 bytes int percentage = roundf((float) bytesReceived / (float) bytesTotal * 100.0f); qCDebug(networking).nospace() << "Progress for " << _url.path() << " - " - << bytesReceived << " bytes of " << bytesTotal << " - " << percentage << "%"; + << bytesReceived << " of " << bytesTotal << " bytes - " << percentage << "%"; _lastProgressDebug = now; }