From e89b6c5d2c457be9b7c70a3140237a07aa4d1c04 Mon Sep 17 00:00:00 2001 From: ZappoMan Date: Thu, 20 Apr 2017 17:26:31 -0700 Subject: [PATCH] some initial debugging on tpose avatars --- interface/src/avatar/Avatar.cpp | 17 ++++++++++++----- libraries/avatars/src/AvatarData.cpp | 5 +++++ libraries/avatars/src/AvatarHashMap.cpp | 4 ++++ .../src/model-networking/ModelCache.h | 1 + .../networking/src/HTTPResourceRequest.cpp | 17 +++++++++++++---- libraries/networking/src/ReceivedMessage.cpp | 6 ++++-- libraries/networking/src/ReceivedMessage.h | 5 +++++ libraries/networking/src/ResourceCache.cpp | 5 +++-- libraries/networking/src/ResourceCache.h | 3 +++ libraries/networking/src/udt/PacketList.h | 2 ++ libraries/render-utils/src/Model.h | 1 + 11 files changed, 53 insertions(+), 13 deletions(-) diff --git a/interface/src/avatar/Avatar.cpp b/interface/src/avatar/Avatar.cpp index 5b996a3cdf..563de9434d 100644 --- a/interface/src/avatar/Avatar.cpp +++ b/interface/src/avatar/Avatar.cpp @@ -341,6 +341,8 @@ void Avatar::updateAvatarEntities() { void Avatar::simulate(float deltaTime, bool inView) { PROFILE_RANGE(simulation, "simulate"); + //qDebug() << __FUNCTION__ << "skeleton download attempts:" << _skeletonModel->getResourceDownloadAttempts(); + _simulationRate.increment(); if (inView) { _simulationInViewRate.increment(); @@ -1112,11 +1114,16 @@ void Avatar::setSkeletonModelURL(const QUrl& skeletonModelURL) { void Avatar::setModelURLFinished(bool success) { if (!success && _skeletonModelURL != AvatarData::defaultFullAvatarModelUrl()) { - qCWarning(interfaceapp) << "Using default after failing to load Avatar model: " << _skeletonModelURL; - // call _skeletonModel.setURL, but leave our copy of _skeletonModelURL alone. This is so that - // we don't redo this every time we receive an identity packet from the avatar with the bad url. - QMetaObject::invokeMethod(_skeletonModel.get(), "setURL", - Qt::QueuedConnection, Q_ARG(QUrl, AvatarData::defaultFullAvatarModelUrl())); + // FIXME -- + if (_skeletonModel->getResourceDownloadAttempts() > 4) { + qCWarning(interfaceapp) << "Using default after failing to load Avatar model: " << _skeletonModelURL; + // call _skeletonModel.setURL, but leave our copy of _skeletonModelURL alone. This is so that + // we don't redo this every time we receive an identity packet from the avatar with the bad url. + QMetaObject::invokeMethod(_skeletonModel.get(), "setURL", + Qt::QueuedConnection, Q_ARG(QUrl, AvatarData::defaultFullAvatarModelUrl())); + } else { + qCWarning(interfaceapp) << "Avatar model: " << _skeletonModelURL << "failed to load... attempts:" << _skeletonModel->getResourceDownloadAttempts(); + } } } diff --git a/libraries/avatars/src/AvatarData.cpp b/libraries/avatars/src/AvatarData.cpp index 9802630cf5..278ce53472 100644 --- a/libraries/avatars/src/AvatarData.cpp +++ b/libraries/avatars/src/AvatarData.cpp @@ -1468,6 +1468,7 @@ QUrl AvatarData::cannonicalSkeletonModelURL(const QUrl& emptyURL) const { void AvatarData::processAvatarIdentity(const Identity& identity, bool& identityChanged, bool& displayNameChanged) { if (_firstSkeletonCheck || (identity.skeletonModelURL != cannonicalSkeletonModelURL(emptyURL))) { + qDebug() << __FUNCTION__ << "about to call setSkeletonModelURL(identity.skeletonModelURL);... identity.skeletonModelURL:" << identity.skeletonModelURL; setSkeletonModelURL(identity.skeletonModelURL); identityChanged = true; if (_firstSkeletonCheck) { @@ -1514,6 +1515,10 @@ QByteArray AvatarData::identityByteArray() const { } void AvatarData::setSkeletonModelURL(const QUrl& skeletonModelURL) { + if (skeletonModelURL.isEmpty()) { + qDebug() << __FUNCTION__ << "caller called with empty URL."; + } + const QUrl& expanded = skeletonModelURL.isEmpty() ? AvatarData::defaultFullAvatarModelUrl() : skeletonModelURL; if (expanded == _skeletonModelURL) { return; diff --git a/libraries/avatars/src/AvatarHashMap.cpp b/libraries/avatars/src/AvatarHashMap.cpp index 0d341c684e..46a3a67976 100644 --- a/libraries/avatars/src/AvatarHashMap.cpp +++ b/libraries/avatars/src/AvatarHashMap.cpp @@ -126,6 +126,10 @@ AvatarSharedPointer AvatarHashMap::parseAvatarData(QSharedPointer message, SharedNodePointer sendingNode) { + qDebug() << __FUNCTION__ << "sendingNode:" << sendingNode << "message.failed():" << message->failed() + << "isComplete:" << message->isComplete() + << "messageNumber:" << message->getMessageNumber(); + AvatarData::Identity identity; AvatarData::parseAvatarIdentityPacket(message->getMessage(), identity); diff --git a/libraries/model-networking/src/model-networking/ModelCache.h b/libraries/model-networking/src/model-networking/ModelCache.h index 967897477d..67d57eab19 100644 --- a/libraries/model-networking/src/model-networking/ModelCache.h +++ b/libraries/model-networking/src/model-networking/ModelCache.h @@ -112,6 +112,7 @@ public: void setResource(GeometryResource::Pointer resource); QUrl getURL() const { return (bool)_resource ? _resource->getURL() : QUrl(); } + int getResourceDownloadAttempts() { return _resource ? _resource->getDownloadAttempts() : 0; } private: void startWatching(); diff --git a/libraries/networking/src/HTTPResourceRequest.cpp b/libraries/networking/src/HTTPResourceRequest.cpp index 85da5de5b8..e43545f38e 100644 --- a/libraries/networking/src/HTTPResourceRequest.cpp +++ b/libraries/networking/src/HTTPResourceRequest.cpp @@ -75,10 +75,19 @@ void HTTPResourceRequest::onRequestFinished() { switch(_reply->error()) { case QNetworkReply::NoError: - _data = _reply->readAll(); - _loadedFromCache = _reply->attribute(QNetworkRequest::SourceIsFromCacheAttribute).toBool(); - _result = Success; - break; + { + // For debugging, have a random chance of treating this like a failure + bool randFailure = false; // _url.toString().contains(".fst") ? (rand() % 100) > 10 : false; + + if (!randFailure) { + _data = _reply->readAll(); + _loadedFromCache = _reply->attribute(QNetworkRequest::SourceIsFromCacheAttribute).toBool(); + _result = Success; + break; + } + // else fall through to timeout + qDebug() << "**** Randomly pretending to timeout instead of successfully download HTTP resource:" << _url << " ******************************"; + } case QNetworkReply::TimeoutError: _result = Timeout; diff --git a/libraries/networking/src/ReceivedMessage.cpp b/libraries/networking/src/ReceivedMessage.cpp index 02cb58fb2d..5c8239f227 100644 --- a/libraries/networking/src/ReceivedMessage.cpp +++ b/libraries/networking/src/ReceivedMessage.cpp @@ -27,7 +27,8 @@ ReceivedMessage::ReceivedMessage(const NLPacketList& packetList) _packetType(packetList.getType()), _packetVersion(packetList.getVersion()), _senderSockAddr(packetList.getSenderSockAddr()), - _isComplete(true) + _isComplete(true), + _messageNumber(packetList.getMessageNumber()) { } @@ -39,7 +40,8 @@ ReceivedMessage::ReceivedMessage(NLPacket& packet) _packetType(packet.getType()), _packetVersion(packet.getVersion()), _senderSockAddr(packet.getSenderSockAddr()), - _isComplete(packet.getPacketPosition() == NLPacket::ONLY) + _isComplete(packet.getPacketPosition() == NLPacket::ONLY), + _messageNumber(packet.getMessageNumber()) { } diff --git a/libraries/networking/src/ReceivedMessage.h b/libraries/networking/src/ReceivedMessage.h index 3acb7163e7..d154794719 100644 --- a/libraries/networking/src/ReceivedMessage.h +++ b/libraries/networking/src/ReceivedMessage.h @@ -50,6 +50,8 @@ public: qint64 getBytesLeftToRead() const { return _data.size() - _position; } + qint64 getMessageNumber() const { return _messageNumber; } + void seek(qint64 position) { _position = position; } qint64 peek(char* data, qint64 size); @@ -98,6 +100,9 @@ private: std::atomic _isComplete { true }; std::atomic _failed { false }; + + udt::Packet::MessageNumber _messageNumber { 0 }; + }; Q_DECLARE_METATYPE(ReceivedMessage*) diff --git a/libraries/networking/src/ResourceCache.cpp b/libraries/networking/src/ResourceCache.cpp index 4031ff8bf7..ed0d5fd20b 100644 --- a/libraries/networking/src/ResourceCache.cpp +++ b/libraries/networking/src/ResourceCache.cpp @@ -724,10 +724,11 @@ void Resource::handleReplyFinished() { } else { switch (result) { case ResourceRequest::Result::Timeout: { - qCDebug(networking) << "Timed out loading" << _url << "received" << _bytesReceived << "total" << _bytesTotal; + qCDebug(networking) << "Timed out loading" << _url << "received" << _bytesReceived << "total" << _bytesTotal << "attempt:" << _attempts << "of" << MAX_ATTEMPTS; // Fall through to other cases } case ResourceRequest::Result::ServerUnavailable: { + qCDebug(networking) << "Server Unavailable loading" << _url << "attempt:" << _attempts << "of" << MAX_ATTEMPTS; // retry with increasing delays const int BASE_DELAY_MS = 1000; if (_attempts++ < MAX_ATTEMPTS) { @@ -742,7 +743,7 @@ void Resource::handleReplyFinished() { // fall through to final failure } default: { - qCDebug(networking) << "Error loading " << _url; + qCDebug(networking) << "Error loading " << _url << "attempt:" << _attempts << "of" << MAX_ATTEMPTS; auto error = (result == ResourceRequest::Timeout) ? QNetworkReply::TimeoutError : QNetworkReply::UnknownNetworkError; emit failed(error); diff --git a/libraries/networking/src/ResourceCache.h b/libraries/networking/src/ResourceCache.h index 53ccd2c386..df21a296a6 100644 --- a/libraries/networking/src/ResourceCache.h +++ b/libraries/networking/src/ResourceCache.h @@ -395,6 +395,9 @@ public: const QUrl& getURL() const { return _url; } + int getDownloadAttempts() { return _attempts; } + + signals: /// Fired when the resource begins downloading. void loading(); diff --git a/libraries/networking/src/udt/PacketList.h b/libraries/networking/src/udt/PacketList.h index 5083d77ec9..09857c795e 100644 --- a/libraries/networking/src/udt/PacketList.h +++ b/libraries/networking/src/udt/PacketList.h @@ -43,6 +43,8 @@ public: size_t getDataSize() const; size_t getMessageSize() const; QByteArray getMessage() const; + udt::Packet::MessageNumber getMessageNumber() const { return _messageNumber; } + QByteArray getExtendedHeader() const { return _extendedHeader; } diff --git a/libraries/render-utils/src/Model.h b/libraries/render-utils/src/Model.h index 62e045a3c1..3e67f2a296 100644 --- a/libraries/render-utils/src/Model.h +++ b/libraries/render-utils/src/Model.h @@ -252,6 +252,7 @@ public: void renderDebugMeshBoxes(gpu::Batch& batch); + int getResourceDownloadAttempts() { return _renderWatcher.getResourceDownloadAttempts(); } public slots: void loadURLFinished(bool success);