Add more logs to track file hydration.
authorCamila Ayres <hello@camilasan.com>
Wed, 12 Jun 2024 13:32:01 +0000 (15:32 +0200)
committerbackportbot[bot] <backportbot[bot]@users.noreply.github.com>
Fri, 28 Jun 2024 07:45:49 +0000 (07:45 +0000)
Signed-off-by: Camila Ayres <hello@camilasan.com>
src/libsync/propagatedownload.cpp
src/libsync/vfs/cfapi/cfapiwrapper.cpp

index 1faf04410a2d7a3e54a13b77f4eef2fd51ce0936..7b2bd987c62226289390cb17ba3cc98f07f0687d 100644 (file)
@@ -329,7 +329,7 @@ void GETFileJob::slotReadyRead()
     }
 
     if (reply()->isFinished() && (reply()->bytesAvailable() == 0 || !_saveBodyToFile)) {
-        qCDebug(lcGetJob) << "Actually finished!";
+        qCDebug(lcGetJob) << "Get file job finished bytesAvailable/_saveBodyToFile:" << reply()->bytesAvailable() << "/" << _saveBodyToFile ;
         if (_bandwidthManager) {
             _bandwidthManager->unregisterDownloadJob(this);
         }
index 8b168879569441538f46d06c82203ccddedfd174..57707af4cf1e51c06ff7593d5854bdd3521a2f27 100644 (file)
@@ -133,6 +133,9 @@ void cfApiSendTransferInfo(const CF_CONNECTION_KEY &connectionKey, const CF_TRAN
 void CALLBACK cfApiFetchDataCallback(const CF_CALLBACK_INFO *callbackInfo, const CF_CALLBACK_PARAMETERS *callbackParameters)
 {
     qDebug(lcCfApiWrapper) << "Fetch data callback called. File size:" << callbackInfo->FileSize.QuadPart;
+    qDebug(lcCfApiWrapper) << "Fetch data requested by proccess id:" << callbackInfo->ProcessInfo->ProcessId;
+    qDebug(lcCfApiWrapper) << "Fetch data requested by application id:" << QString(QString::fromWCharArray(callbackInfo->ProcessInfo->ApplicationId));
+
     const auto sendTransferError = [=] {
         cfApiSendTransferInfo(callbackInfo->ConnectionKey,
                               callbackInfo->TransferKey,
@@ -158,6 +161,8 @@ void CALLBACK cfApiFetchDataCallback(const CF_CALLBACK_INFO *callbackInfo, const
     const auto path = QString(QString::fromWCharArray(callbackInfo->VolumeDosName) + QString::fromWCharArray(callbackInfo->NormalizedPath));
     const auto requestId = QString::number(callbackInfo->TransferKey.QuadPart, 16);
 
+    qCDebug(lcCfApiWrapper) << "Request hydration for" << path << requestId;
+
     const auto invokeResult = QMetaObject::invokeMethod(vfs, [=] { vfs->requestHydration(requestId, path); }, Qt::QueuedConnection);
     if (!invokeResult) {
         qCCritical(lcCfApiWrapper) << "Failed to trigger hydration for" << path << requestId;
@@ -165,26 +170,33 @@ void CALLBACK cfApiFetchDataCallback(const CF_CALLBACK_INFO *callbackInfo, const
         return;
     }
 
+    qCDebug(lcCfApiWrapper) << "Successfully triggered hydration for" << path << requestId;
+
     // Block and wait for vfs to signal back the hydration is ready
     bool hydrationRequestResult = false;
     QEventLoop loop;
     QObject::connect(vfs, &OCC::VfsCfApi::hydrationRequestReady, &loop, [&](const QString &id) {
         if (requestId == id) {
             hydrationRequestResult = true;
+            qCDebug(lcCfApiWrapper) << "Hydration request ready for" << path << requestId;
             loop.quit();
         }
     });
     QObject::connect(vfs, &OCC::VfsCfApi::hydrationRequestFailed, &loop, [&](const QString &id) {
         if (requestId == id) {
             hydrationRequestResult = false;
+            qCDebug(lcCfApiWrapper) << "Hydration request failed for" << path << requestId;
             loop.quit();
         }
     });
+
+    qCDebug(lcCfApiWrapper) << "Starting event loop 1";
     loop.exec();
-    QObject::disconnect(vfs, nullptr, &loop, nullptr);
-    qCInfo(lcCfApiWrapper) << "VFS replied for hydration of" << path << requestId << "status was:" << hydrationRequestResult;
+    QObject::disconnect(vfs, nullptr, &loop, nullptr); // Ensure we properly cancel hydration on server errors
 
+    qCInfo(lcCfApiWrapper) << "VFS replied for hydration of" << path << requestId << "status was:" << hydrationRequestResult;
     if (!hydrationRequestResult) {
+        qCCritical(lcCfApiWrapper) << "Failed to trigger hydration for" << path << requestId;
         sendTransferError();
         return;
     }
@@ -212,6 +224,7 @@ void CALLBACK cfApiFetchDataCallback(const CF_CALLBACK_INFO *callbackInfo, const
     auto hydrationRequestCancelled = false;
     QObject::connect(&signalSocket, &QLocalSocket::readyRead, &loop, [&] {
         hydrationRequestCancelled = true;
+        qCCritical(lcCfApiWrapper) << "Hydration canceled for " << path << requestId;
     });
 
     // CFAPI expects sent blocks to be of a multiple of a block size.
@@ -223,17 +236,25 @@ void CALLBACK cfApiFetchDataCallback(const CF_CALLBACK_INFO *callbackInfo, const
 
     const auto alignAndSendData = [&](const QByteArray &receivedData) {
         QByteArray data = protrudingData + receivedData;
+        qCWarning(lcCfApiWrapper) << "protrudingData + receivedData:" << data;
         protrudingData.clear();
         if (data.size() < cfapiBlockSize) {
             protrudingData = data;
+            qCWarning(lcCfApiWrapper) << "protrudingData:" << protrudingData;
+            sendTransferInfo(data, dataOffset);
+            dataOffset += data.size();
             return;
         }
         const auto protudingSize = data.size() % cfapiBlockSize;
+        qCWarning(lcCfApiWrapper) << "protudingSize:" << protudingSize;
         protrudingData = data.right(protudingSize);
+        qCWarning(lcCfApiWrapper) << "data.right(protudingSize):" << protrudingData;
         data.chop(protudingSize);
-
+        qCWarning(lcCfApiWrapper) << "data.chop(protudingSize)" << data;
+        qCWarning(lcCfApiWrapper) << "sendTransferInfo(data:" << data << ", dataOffset:" << dataOffset << ")";
         sendTransferInfo(data, dataOffset);
         dataOffset += data.size();
+        qCWarning(lcCfApiWrapper) << "dataOffset:" << dataOffset;
     };
 
     QObject::connect(&socket, &QLocalSocket::readyRead, &loop, [&] {
@@ -260,6 +281,7 @@ void CALLBACK cfApiFetchDataCallback(const CF_CALLBACK_INFO *callbackInfo, const
         }
     });
 
+    qCDebug(lcCfApiWrapper) << "Starting event loop 2";
     loop.exec();
 
     if (!hydrationRequestCancelled && !protrudingData.isEmpty()) {