Move Ktx processing to thread pool.

libraries/gpu/src/gpu/Texture_ktx.cpp

@@ -15,6 +15,7 @@
 #include <QtCore/QByteArray>
 
 #include <ktx/KTX.h>
+#include <Profile.h>
 
 #include "GPULogging.h"
 
@@ -242,6 +243,7 @@ uint16 KtxStorage::minAvailableMipLevel() const {
 }
 
 void KtxStorage::assignMipData(uint16 level, const storage::StoragePointer& storage) {
+    PROFILE_RANGE(app, __FUNCTION__)
     if (level != _minMipLevelAvailable - 1) {
         qWarning() << "Invalid level to be stored, expected: " << (_minMipLevelAvailable - 1) << ", got: " << level << " " << _filename.c_str();
         return;
@@ -283,6 +285,7 @@ void KtxStorage::assignMipData(uint16 level, const storage::StoragePointer& stor
         }
 
         memcpy(imageData, storage->data(), storage->size());
+        
         _minMipLevelAvailable = level;
         if (_offsetToMinMipKV > 0) {
             auto minMipKeyData = fileData + ktx::KTX_HEADER_SIZE + _offsetToMinMipKV;
@@ -311,6 +314,7 @@ void Texture::setKtxBacking(const std::string& filename) {
 
 
 ktx::KTXUniquePointer Texture::serialize(const Texture& texture) {
+    PROFILE_RANGE(app, __FUNCTION__)
     ktx::Header header;
 
     // From texture format to ktx format description
@@ -453,6 +457,7 @@ TexturePointer Texture::unserialize(const std::string& ktxfile) {
 }
 
 TexturePointer Texture::unserialize(const std::string& ktxfile, const ktx::KTXDescriptor& descriptor) {
+    PROFILE_RANGE(app, __FUNCTION__)
     const auto& header = descriptor.header;
 
     Format mipFormat = Format::COLOR_BGRA_32;

libraries/model-networking/src/model-networking/TextureCache.cpp

@@ -300,16 +300,23 @@ void NetworkTexture::setImage(gpu::TexturePointer texture, int originalWidth,
     _textureSource->resetTexture(texture);
 
     if (texture) {
+        if (_sourceIsKTX) {
+            _ktxResourceState = WAITING_FOR_MIP_REQUEST;
+        }
+
         _width = texture->getWidth();
         _height = texture->getHeight();
         setSize(texture->getStoredSize());
+        finishedLoading(true);
     } else {
         // FIXME: If !gpuTexture, we failed to load!
-        _width = _height = 0;
+        if (_sourceIsKTX) {
-        qWarning() << "Texture did not load";
+            _ktxResourceState = FAILED_TO_LOAD;
-    }
+        }
 
-    finishedLoading(true);
+        _width = _height = 0;
+        finishedLoading(false);
+    }
 
     emit networkTextureCreated(qWeakPointerCast<NetworkTexture, Resource> (_self));
 }
@@ -407,6 +414,7 @@ void NetworkTexture::makeRequest() {
 }
 
 void NetworkTexture::startRequestForNextMipLevel() {
+    PROFILE_RANGE(app, __FUNCTION__);
     if (_lowestKnownPopulatedMip == 0) {
         qWarning(networking) << "Requesting next mip level but all have been fulfilled: " << _lowestKnownPopulatedMip
             << " " << _textureSource->getGPUTexture()->minAvailableMipLevel() << " " << _url;
@@ -434,6 +442,7 @@ void NetworkTexture::startMipRangeRequest(uint16_t low, uint16_t high) {
     if (_ktxMipRequest) {
         return;
     }
+    PROFILE_RANGE(app, __FUNCTION__);
 
     bool isHighMipRequest = low == NULL_MIP_LEVEL && high == NULL_MIP_LEVEL;
 
@@ -470,41 +479,101 @@ void NetworkTexture::startMipRangeRequest(uint16_t low, uint16_t high) {
 
 
 void NetworkTexture::ktxHeaderRequestFinished() {
+    PROFILE_RANGE(app, __FUNCTION__);
+
+    Q_ASSERT_X(_ktxHeaderRequest, "Resource::handleReplyFinished", "Request should not be null while in handleReplyFinished");
     Q_ASSERT(_ktxResourceState == LOADING_INITIAL_DATA);
 
-    if (!_ktxHeaderRequest) {
+    PROFILE_ASYNC_END(resource, "Resource:" + getType(), QString::number(_requestID), {
+        { "from_cache", _ktxHeaderRequest->loadedFromCache() },
+        { "size_mb", _bytesTotal / 1000000.0 }
+    });
+
+    setSize(_bytesTotal);
+
+    if (!_ktxHeaderRequest || _ktxHeaderRequest != sender()) {
+        // This can happen in the edge case that a request is timed out, but a `finished` signal is emitted before it is deleted.
+        qWarning(networking) << "Received signal NetworkTexture::ktxHeaderRequestFinished from ResourceRequest that is not the current"
+            << " request: " << sender() << ", " << _ktxHeaderRequest;
         return;
     }
 
-    _ktxHeaderRequestFinished = true;
+    ResourceCache::requestCompleted(_self);
-    maybeHandleFinishedInitialLoad();
+
+    auto result = _ktxHeaderRequest->getResult();
+    if (result == ResourceRequest::Success) {
+        auto extraInfo = _url == _activeUrl ? "" : QString(", %1").arg(_activeUrl.toDisplayString());
+        qCDebug(networking).noquote() << QString("Request finished for %1%2").arg(_url.toDisplayString(), extraInfo);
+
+        auto data = _ktxHeaderRequest->getData();
+
+        //emit loaded(data);
+        //downloadFinished(data);
+        _ktxHeaderRequestFinished = true;
+        maybeHandleFinishedInitialLoad();
+
+    } else {
+        handleFailedRequest(result);
+    }
+
+    _ktxHeaderRequest->disconnect(this);
+    _ktxHeaderRequest->deleteLater();
+    _ktxHeaderRequest = nullptr;
 }
 
 void NetworkTexture::ktxMipRequestFinished() {
+    PROFILE_RANGE(app, __FUNCTION__);
+
+    Q_ASSERT_X(_ktxMipRequest, "Resource::handleReplyFinished", "Request should not be null while in handleReplyFinished");
     Q_ASSERT(_ktxResourceState == LOADING_INITIAL_DATA || _ktxResourceState == REQUESTING_MIP);
 
-    if (!_ktxMipRequest) {
+    PROFILE_ASYNC_END(resource, "Resource:" + getType(), QString::number(_requestID), {
+        { "from_cache", _ktxMipRequest->loadedFromCache() },
+        { "size_mb", _bytesTotal / 1000000.0 }
+    });
+
+    setSize(_bytesTotal);
+
+    if (!_ktxMipRequest || _ktxMipRequest != sender()) {
+        // This can happen in the edge case that a request is timed out, but a `finished` signal is emitted before it is deleted.
+        qWarning(networking) << "Received signal NetworkTexture::ktxHeaderRequestFinished from ResourceRequest that is not the current"
+            << " request: " << sender() << ", " << _ktxMipRequest;
         return;
     }
 
-    if (_ktxResourceState == LOADING_INITIAL_DATA) {
+    ResourceCache::requestCompleted(_self);
-        _ktxHighMipRequestFinished = true;
-        maybeHandleFinishedInitialLoad();
-    } else if (_ktxResourceState == REQUESTING_MIP) {
-        Q_ASSERT(_ktxMipLevelRangeInFlight.first != NULL_MIP_LEVEL);
-        TextureCache::requestCompleted(_self);
 
-        if (_ktxMipRequest->getResult() == ResourceRequest::Success) {
+    auto result = _ktxMipRequest->getResult();
+    if (result == ResourceRequest::Success) {
+        auto extraInfo = _url == _activeUrl ? "" : QString(", %1").arg(_activeUrl.toDisplayString());
+        qCDebug(networking).noquote() << QString("Request finished for %1%2").arg(_url.toDisplayString(), extraInfo);
+
+        auto data = _ktxMipRequest->getData();
+
+        //emit loaded(data);
+        //downloadFinished(data);
+
+        if (_ktxResourceState == LOADING_INITIAL_DATA) {
+            _ktxHighMipRequestFinished = true;
+            
+            ////
+            maybeHandleFinishedInitialLoad();
+        } else if (_ktxResourceState == REQUESTING_MIP) {
+            Q_ASSERT(_ktxMipLevelRangeInFlight.first != NULL_MIP_LEVEL);
             Q_ASSERT(_ktxMipLevelRangeInFlight.second - _ktxMipLevelRangeInFlight.first == 0);
+            _lowestKnownPopulatedMip = _ktxMipLevelRangeInFlight.first;
+            _ktxResourceState = WAITING_FOR_MIP_REQUEST;
 
+            if (_ktxResourceState == WAITING_FOR_MIP_REQUEST && _lowestRequestedMipLevel < _lowestKnownPopulatedMip) {
+                startRequestForNextMipLevel();
+            }
+
+            ////
             auto texture = _textureSource->getGPUTexture();
             if (texture) {
-                texture->assignStoredMip(_ktxMipLevelRangeInFlight.first,
+                    texture->assignStoredMip(_ktxMipLevelRangeInFlight.first,
-                    _ktxMipRequest->getData().size(), reinterpret_cast<uint8_t*>(_ktxMipRequest->getData().data()));
+                        _ktxMipRequest->getData().size(), reinterpret_cast<uint8_t*>(_ktxMipRequest->getData().data()));
-
                 if (texture->minAvailableMipLevel() <= _ktxMipLevelRangeInFlight.first) {
-                    _lowestKnownPopulatedMip = texture->minAvailableMipLevel();
-                    _ktxResourceState = WAITING_FOR_MIP_REQUEST;
                 } else {
                     qWarning(networking) << "Failed to load mip: " << _url << ":" << _ktxMipLevelRangeInFlight.first;
                     _ktxResourceState = FAILED_TO_LOAD;
@@ -514,29 +583,29 @@ void NetworkTexture::ktxMipRequestFinished() {
                 qWarning(networking) << "Trying to update mips but texture is null";
             }
             finishedLoading(true);
+
         } else {
-            finishedLoading(false);
+            qWarning() << "Mip request finished in an unexpected state: " << _ktxResourceState;
-            if (handleFailedRequest(_ktxMipRequest->getResult())) {
-                _ktxResourceState = PENDING_MIP_REQUEST;
-            } else {
-                qWarning(networking) << "Failed to load mip: " << _url;
-                _ktxResourceState = FAILED_TO_LOAD;
-            }
         }
 
-        _ktxMipRequest->deleteLater();
-        _ktxMipRequest = nullptr;
 
-        if (_ktxResourceState == WAITING_FOR_MIP_REQUEST && _lowestRequestedMipLevel < _lowestKnownPopulatedMip) {
-            startRequestForNextMipLevel();
-        }
     } else {
-        qWarning() << "Mip request finished in an unexpected state: " << _ktxResourceState;
+        if (handleFailedRequest(result)) {
+            _ktxResourceState = PENDING_MIP_REQUEST;
+        } else {
+            _ktxResourceState = FAILED_TO_LOAD;
+        }
     }
+
+    _ktxMipRequest->disconnect(this);
+    _ktxMipRequest->deleteLater();
+    _ktxMipRequest = nullptr;
 }
 
 // This is called when the header or top mips have been loaded
 void NetworkTexture::maybeHandleFinishedInitialLoad() {
+    PROFILE_RANGE(app, __FUNCTION__);
+
     Q_ASSERT(_ktxResourceState == LOADING_INITIAL_DATA);
 
     if (_ktxHeaderRequestFinished && _ktxHighMipRequestFinished) {
@@ -546,15 +615,9 @@ void NetworkTexture::maybeHandleFinishedInitialLoad() {
         if (_ktxHeaderRequest->getResult() != ResourceRequest::Success || _ktxMipRequest->getResult() != ResourceRequest::Success) {
             if (handleFailedRequest(_ktxMipRequest->getResult())) {
                 _ktxResourceState = PENDING_INITIAL_LOAD;
-            }
+            } else {
-            else {
                 _ktxResourceState = FAILED_TO_LOAD;
             }
-
-            _ktxHeaderRequest->deleteLater();
-            _ktxHeaderRequest = nullptr;
-            _ktxMipRequest->deleteLater();
-            _ktxMipRequest = nullptr;
         } else {
             // create ktx...
             auto ktxHeaderData = _ktxHeaderRequest->getData();
@@ -564,16 +627,20 @@ void NetworkTexture::maybeHandleFinishedInitialLoad() {
 
             if (!ktx::checkIdentifier(header->identifier)) {
                 qWarning() << "Cannot load " << _url << ", invalid header identifier";
-                _ktxResourceState = FAILED_TO_LOAD;
+                QMetaObject::invokeMethod(resource.data(), "setImage",
-                finishedLoading(false);
+                    Q_ARG(gpu::TexturePointer, nullptr),
+                    Q_ARG(int, 0),
+                    Q_ARG(int, 0));
                 return;
             }
 
             auto kvSize = header->bytesOfKeyValueData;
             if (kvSize > (ktxHeaderData.size() - ktx::KTX_HEADER_SIZE)) {
                 qWarning() << "Cannot load " << _url << ", did not receive all kv data with initial request";
-                _ktxResourceState = FAILED_TO_LOAD;
+                QMetaObject::invokeMethod(resource.data(), "setImage",
-                finishedLoading(false);
+                    Q_ARG(gpu::TexturePointer, nullptr),
+                    Q_ARG(int, 0),
+                    Q_ARG(int, 0));
                 return;
             }
 
@@ -582,8 +649,11 @@ void NetworkTexture::maybeHandleFinishedInitialLoad() {
             auto imageDescriptors = header->generateImageDescriptors();
             if (imageDescriptors.size() == 0) {
                 qWarning(networking) << "Failed to process ktx file " << _url;
-                _ktxResourceState = FAILED_TO_LOAD;
+                QMetaObject::invokeMethod(resource.data(), "setImage",
-                finishedLoading(false);
+                    Q_ARG(gpu::TexturePointer, nullptr),
+                    Q_ARG(int, 0),
+                    Q_ARG(int, 0));
+                return;
             }
             _originalKtxDescriptor.reset(new ktx::KTXDescriptor(*header, keyValues, imageDescriptors));
 
@@ -595,8 +665,10 @@ void NetworkTexture::maybeHandleFinishedInitialLoad() {
             std::string hash;
             if (found == keyValues.end() || found->_value.size() != gpu::SOURCE_HASH_BYTES) {
                 qWarning("Invalid source hash key found, bailing");
-                _ktxResourceState = FAILED_TO_LOAD;
+                QMetaObject::invokeMethod(resource.data(), "setImage",
-                finishedLoading(false);
+                    Q_ARG(gpu::TexturePointer, nullptr),
+                    Q_ARG(int, 0),
+                    Q_ARG(int, 0));
                 return;
             } else {
                 // at this point the source hash is in binary 16-byte form
@@ -624,7 +696,10 @@ void NetworkTexture::maybeHandleFinishedInitialLoad() {
                 auto memKtx = ktx::KTX::createBare(*header, keyValues);
                 if (!memKtx) {
                     qWarning() << " Ktx could not be created, bailing";
-                    finishedLoading(false);
+                    QMetaObject::invokeMethod(resource.data(), "setImage",
+                        Q_ARG(gpu::TexturePointer, nullptr),
+                        Q_ARG(int, 0),
+                        Q_ARG(int, 0));
                     return;
                 }
 
@@ -635,8 +710,10 @@ void NetworkTexture::maybeHandleFinishedInitialLoad() {
                 auto& ktxCache = textureCache->_ktxCache;
                 if (!memKtx || !(file = ktxCache.writeFile(data, KTXCache::Metadata(filename, length)))) {
                     qCWarning(modelnetworking) << _url << " failed to write cache file";
-                    _ktxResourceState = FAILED_TO_LOAD;
+                    QMetaObject::invokeMethod(resource.data(), "setImage",
-                    finishedLoading(false);
+                        Q_ARG(gpu::TexturePointer, nullptr),
+                        Q_ARG(int, 0),
+                        Q_ARG(int, 0));
                     return;
                 } else {
                     _file = file;
@@ -672,14 +749,18 @@ void NetworkTexture::maybeHandleFinishedInitialLoad() {
 
             _lowestKnownPopulatedMip = texture->minAvailableMipLevel();
 
-            _ktxResourceState = WAITING_FOR_MIP_REQUEST;
-            setImage(texture, header->getPixelWidth(), header->getPixelHeight());
 
-            _ktxHeaderRequest->deleteLater();
+            QMetaObject::invokeMethod(resource.data(), "ktxRequestProcessed",
-            _ktxHeaderRequest = nullptr;
+                                      Q_ARG(gpu::TexturePointer, texture),
-            _ktxMipRequest->deleteLater();
+                                      Q_ARG(int, texture->getWidth()),
-            _ktxMipRequest = nullptr;
+                                      Q_ARG(int, texture->getHeight()));
         }
+
+        _ktxHeaderRequest->deleteLater();
+        _ktxHeaderRequest = nullptr;
+        _ktxMipRequest->deleteLater();
+        _ktxMipRequest = nullptr;
+
         startRequestForNextMipLevel();
     }
 }

libraries/model-networking/src/model-networking/TextureCache.h

@@ -74,7 +74,7 @@ protected:
     virtual bool isCacheable() const override { return _loaded; }
 
     virtual void downloadFinished(const QByteArray& data) override;
-
+    
     Q_INVOKABLE void loadContent(const QByteArray& content);
     Q_INVOKABLE void setImage(gpu::TexturePointer texture, int originalWidth, int originalHeight);
 

libraries/networking/src/FileCache.cpp

@@ -21,8 +21,9 @@
 #include <QtCore/QSaveFile>
 #include <QtCore/QStorageInfo>
 
-#include <PathUtils.h>
 #include <NumericalConstants.h>
+#include <PathUtils.h>
+#include <Profile.h>
 
 #ifdef Q_OS_WIN
 #include <sys/utime.h>
@@ -87,6 +88,7 @@ FileCache::~FileCache() {
 }
 
 void FileCache::initialize() {
+    PROFILE_RANGE(app, __FUNCTION__)
     QDir dir(_dirpath.c_str());
 
     if (dir.exists()) {
@@ -127,6 +129,7 @@ FilePointer FileCache::addFile(Metadata&& metadata, const std::string& filepath)
 }
 
 FilePointer FileCache::writeFile(const char* data, File::Metadata&& metadata, bool overwrite) {
+    PROFILE_RANGE(app, __FUNCTION__)
     assert(_initialized);
 
     std::string filepath = getFilepath(metadata.key);
@@ -319,6 +322,7 @@ File::File(Metadata&& metadata, const std::string& filepath) :
 }
 
 File::~File() {
+    PROFILE_RANGE(app, __FUNCTION__)
     QFile file(getFilepath().c_str());
     if (file.exists() && !_shouldPersist) {
         qCInfo(file_cache, "Unlinked %s", getFilepath().c_str());
@@ -327,6 +331,7 @@ File::~File() {
 }
 
 void File::touch() {
+    PROFILE_RANGE(app, __FUNCTION__)
     utime(_filepath.c_str(), nullptr);
     _modified = std::max<int64_t>(QFileInfo(_filepath.c_str()).lastRead().toMSecsSinceEpoch(), _modified);
 }

libraries/shared/src/shared/Storage.cpp

@@ -12,6 +12,8 @@
 #include <QtCore/QDebug>
 #include <QtCore/QLoggingCategory>
 
+#include "../Profile.h"
+
 Q_LOGGING_CATEGORY(storagelogging, "hifi.core.storage")
 
 using namespace storage;
@@ -48,6 +50,7 @@ MemoryStorage::MemoryStorage(size_t size, const uint8_t* data) {
 }
 
 StoragePointer FileStorage::create(const QString& filename, size_t size, const uint8_t* data) {
+    PROFILE_RANGE(app, "FileStorage::create()");
     QFile file(filename);
     if (!file.open(QFile::ReadWrite | QIODevice::Truncate)) {
         throw std::runtime_error("Unable to open file for writing");
@@ -70,6 +73,8 @@ StoragePointer FileStorage::create(const QString& filename, size_t size, const u
 }
 
 FileStorage::FileStorage(const QString& filename) : _file(filename) {
+    PROFILE_RANGE(app, "FileStorage()");
+
     bool opened = _file.open(QFile::ReadWrite);
     if (opened) {
         _hasWriteAccess = true;
@@ -79,6 +84,7 @@ FileStorage::FileStorage(const QString& filename) : _file(filename) {
     }
 
     if (opened) {
+        PROFILE_RANGE(app, "FileStorage() map");
         _mapped = _file.map(0, _file.size());
         if (_mapped) {
             _valid = true;
@@ -91,6 +97,7 @@ FileStorage::FileStorage(const QString& filename) : _file(filename) {
 }
 
 FileStorage::~FileStorage() {
+    PROFILE_RANGE(app, "~FileStorage()");
     if (_mapped) {
         if (!_file.unmap(_mapped)) {
             throw std::runtime_error("Unable to unmap file");