Categorize file transfer and browser logs and reduce I/O noise

This commit is contained in:
evgeny committed 2026-10-18 15:08:42 +02:00
1 parent 81ee235f73
commit 74e2238b7f
3 files changed
+16 -24

No files matched your search

+3 -7
View File
@@ -112,8 +112,6 @@ static void transfer_release(struct mf_transfer* t) {
static void transfer_work(void* arg) { static void transfer_work(void* arg) {
struct mf_transfer* t = arg; struct mf_transfer* t = arg;
int rc = MF_OK; int rc = MF_OK;
DEBUG_TRACE(DEBUG_CATEGORY_DEBUG, "member_files: stream I/O id=%llu work=%d offset=%llu slots=%u",
(unsigned long long)t->request.id, t->work, (unsigned long long)t->io_offset, t->io_count);
if (t->work == TRANSFER_PREPARE) { if (t->work == TRANSFER_PREPARE) {
if (t->server) { if (t->server) {
struct mf_message q = t->open; struct mf_message q = t->open;
@@ -209,8 +207,6 @@ static void transfer_work(void* arg) {
static void transfer_done(void* arg, int error) { static void transfer_done(void* arg, int error) {
struct mf_transfer* t = arg; t->busy = 0; struct mf_transfer* t = arg; t->busy = 0;
int status = error ? MF_CANCELLED : t->work_status; int status = error ? MF_CANCELLED : t->work_status;
DEBUG_TRACE(DEBUG_CATEGORY_DEBUG, "member_files: stream I/O done id=%llu work=%d status=%s bytes=%llu buffered=%u",
(unsigned long long)t->request.id, t->work, mf_status_text(status), (unsigned long long)t->io_bytes, t->count);
if (t->work == TRANSFER_FINISH) { if (t->work == TRANSFER_FINISH) {
t->finished_io = 1; t->finished_io = 1;
if (!t->status) t->status = status; if (!t->status) t->status = status;
@@ -368,7 +364,7 @@ static void transfer_send_open(struct mf_transfer* t, uint8_t command) {
static void transfer_connected(struct CONN_MGR_HANDLE* h, uint64_t peer, uint64_t group, enum conn_mgr_event event, void* arg) { static void transfer_connected(struct CONN_MGR_HANDLE* h, uint64_t peer, uint64_t group, enum conn_mgr_event event, void* arg) {
(void)h; (void)peer; (void)group; (void)h; (void)peer; (void)group;
struct mf_transfer* t = arg; struct mf_transfer* t = arg;
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "member_files: stream CM id=%llu event=%d", (unsigned long long)t->request.id, event); DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "member_files: stream CM id=%llu event=%d", (unsigned long long)t->request.id, event);
if (event == CONN_EVENT_UP) transfer_wake(t); if (event == CONN_EVENT_UP) transfer_wake(t);
} }
@@ -451,7 +447,7 @@ void mf_transfer_dispatch(struct member_files* f, uint64_t group, uint64_t peer,
return; return;
} }
if (!t || t->stopping) { if (!t || t->stopping) {
DEBUG_TRACE(DEBUG_CATEGORY_DEBUG, "member_files: late stream packet id=%llu command=%s", DEBUG_TRACE(DEBUG_CATEGORY_MEDIA, "member_files: late stream packet id=%llu command=%s",
(unsigned long long)id, mf_command_text(q->command)); (unsigned long long)id, mf_command_text(q->command));
return; return;
} }
@@ -498,7 +494,7 @@ void mf_transfers_tick(struct member_files* f, uint64_t now) {
transfer_release(t); transfer_release(t);
} else if (!t->stopping && now - t->progress_tb >= TRANSFER_TIMEOUT_TB) transfer_stop(t, MF_TIMEOUT); } else if (!t->stopping && now - t->progress_tb >= TRANSFER_TIMEOUT_TB) transfer_stop(t, MF_TIMEOUT);
else if (!t->stopping && now - t->last_log >= 10000) { else if (!t->stopping && now - t->last_log >= 10000) {
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA,
"member_files: stream progress id=%llu server=%d sending=%d done=%llu/%llu buffered=%u io=%d wait=%s rate=%lluB/s", "member_files: stream progress id=%llu server=%d sending=%d done=%llu/%llu buffered=%u io=%d wait=%s rate=%lluB/s",
(unsigned long long)t->request.id, t->server, t->sending, (unsigned long long)t->offset, (unsigned long long)t->request.id, t->server, t->sending, (unsigned long long)t->offset,
(unsigned long long)t->size, t->count, t->busy, t->waiter.internal ? "router" : t->busy ? "disk" : "peer", (unsigned long long)t->size, t->count, t->busy, t->waiter.internal ? "router" : t->busy ? "disk" : "peer",
+2 -2
View File
@@ -129,7 +129,7 @@ void MemberFileBatch::request(uint8_t command) {
if ((m_mode == Download || command == MF_REMOVE_PATH || command == MF_LIST) && entry.version.size() == 16) if ((m_mode == Download || command == MF_REMOVE_PATH || command == MF_LIST) && entry.version.size() == 16)
memcpy(r.version, entry.version.constData(), 16); memcpy(r.version, entry.version.constData(), 16);
r.cursor = command == MF_LIST ? entry.cursor : 0; m_command = command; m_request = r.request_id; r.cursor = command == MF_LIST ? entry.cursor : 0; m_command = command; m_request = r.request_id;
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "file batch: request id=%llu command=%s path=%s cursor=%llu", DEBUG_TRACE(DEBUG_CATEGORY_MEDIA, "file batch: request id=%llu command=%s path=%s cursor=%llu",
(unsigned long long)m_request, mf_command_text(command), r.path, (unsigned long long)r.cursor); (unsigned long long)m_request, mf_command_text(command), r.path, (unsigned long long)r.cursor);
gui_bridge_post_uasync_fn(member_files_gui_request, q); gui_bridge_post_uasync_fn(member_files_gui_request, q);
} }
@@ -271,7 +271,7 @@ void MemberFileBatch::advance(bool skipped) {
if (m_scanning) { if (m_scanning) {
// Обратный порядок полного обхода гарантирует удаление детей раньше родителей. // Обратный порядок полного обхода гарантирует удаление детей раньше родителей.
m_remove.prepend(m_queue.first()); m_remove.prepend(m_queue.first());
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "file batch: removal planned path=%s entries=%d", DEBUG_TRACE(DEBUG_CATEGORY_MEDIA, "file batch: removal planned path=%s entries=%d",
qPrintable(m_queue.first().remote), int(m_remove.size())); qPrintable(m_queue.first().remote), int(m_remove.size()));
} else { } else {
DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "file batch: entry completed path=%s skipped=%d", qPrintable(m_queue.first().remote), skipped); DEBUG_INFO(DEBUG_CATEGORY_MEDIA, "file batch: entry completed path=%s skipped=%d", qPrintable(m_queue.first().remote), skipped);
+11 -15
View File
@@ -130,7 +130,6 @@ MemberFileBrowser::MemberFileBrowser(DbManager* db, QWidget* parent) : QDialog(p
m_dropHint->setAttribute(Qt::WA_TransparentForMouseEvents); m_dropHint->setAlignment(Qt::AlignCenter); m_dropHint->setAttribute(Qt::WA_TransparentForMouseEvents); m_dropHint->setAlignment(Qt::AlignCenter);
m_dropHint->setStyleSheet("QLabel { border: 2px dashed palette(highlight); background: palette(window); color: palette(text); }"); m_dropHint->setStyleSheet("QLabel { border: 2px dashed palette(highlight); background: palette(window); color: palette(text); }");
m_dropHint->setText(text("Copy to my files")); m_dropHint->hide(); m_dropHint->setText(text("Copy to my files")); m_dropHint->hide();
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "file browser: drop targets installed count=%d", int(dropTargets.size()));
connect(reload, &QPushButton::clicked, this, [this]() { m_staleRetries = 0; refresh(); }); connect(reload, &QPushButton::clicked, this, [this]() { m_staleRetries = 0; refresh(); });
connect(up, &QPushButton::clicked, this, [this]() { connect(up, &QPushButton::clicked, this, [this]() {
m_entries->setFocus(); m_entries->setFocus();
@@ -150,13 +149,11 @@ MemberFileBrowser::MemberFileBrowser(DbManager* db, QWidget* parent) : QDialog(p
auto* removeShortcut = new QShortcut(QKeySequence(Qt::Key_Delete), m_entries); auto* removeShortcut = new QShortcut(QKeySequence(Qt::Key_Delete), m_entries);
removeShortcut->setContext(Qt::WidgetWithChildrenShortcut); removeShortcut->setAutoRepeat(false); removeShortcut->setContext(Qt::WidgetWithChildrenShortcut); removeShortcut->setAutoRepeat(false);
connect(removeShortcut, &QShortcut::activated, this, [this] { connect(removeShortcut, &QShortcut::activated, this, [this] {
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "file browser: Delete key path=%s enabled=%d", qPrintable(selectedPath()), m_remove->isEnabled());
m_remove->click(); m_remove->click();
}); });
auto* upShortcut = new QShortcut(QKeySequence(Qt::Key_Backspace), m_entries); auto* upShortcut = new QShortcut(QKeySequence(Qt::Key_Backspace), m_entries);
upShortcut->setContext(Qt::WidgetWithChildrenShortcut); upShortcut->setAutoRepeat(false); upShortcut->setContext(Qt::WidgetWithChildrenShortcut); upShortcut->setAutoRepeat(false);
connect(upShortcut, &QShortcut::activated, this, [this, up] { connect(upShortcut, &QShortcut::activated, this, [this, up] {
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "file browser: Backspace key path=%s enabled=%d", qPrintable(m_path), up->isEnabled());
up->click(); up->click();
}); });
for (auto key : {Qt::Key_Return, Qt::Key_Enter}) { for (auto key : {Qt::Key_Return, Qt::Key_Enter}) {
@@ -164,7 +161,6 @@ MemberFileBrowser::MemberFileBrowser(DbManager* db, QWidget* parent) : QDialog(p
enterShortcut->setContext(Qt::WidgetWithChildrenShortcut); enterShortcut->setAutoRepeat(false); enterShortcut->setContext(Qt::WidgetWithChildrenShortcut); enterShortcut->setAutoRepeat(false);
connect(enterShortcut, &QShortcut::activated, this, [this] { connect(enterShortcut, &QShortcut::activated, this, [this] {
auto* item = m_entries->currentItem(); auto* item = m_entries->currentItem();
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "file browser: Enter key path=%s selected=%d", qPrintable(selectedPath()), item != nullptr);
if (item) enter(item); if (item) enter(item);
}); });
} }
@@ -289,7 +285,7 @@ void MemberFileBrowser::updateActions() {
bool MemberFileBrowser::post(mf_message& message) { bool MemberFileBrowser::post(mf_message& message) {
if (!m_group || !server() || !gui_bridge_is_uasync_ready()) { if (!m_group || !server() || !gui_bridge_is_uasync_ready()) {
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "member_files: GUI post rejected cmd=%s group=%llx server=%llx ready=%d", DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "member_files: GUI post rejected cmd=%s group=%llx server=%llx ready=%d",
mf_command_text(message.command), (unsigned long long)m_group, (unsigned long long)server(), gui_bridge_is_uasync_ready()); mf_command_text(message.command), (unsigned long long)m_group, (unsigned long long)server(), gui_bridge_is_uasync_ready());
return false; return false;
} }
@@ -297,7 +293,7 @@ bool MemberFileBrowser::post(mf_message& message) {
if (!q) { DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "file browser: request allocation failed"); return false; } if (!q) { DEBUG_ERROR(DEBUG_CATEGORY_MEDIA, "file browser: request allocation failed"); return false; }
message.request_id = requestId(); message.kind = MF_REQUEST; message.request_id = requestId(); message.kind = MF_REQUEST;
q->inst = gui_bridge_get_inst(); q->group = m_group; q->server = server(); q->message = message; q->inst = gui_bridge_get_inst(); q->group = m_group; q->server = server(); q->message = message;
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "member_files: GUI post id=%llu cmd=%s group=%llx server=%llx owner=%llx path=%s", DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "member_files: GUI post id=%llu cmd=%s group=%llx server=%llx owner=%llx path=%s",
(unsigned long long)message.request_id, mf_command_text(message.command), (unsigned long long)m_group, (unsigned long long)message.request_id, mf_command_text(message.command), (unsigned long long)m_group,
(unsigned long long)server(), (unsigned long long)message.owner, message.path); (unsigned long long)server(), (unsigned long long)message.owner, message.path);
gui_bridge_post_uasync_fn(member_files_gui_request, q); return true; gui_bridge_post_uasync_fn(member_files_gui_request, q); return true;
@@ -321,7 +317,7 @@ void MemberFileBrowser::requestQuota() {
} }
void MemberFileBrowser::refresh() { void MemberFileBrowser::refresh() {
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "member_files: GUI refresh old_id=%llu group=%llx server=%llx owner=%llx path=%s", DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "member_files: GUI refresh old_id=%llu group=%llx server=%llx owner=%llx path=%s",
(unsigned long long)m_listId, (unsigned long long)m_group, (unsigned long long)server(), (unsigned long long)owner(), qPrintable(m_path)); (unsigned long long)m_listId, (unsigned long long)m_group, (unsigned long long)server(), (unsigned long long)owner(), qPrintable(m_path));
cancelRequest(m_listId); m_listId = 0; m_entries->clear(); m_location->setText(m_path); updateActions(); cancelRequest(m_listId); m_listId = 0; m_entries->clear(); m_location->setText(m_path); updateActions();
cancelRequest(m_quotaId); m_quotaId = 0; m_refreshGeneration++; cancelRequest(m_quotaId); m_quotaId = 0; m_refreshGeneration++;
@@ -355,21 +351,21 @@ void MemberFileBrowser::enter(QTreeWidgetItem* item) {
} }
void MemberFileBrowser::onResponse(const uint8_t* data, int length) { void MemberFileBrowser::onResponse(const uint8_t* data, int length) {
if (!data || length < 16) { DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "member_files: GUI short response bytes=%d", length); return; } if (!data || length < 16) { DEBUG_WARN(DEBUG_CATEGORY_MEDIA, "member_files: GUI short response bytes=%d", length); return; }
if (mf_get64(data) != m_group || mf_get64(data + 8) != server()) { if (mf_get64(data) != m_group || mf_get64(data + 8) != server()) {
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "member_files: GUI response ignored context group=%llx/%llx server=%llx/%llx", DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "member_files: GUI response ignored context group=%llx/%llx server=%llx/%llx",
(unsigned long long)mf_get64(data), (unsigned long long)m_group, (unsigned long long)mf_get64(data), (unsigned long long)m_group,
(unsigned long long)mf_get64(data + 8), (unsigned long long)server()); (unsigned long long)mf_get64(data + 8), (unsigned long long)server());
return; return;
} }
mf_message r{}; if (mf_decode(data + 16, (size_t)length - 16, &r)) return; mf_message r{}; if (mf_decode(data + 16, (size_t)length - 16, &r)) return;
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "member_files: GUI response id=%llu list_id=%llu cmd=%s status=%s bytes=%u owner=%llx/%llx path=%s", DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "member_files: GUI response id=%llu list_id=%llu cmd=%s status=%s bytes=%u owner=%llx/%llx path=%s",
(unsigned long long)r.request_id, (unsigned long long)m_listId, mf_command_text(r.command), mf_status_text(r.status), r.data_len, (unsigned long long)r.request_id, (unsigned long long)m_listId, mf_command_text(r.command), mf_status_text(r.status), r.data_len,
(unsigned long long)r.owner, (unsigned long long)owner(), r.path); (unsigned long long)r.owner, (unsigned long long)owner(), r.path);
if (m_batch && m_batch->response(r)) return; if (m_batch && m_batch->response(r)) return;
if (r.command == MF_QUOTA) { if (r.command == MF_QUOTA) {
if (r.request_id != m_quotaId || r.owner != owner()) { if (r.request_id != m_quotaId || r.owner != owner()) {
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "member_files: GUI stale quota response id=%llu", (unsigned long long)r.request_id); DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "member_files: GUI stale quota response id=%llu", (unsigned long long)r.request_id);
return; return;
} }
m_quotaId = 0; m_quotaId = 0;
@@ -393,7 +389,7 @@ void MemberFileBrowser::onResponse(const uint8_t* data, int length) {
m_quota->setText(label); m_quota->setText(label);
m_quota->setToolTip(text("Used: %1 bytes\nLimit: %2 bytes\nReserved: %3 bytes\nFiles: %4\nDirectories: %5") m_quota->setToolTip(text("Used: %1 bytes\nLimit: %2 bytes\nReserved: %3 bytes\nFiles: %4\nDirectories: %5")
.arg(used).arg(limit).arg(reserved).arg(files).arg(directories)); .arg(used).arg(limit).arg(reserved).arg(files).arg(directories));
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA,
"member_files: GUI quota owner=%llu used=%llu limit=%llu reserved=%llu files=%llu directories=%llu", "member_files: GUI quota owner=%llu used=%llu limit=%llu reserved=%llu files=%llu directories=%llu",
(unsigned long long)owner(), (unsigned long long)used, (unsigned long long)limit, (unsigned long long)reserved, (unsigned long long)owner(), (unsigned long long)used, (unsigned long long)limit, (unsigned long long)reserved,
(unsigned long long)files, (unsigned long long)directories); (unsigned long long)files, (unsigned long long)directories);
@@ -434,13 +430,13 @@ void MemberFileBrowser::onResponse(const uint8_t* data, int length) {
} else { } else {
m_listId = 0; m_entries->setSortingEnabled(true); m_entries->sortItems(0, Qt::AscendingOrder); m_listId = 0; m_entries->setSortingEnabled(true); m_entries->sortItems(0, Qt::AscendingOrder);
m_status->setText(text("%1 entries").arg(m_entries->topLevelItemCount())); updateActions(); m_status->setText(text("%1 entries").arg(m_entries->topLevelItemCount())); updateActions();
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "member_files: GUI directory ready id=%llu entries=%d", DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "member_files: GUI directory ready id=%llu entries=%d",
(unsigned long long)r.request_id, m_entries->topLevelItemCount()); (unsigned long long)r.request_id, m_entries->topLevelItemCount());
} }
return; return;
} }
if (!m_actions.contains(r.request_id)) { if (!m_actions.contains(r.request_id)) {
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "member_files: GUI response ignored stale id=%llu cmd=%s", DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "member_files: GUI response ignored stale id=%llu cmd=%s",
(unsigned long long)r.request_id, mf_command_text(r.command)); (unsigned long long)r.request_id, mf_command_text(r.command));
return; return;
} }
@@ -583,7 +579,7 @@ void MemberFileBrowser::exportFile(bool clipboard, const QString& destination) {
auto* mime = new DeferredFileMimeData; auto* mime = new DeferredFileMimeData;
mime->localFiles = [guard, id, result] { mime->localFiles = [guard, id, result] {
if (guard && guard->m_exportId == id) { if (guard && guard->m_exportId == id) {
DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "file browser: drag waiting for batch id=%llu", (unsigned long long)id); DEBUG_DEBUG(DEBUG_CATEGORY_MEDIA, "file browser: drag waiting for batch id=%llu", (unsigned long long)id);
QEventLoop wait; QEventLoop wait;
QObject::connect(guard, &MemberFileBrowser::exportFinished, &wait, &QEventLoop::quit); QObject::connect(guard, &MemberFileBrowser::exportFinished, &wait, &QEventLoop::quit);
QObject::connect(guard, &QObject::destroyed, &wait, &QEventLoop::quit); QObject::connect(guard, &QObject::destroyed, &wait, &QEventLoop::quit);