From 0043a84234c615553fa5b6d9bb39daec32332412 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Fri, 25 Mar 2016 10:22:14 -0700 Subject: [PATCH 1/6] guard the SendQueue sleep and send a user activity when weird --- libraries/networking/src/udt/SendQueue.cpp | 30 +++++++++++++++++++++- 1 file changed, 29 insertions(+), 1 deletion(-) diff --git a/libraries/networking/src/udt/SendQueue.cpp b/libraries/networking/src/udt/SendQueue.cpp index 2ffa42cb82..6fb6ab00e7 100644 --- a/libraries/networking/src/udt/SendQueue.cpp +++ b/libraries/networking/src/udt/SendQueue.cpp @@ -17,6 +17,7 @@ #include #include +#include #include #include @@ -27,6 +28,7 @@ #include "ControlPacket.h" #include "Packet.h" #include "PacketList.h" +#include "../UserActivityLogger.h" #include "Socket.h" using namespace udt; @@ -328,7 +330,33 @@ void SendQueue::run() { nextPacketTimestamp += std::chrono::microseconds(nextPacketDelta); // sleep as long as we need until next packet send, if we can - const auto timeToSleep = duration_cast(nextPacketTimestamp - p_high_resolution_clock::now()); + auto now = p_high_resolution_clock::now(); + auto timeToSleep = duration_cast(nextPacketTimestamp - now); + + // we're seeing SendQueues sleep for a long period of time here, + // which can lock the NodeList if it's attempting to clear connections + // for now we guard this by capping the time this thread and sleep for + + const int MAX_SEND_QUEUE_SLEEP_USECS = 5000000; + if (timeToSleep.count() > MAX_SEND_QUEUE_SLEEP_USECS) { + // alright, we're in a weird state + // we want to know why this is happening so we can implement a better fix than this guard + // send some details up to the API (if the user allows us) that indicate how we could such a large timeToSleep + static const QString SEND_QUEUE_LONG_SLEEP_ACTION = "sendqueue-sleep"; + + // setup a json object with the details we want + QJsonObject longSleepObject; + longSleepObject["timeToSleep"] = timeToSleep.count(); + longSleepObject["packetSendPeriod"] = _packetSendPeriod.load(); + longSleepObject["nextPacketDelta"] = nextPacketDelta; + longSleepObject["nextPacketTimestamp"] = nextPacketTimestamp.time_since_epoch().count(); + longSleepObject["then"] = now.time_since_epoch().count(); + + // hopefully send this event using the user activity logger + UserActivityLogger::getInstance().logAction(SEND_QUEUE_LONG_SLEEP_ACTION, longSleepObject); + + timeToSleep = std::chrono::microseconds(MAX_SEND_QUEUE_SLEEP_USECS); + } std::this_thread::sleep_for(timeToSleep); } From d8859def37bbe793760b7fdd4d675ee97606bf22 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Fri, 25 Mar 2016 10:47:06 -0700 Subject: [PATCH 2/6] fix for AccountManagerAuth::Type register, consts --- libraries/networking/src/AccountManager.cpp | 4 +++- libraries/networking/src/UserActivityLogger.cpp | 6 ------ libraries/networking/src/UserActivityLogger.h | 1 - libraries/networking/src/udt/SendQueue.cpp | 6 +++--- 4 files changed, 6 insertions(+), 11 deletions(-) diff --git a/libraries/networking/src/AccountManager.cpp b/libraries/networking/src/AccountManager.cpp index af30132b70..ec68ee7369 100644 --- a/libraries/networking/src/AccountManager.cpp +++ b/libraries/networking/src/AccountManager.cpp @@ -81,6 +81,8 @@ AccountManager::AccountManager() : qRegisterMetaType("QHttpMultiPart*"); + qRegisterMetaType(); + connect(&_accountInfo, &DataServerAccountInfo::balanceChanged, this, &AccountManager::accountInfoBalanceChanged); } @@ -215,7 +217,7 @@ void AccountManager::sendRequest(const QString& path, if (thread() != QThread::currentThread()) { QMetaObject::invokeMethod(this, "sendRequest", Q_ARG(const QString&, path), - Q_ARG(AccountManagerAuth::Type, AccountManagerAuth::Required), + Q_ARG(AccountManagerAuth::Type, authType), Q_ARG(QNetworkAccessManager::Operation, operation), Q_ARG(const JSONCallbackParameters&, callbackParams), Q_ARG(const QByteArray&, dataByteArray), diff --git a/libraries/networking/src/UserActivityLogger.cpp b/libraries/networking/src/UserActivityLogger.cpp index f2019ba9a9..2406753b0d 100644 --- a/libraries/networking/src/UserActivityLogger.cpp +++ b/libraries/networking/src/UserActivityLogger.cpp @@ -58,8 +58,6 @@ void UserActivityLogger::logAction(QString action, QJsonObject details, JSONCall // if no callbacks specified, call our owns if (params.isEmpty()) { - params.jsonCallbackReceiver = this; - params.jsonCallbackMethod = "requestFinished"; params.errorCallbackReceiver = this; params.errorCallbackMethod = "requestError"; } @@ -70,10 +68,6 @@ void UserActivityLogger::logAction(QString action, QJsonObject details, JSONCall params, NULL, multipart); } -void UserActivityLogger::requestFinished(QNetworkReply& requestReply) { - // qCDebug(networking) << object; -} - void UserActivityLogger::requestError(QNetworkReply& errorReply) { qCDebug(networking) << errorReply.error() << "-" << errorReply.errorString(); } diff --git a/libraries/networking/src/UserActivityLogger.h b/libraries/networking/src/UserActivityLogger.h index 2811be86a8..fa323f1cca 100644 --- a/libraries/networking/src/UserActivityLogger.h +++ b/libraries/networking/src/UserActivityLogger.h @@ -39,7 +39,6 @@ public slots: void wentTo(QString destinationType, QString destinationName); private slots: - void requestFinished(QNetworkReply& requestReply); void requestError(QNetworkReply& errorReply); private: diff --git a/libraries/networking/src/udt/SendQueue.cpp b/libraries/networking/src/udt/SendQueue.cpp index 6fb6ab00e7..121a888c62 100644 --- a/libraries/networking/src/udt/SendQueue.cpp +++ b/libraries/networking/src/udt/SendQueue.cpp @@ -337,8 +337,8 @@ void SendQueue::run() { // which can lock the NodeList if it's attempting to clear connections // for now we guard this by capping the time this thread and sleep for - const int MAX_SEND_QUEUE_SLEEP_USECS = 5000000; - if (timeToSleep.count() > MAX_SEND_QUEUE_SLEEP_USECS) { + const microseconds MAX_SEND_QUEUE_SLEEP_USECS { 5000000 }; + if (timeToSleep > MAX_SEND_QUEUE_SLEEP_USECS) { // alright, we're in a weird state // we want to know why this is happening so we can implement a better fix than this guard // send some details up to the API (if the user allows us) that indicate how we could such a large timeToSleep @@ -355,7 +355,7 @@ void SendQueue::run() { // hopefully send this event using the user activity logger UserActivityLogger::getInstance().logAction(SEND_QUEUE_LONG_SLEEP_ACTION, longSleepObject); - timeToSleep = std::chrono::microseconds(MAX_SEND_QUEUE_SLEEP_USECS); + timeToSleep = MAX_SEND_QUEUE_SLEEP_USECS; } std::this_thread::sleep_for(timeToSleep); From 74e041e9aab42f5cf7454cbe9303714045848a96 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Fri, 25 Mar 2016 11:16:31 -0700 Subject: [PATCH 3/6] cast chrono durations to int explicitly --- libraries/networking/src/udt/SendQueue.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/libraries/networking/src/udt/SendQueue.cpp b/libraries/networking/src/udt/SendQueue.cpp index 121a888c62..4642689eee 100644 --- a/libraries/networking/src/udt/SendQueue.cpp +++ b/libraries/networking/src/udt/SendQueue.cpp @@ -346,11 +346,11 @@ void SendQueue::run() { // setup a json object with the details we want QJsonObject longSleepObject; - longSleepObject["timeToSleep"] = timeToSleep.count(); + longSleepObject["timeToSleep"] = int64_t(timeToSleep.count()); longSleepObject["packetSendPeriod"] = _packetSendPeriod.load(); longSleepObject["nextPacketDelta"] = nextPacketDelta; - longSleepObject["nextPacketTimestamp"] = nextPacketTimestamp.time_since_epoch().count(); - longSleepObject["then"] = now.time_since_epoch().count(); + longSleepObject["nextPacketTimestamp"] = int64_t(nextPacketTimestamp.time_since_epoch().count()); + longSleepObject["then"] = int64_t(now.time_since_epoch().count()); // hopefully send this event using the user activity logger UserActivityLogger::getInstance().logAction(SEND_QUEUE_LONG_SLEEP_ACTION, longSleepObject); From ce4d56fb90923bf054be1434f08b720f25dbeccf Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Fri, 25 Mar 2016 13:06:17 -0700 Subject: [PATCH 4/6] add warning for long sendqueue sleeps --- libraries/networking/src/udt/SendQueue.cpp | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/libraries/networking/src/udt/SendQueue.cpp b/libraries/networking/src/udt/SendQueue.cpp index 4642689eee..a84a0b35d2 100644 --- a/libraries/networking/src/udt/SendQueue.cpp +++ b/libraries/networking/src/udt/SendQueue.cpp @@ -337,8 +337,14 @@ void SendQueue::run() { // which can lock the NodeList if it's attempting to clear connections // for now we guard this by capping the time this thread and sleep for - const microseconds MAX_SEND_QUEUE_SLEEP_USECS { 5000000 }; + const microseconds MAX_SEND_QUEUE_SLEEP_USECS { 2000000 }; if (timeToSleep > MAX_SEND_QUEUE_SLEEP_USECS) { + qWarning() << "udt::SendQueue wanted to sleep for" << timeToSleep.count() << "microseconds"; + qWarning() << "Capping sleep to" << MAX_SEND_QUEUE_SLEEP_USECS.count(); + qWarning() << "PSP:" << _packetSendPeriod << "NPD:" << nextPacketDelta + << "NPT:" << nextPacketTimestamp.time_since_epoch().count() + << "NOW:" << now.time_since_epoch().count(); + // alright, we're in a weird state // we want to know why this is happening so we can implement a better fix than this guard // send some details up to the API (if the user allows us) that indicate how we could such a large timeToSleep From 044fb983d74f975735e66a8a8bfbb8f665de8730 Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Fri, 25 Mar 2016 13:07:54 -0700 Subject: [PATCH 5/6] cast chrono durations to qint64 --- libraries/networking/src/udt/SendQueue.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/libraries/networking/src/udt/SendQueue.cpp b/libraries/networking/src/udt/SendQueue.cpp index a84a0b35d2..8933c984d5 100644 --- a/libraries/networking/src/udt/SendQueue.cpp +++ b/libraries/networking/src/udt/SendQueue.cpp @@ -352,11 +352,11 @@ void SendQueue::run() { // setup a json object with the details we want QJsonObject longSleepObject; - longSleepObject["timeToSleep"] = int64_t(timeToSleep.count()); + longSleepObject["timeToSleep"] = qint64(timeToSleep.count()); longSleepObject["packetSendPeriod"] = _packetSendPeriod.load(); longSleepObject["nextPacketDelta"] = nextPacketDelta; - longSleepObject["nextPacketTimestamp"] = int64_t(nextPacketTimestamp.time_since_epoch().count()); - longSleepObject["then"] = int64_t(now.time_since_epoch().count()); + longSleepObject["nextPacketTimestamp"] = qint64(nextPacketTimestamp.time_since_epoch().count()); + longSleepObject["then"] = qint64(now.time_since_epoch().count()); // hopefully send this event using the user activity logger UserActivityLogger::getInstance().logAction(SEND_QUEUE_LONG_SLEEP_ACTION, longSleepObject); From d9abc79b5d3a7b420071799777bcd553ba5cc87f Mon Sep 17 00:00:00 2001 From: Stephen Birarda Date: Fri, 25 Mar 2016 13:37:13 -0700 Subject: [PATCH 6/6] return for AccountManager sendRequest if threads do not match --- libraries/networking/src/AccountManager.cpp | 1 + 1 file changed, 1 insertion(+) diff --git a/libraries/networking/src/AccountManager.cpp b/libraries/networking/src/AccountManager.cpp index ec68ee7369..e97b077f24 100644 --- a/libraries/networking/src/AccountManager.cpp +++ b/libraries/networking/src/AccountManager.cpp @@ -223,6 +223,7 @@ void AccountManager::sendRequest(const QString& path, Q_ARG(const QByteArray&, dataByteArray), Q_ARG(QHttpMultiPart*, dataMultiPart), Q_ARG(QVariantMap, propertyMap)); + return; } QNetworkAccessManager& networkAccessManager = NetworkAccessManager::getInstance();