Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[stable-3.12] Add cfapi debug logs #6851

Merged
merged 3 commits into from
Jun 28, 2024
Merged

[stable-3.12] Add cfapi debug logs #6851

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
4c48f4f
Add more logs to track file hydration.
camilasan Jun 12, 2024
e69dfe5
Add new cfapi callbacks for logging.
camilasan Jun 13, 2024
f926f5b
Print desktop client process id.
camilasan Jun 19, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion src/libsync/propagatedownload.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
/*

Check notice on line 1 in src/libsync/propagatedownload.cpp

View workflow job for this annotation

GitHub Actions / build

Run clang-format on src/libsync/propagatedownload.cpp 

File src/libsync/propagatedownload.cpp does not conform to Custom style guidelines. (lines 335)
* Copyright (C) by Olivier Goffart <ogoffart@owncloud.com>
*
* This program is free software; you can redistribute it and/or modify
Expand Down Expand Up @@ -332,7 +332,7 @@
}

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);
}
Expand Down
77 changes: 74 additions & 3 deletions src/libsync/vfs/cfapi/cfapiwrapper.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
/*

Check notice on line 1 in src/libsync/vfs/cfapi/cfapiwrapper.cpp

View workflow job for this annotation

GitHub Actions / build

Run clang-format on src/libsync/vfs/cfapi/cfapiwrapper.cpp 

File src/libsync/vfs/cfapi/cfapiwrapper.cpp does not conform to Custom style guidelines. (lines 424, 425, 426, 427)
* Copyright (C) by Kevin Ottens <kevin.ottens@nextcloud.com>
*
* This program is free software; you can redistribute it and/or modify
Expand Down Expand Up @@ -133,6 +133,10 @@
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) << "Desktop client proccess id:" << QCoreApplication::applicationPid();
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,
Expand All @@ -158,33 +162,42 @@
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;
sendTransferError();
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;
}
Expand Down Expand Up @@ -212,6 +225,7 @@
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.
Expand All @@ -223,17 +237,25 @@

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, [&] {
Expand All @@ -260,6 +282,7 @@
}
});

qCDebug(lcCfApiWrapper) << "Starting event loop 2";
loop.exec();

if (!hydrationRequestCancelled && !protrudingData.isEmpty()) {
Expand Down Expand Up @@ -351,9 +374,57 @@
}
}

void CALLBACK cfApiNotifyFileOpenCompletion(const CF_CALLBACK_INFO *callbackInfo, const CF_CALLBACK_PARAMETERS * /*callbackParameters*/)
{
const auto path = QString(QString::fromWCharArray(callbackInfo->VolumeDosName) + QString::fromWCharArray(callbackInfo->NormalizedPath));

auto vfs = reinterpret_cast<OCC::VfsCfApi *>(callbackInfo->CallbackContext);
Q_ASSERT(vfs->metaObject()->className() == QByteArrayLiteral("OCC::VfsCfApi"));
const auto requestId = QString::number(callbackInfo->TransferKey.QuadPart, 16);

qCDebug(lcCfApiWrapper) << "Open file completion:" << path << requestId;
}

void CALLBACK cfApiValidateData(const CF_CALLBACK_INFO *callbackInfo, const CF_CALLBACK_PARAMETERS * /*callbackParameters*/)
{
const auto path = QString(QString::fromWCharArray(callbackInfo->VolumeDosName) + QString::fromWCharArray(callbackInfo->NormalizedPath));

auto vfs = reinterpret_cast<OCC::VfsCfApi *>(callbackInfo->CallbackContext);
Q_ASSERT(vfs->metaObject()->className() == QByteArrayLiteral("OCC::VfsCfApi"));
const auto requestId = QString::number(callbackInfo->TransferKey.QuadPart, 16);

qCDebug(lcCfApiWrapper) << "Validate data:" << path << requestId;
}

void CALLBACK cfApiCancelFetchPlaceHolders(const CF_CALLBACK_INFO *callbackInfo, const CF_CALLBACK_PARAMETERS * /*callbackParameters*/)
{
const auto path = QString(QString::fromWCharArray(callbackInfo->VolumeDosName) + QString::fromWCharArray(callbackInfo->NormalizedPath));

auto vfs = reinterpret_cast<OCC::VfsCfApi *>(callbackInfo->CallbackContext);
Q_ASSERT(vfs->metaObject()->className() == QByteArrayLiteral("OCC::VfsCfApi"));
const auto requestId = QString::number(callbackInfo->TransferKey.QuadPart, 16);

qCDebug(lcCfApiWrapper) << "Cancel fetch placeholder:" << path << requestId;
}

void CALLBACK cfApiNotifyFileCloseCompletion(const CF_CALLBACK_INFO *callbackInfo, const CF_CALLBACK_PARAMETERS * /*callbackParameters*/)
{
const auto path = QString(QString::fromWCharArray(callbackInfo->VolumeDosName) + QString::fromWCharArray(callbackInfo->NormalizedPath));

auto vfs = reinterpret_cast<OCC::VfsCfApi *>(callbackInfo->CallbackContext);
Q_ASSERT(vfs->metaObject()->className() == QByteArrayLiteral("OCC::VfsCfApi"));
const auto requestId = QString::number(callbackInfo->TransferKey.QuadPart, 16);

qCDebug(lcCfApiWrapper) << "Close file completion:" << path << requestId;
}

CF_CALLBACK_REGISTRATION cfApiCallbacks[] = {
{ CF_CALLBACK_TYPE_FETCH_DATA, cfApiFetchDataCallback },
{ CF_CALLBACK_TYPE_CANCEL_FETCH_DATA, cfApiCancelFetchData },
{ CF_CALLBACK_TYPE_NOTIFY_FILE_OPEN_COMPLETION, cfApiNotifyFileOpenCompletion },
{ CF_CALLBACK_TYPE_NOTIFY_FILE_CLOSE_COMPLETION, cfApiNotifyFileCloseCompletion },
{ CF_CALLBACK_TYPE_VALIDATE_DATA, cfApiValidateData },
{ CF_CALLBACK_TYPE_CANCEL_FETCH_PLACEHOLDERS, cfApiCancelFetchPlaceHolders },
CF_CALLBACK_REGISTRATION_END
};

Expand Down
Loading