From a0c27e2130e788f417013136a44c251c7c893da5 Mon Sep 17 00:00:00 2001
From: Stephen Birarda <commit@birarda.com>
Date: Tue, 11 Oct 2016 13:17:57 -0700
Subject: [PATCH] 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 <QtCore/qloggingcategory.h>
+
 #include "AssetClient.h"
 #include "AssetUtils.h"
 #include "MappingRequest.h"
-#include <QtCore/qloggingcategory.h>
+#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 <QUrl>
 
+#include <PortableHighResolutionClock.h>
+
 #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;