From 8bd69ad94105c9ae81a731e133fa57b2e1d280e4 Mon Sep 17 00:00:00 2001 From: Matthieu Gallien Date: Fri, 9 Jun 2023 18:58:50 +0200 Subject: [PATCH 1/7] fully hide some logs from release builds Signed-off-by: Matthieu Gallien --- src/csync/csync_exclude.cpp | 2 ++ src/libsync/discovery.cpp | 6 ++++++ 2 files changed, 8 insertions(+) diff --git a/src/csync/csync_exclude.cpp b/src/csync/csync_exclude.cpp index bddb3047e..9efe50df3 100644 --- a/src/csync/csync_exclude.cpp +++ b/src/csync/csync_exclude.cpp @@ -442,7 +442,9 @@ CSYNC_EXCLUDE_TYPE ExcludedFiles::traversalPatternMatch(const QString &path, Ite addExcludeFilePath(absolutePath); reloadExcludeFiles(); } else { +#if !defined QT_NO_DEBUG qWarning() << "System exclude list file could not be read:" << absolutePath; +#endif } } diff --git a/src/libsync/discovery.cpp b/src/libsync/discovery.cpp index 81e180934..2ed343bc1 100644 --- a/src/libsync/discovery.cpp +++ b/src/libsync/discovery.cpp @@ -952,7 +952,9 @@ void ProcessDirectoryJob::processFileAnalyzeLocalInfo( // Not modified locally (ParentNotChanged) if (noServerEntry) { // not on the server: Removed on the server, delete locally +#if !defined QT_NO_DEBUG qCInfo(lcDisco) << "File" << item->_file << "is not anymore on server. Going to delete it locally."; +#endif item->_instruction = CSYNC_INSTRUCTION_REMOVE; item->_direction = SyncFileItem::Down; } else if (dbEntry._type == ItemTypeVirtualFileDehydration) { @@ -980,7 +982,9 @@ void ProcessDirectoryJob::processFileAnalyzeLocalInfo( } else if (!serverModified) { // Removed locally: also remove on the server. if (!dbEntry._serverHasIgnoredFiles) { +#if !defined QT_NO_DEBUG qCInfo(lcDisco) << "File" << item->_file << "was deleted locally. Going to delete it on the server."; +#endif item->_instruction = CSYNC_INSTRUCTION_REMOVE; item->_direction = SyncFileItem::Up; } @@ -1019,7 +1023,9 @@ void ProcessDirectoryJob::processFileAnalyzeLocalInfo( } else if (!typeChange && ((dbEntry._modtime == localEntry.modtime && dbEntry._fileSize == localEntry.size) || localEntry.isDirectory)) { // Local file unchanged. if (noServerEntry) { +#if !defined QT_NO_DEBUG qCInfo(lcDisco) << "File" << item->_file << "is not anymore on server. Going to delete it locally."; +#endif item->_instruction = CSYNC_INSTRUCTION_REMOVE; item->_direction = SyncFileItem::Down; } else if (dbEntry._type == ItemTypeVirtualFileDehydration || localEntry.type == ItemTypeVirtualFileDehydration) { From 40b1987287b1de59148689f6609c5ebefb530345 Mon Sep 17 00:00:00 2001 From: Matthieu Gallien Date: Fri, 9 Jun 2023 19:36:06 +0200 Subject: [PATCH 2/7] downgrade some log lines to be less verbose those log lines can easily be skipped from info level as they are needed in very rare occasion Signed-off-by: Matthieu Gallien --- src/gui/socketapi/socketapi.cpp | 6 +++--- src/libsync/bandwidthmanager.cpp | 2 +- src/libsync/propagatedownload.cpp | 2 +- src/libsync/syncengine.cpp | 2 +- 4 files changed, 6 insertions(+), 6 deletions(-) diff --git a/src/gui/socketapi/socketapi.cpp b/src/gui/socketapi/socketapi.cpp index b657ecaa6..4b1dab50e 100644 --- a/src/gui/socketapi/socketapi.cpp +++ b/src/gui/socketapi/socketapi.cpp @@ -316,7 +316,7 @@ void SocketApi::slotNewConnection() if (!socket) { return; } - qCInfo(lcSocketApi) << "New connection" << socket; + qCDebug(lcSocketApi) << "New connection" << socket; connect(socket, &QIODevice::readyRead, this, &SocketApi::slotReadSocket); connect(socket, SIGNAL(disconnected()), this, SLOT(onLostConnection())); connect(socket, &QObject::destroyed, this, &SocketApi::slotSocketDestroyed); @@ -327,7 +327,7 @@ void SocketApi::slotNewConnection() for (Folder *f : FolderMan::instance()->map()) { if (f->canSync()) { QString message = buildRegisterPathMessage(removeTrailingSlash(f->path())); - qCInfo(lcSocketApi) << "Trying to send SocketAPI Register Path Message -->" << message << "to" << listener->socket; + qCDebug(lcSocketApi) << "Trying to send SocketAPI Register Path Message -->" << message << "to" << listener->socket; listener->sendMessage(message); } } @@ -366,7 +366,7 @@ void SocketApi::slotReadSocket() // Make sure to normalize the input from the socket to // make sure that the path will match, especially on OS X. const QString line = QString::fromUtf8(socket->readLine().trimmed()).normalized(QString::NormalizationForm_C); - qCInfo(lcSocketApi) << "Received SocketAPI message <--" << line << "from" << socket; + qCDebug(lcSocketApi) << "Received SocketAPI message <--" << line << "from" << socket; const int argPos = line.indexOf(QLatin1Char(':')); const QByteArray command = line.midRef(0, argPos).toUtf8().toUpper(); const int indexOfMethod = [&] { diff --git a/src/libsync/bandwidthmanager.cpp b/src/libsync/bandwidthmanager.cpp index f5fc3582b..358822e6b 100644 --- a/src/libsync/bandwidthmanager.cpp +++ b/src/libsync/bandwidthmanager.cpp @@ -286,7 +286,7 @@ void BandwidthManager::relativeDownloadMeasuringTimerExpired() auto quota = relativeLimitProgressDifference * (downloadLimitPercent / 100.0); if (quota > 20 * 1024) { - qCInfo(lcBandwidthManager) << "ADJUSTING QUOTA FROM " << quota << " TO " << quota - 20 * 1024; + qCDebug(lcBandwidthManager) << "ADJUSTING QUOTA FROM " << quota << " TO " << quota - 20 * 1024; quota -= 20 * 1024; } diff --git a/src/libsync/propagatedownload.cpp b/src/libsync/propagatedownload.cpp index b82f80a7c..2edd3c4c5 100644 --- a/src/libsync/propagatedownload.cpp +++ b/src/libsync/propagatedownload.cpp @@ -306,7 +306,7 @@ void GETFileJob::slotReadyRead() if (_bandwidthLimited) { toRead = qMin(qint64(bufferSize), _bandwidthQuota); if (toRead == 0) { - qCWarning(lcGetJob) << "Out of quota"; + qCDebug(lcGetJob) << "Out of quota"; break; } _bandwidthQuota -= toRead; diff --git a/src/libsync/syncengine.cpp b/src/libsync/syncengine.cpp index f162b0ed5..5f955ac0d 100644 --- a/src/libsync/syncengine.cpp +++ b/src/libsync/syncengine.cpp @@ -624,7 +624,7 @@ void SyncEngine::startSync() _discoveryPhase->_syncOptions = _syncOptions; _discoveryPhase->_shouldDiscoverLocaly = [this](const QString &path) { const auto result = shouldDiscoverLocally(path); - qCInfo(lcEngine) << "shouldDiscoverLocaly" << path << (result ? "true" : "false"); + qCDebug(lcEngine) << "shouldDiscoverLocaly" << path << (result ? "true" : "false"); return result; }; _discoveryPhase->setSelectiveSyncBlackList(selectiveSyncBlackList); From 516649334f2b1cc140d838c5bd6b329bc1d84bb0 Mon Sep 17 00:00:00 2001 From: Matthieu Gallien Date: Fri, 9 Jun 2023 19:36:52 +0200 Subject: [PATCH 3/7] by default hide most discovery log traces will make the logs much less usefull by default Signed-off-by: Matthieu Gallien --- src/libsync/discovery.cpp | 4 ++-- src/libsync/syncfilestatustracker.cpp | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/src/libsync/discovery.cpp b/src/libsync/discovery.cpp index 2ed343bc1..689496da4 100644 --- a/src/libsync/discovery.cpp +++ b/src/libsync/discovery.cpp @@ -421,7 +421,7 @@ void ProcessDirectoryJob::processFile(PathTuple path, const char *hasLocal = localEntry.isValid() ? "true" : _queryLocal == ParentNotChanged ? "db" : "false"; const auto serverFileIsLocked = (serverEntry.isValid() ? (serverEntry.locked == SyncFileItem::LockStatus::LockedItem ? "locked" : "not locked") : ""); const auto localFileIsLocked = dbEntry._lockstate._locked ? "locked" : "not locked"; - qCInfo(lcDisco).nospace() << "Processing " << path._original + qCDebug(lcDisco).nospace() << "Processing " << path._original << " | (db/local/remote)" << " | valid: " << dbEntry.isValid() << "/" << hasLocal << "/" << hasServer << " | mtime: " << dbEntry._modtime << "/" << localEntry.modtime << "/" << serverEntry.modtime @@ -1544,7 +1544,7 @@ void ProcessDirectoryJob::processFileFinalize( item->_direction = _dirItem->_direction; } - qCInfo(lcDisco) << "Discovered" << item->_file << item->_instruction << item->_direction << item->_type; + qCDebug(lcDisco) << "Discovered" << item->_file << item->_instruction << item->_direction << item->_type; if (item->isDirectory() && item->_instruction == CSYNC_INSTRUCTION_SYNC) item->_instruction = CSYNC_INSTRUCTION_UPDATE_METADATA; diff --git a/src/libsync/syncfilestatustracker.cpp b/src/libsync/syncfilestatustracker.cpp index 7d03fba32..6117ef223 100644 --- a/src/libsync/syncfilestatustracker.cpp +++ b/src/libsync/syncfilestatustracker.cpp @@ -226,7 +226,7 @@ void SyncFileStatusTracker::slotAboutToPropagate(SyncFileItemVector &items) std::swap(_syncProblems, oldProblems); foreach (const SyncFileItemPtr &item, items) { - qCDebug(lcStatusTracker) << "Investigating" << item->destination() << item->_status << item->_instruction << item->_direction; + qCInfo(lcStatusTracker) << "Investigating" << item->destination() << item->_status << item->_instruction << item->_direction; _dirtyPaths.remove(item->destination()); if (hasErrorStatus(*item)) { From 257bebb79029f6bb3b06f1a36062e606363362bf Mon Sep 17 00:00:00 2001 From: Matthieu Gallien Date: Mon, 12 Jun 2023 10:18:42 +0200 Subject: [PATCH 4/7] avoid info level for new entries in ActivityListModel should also decrease the number of log lines during heavy sync Signed-off-by: Matthieu Gallien --- src/gui/tray/activitylistmodel.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/gui/tray/activitylistmodel.cpp b/src/gui/tray/activitylistmodel.cpp index a917a580a..8e5f3e45b 100644 --- a/src/gui/tray/activitylistmodel.cpp +++ b/src/gui/tray/activitylistmodel.cpp @@ -558,7 +558,7 @@ void ActivityListModel::addEntriesToActivityList(const ActivityList &activityLis void ActivityListModel::addErrorToActivityList(const Activity &activity, const ErrorType type) { - qCInfo(lcActivity) << "Error successfully added to the notification list: " << type << activity._message << activity._subject << activity._syncResultStatus << activity._syncFileItemStatus; + qCDebug(lcActivity) << "Error successfully added to the notification list: " << type << activity._message << activity._subject << activity._syncResultStatus << activity._syncFileItemStatus; auto modifiedActivity = activity; if (type == ErrorType::NetworkError) { modifiedActivity._subject = tr("Network error occurred: client will retry syncing."); @@ -594,14 +594,14 @@ void ActivityListModel::addIgnoredFileToList(const Activity &newActivity) void ActivityListModel::addNotificationToActivityList(const Activity &activity) { - qCInfo(lcActivity) << "Notification successfully added to the notification list: " << activity._subject; + qCDebug(lcActivity) << "Notification successfully added to the notification list: " << activity._subject; addEntriesToActivityList({activity}); _notificationLists.prepend(activity); } void ActivityListModel::addSyncFileItemToActivityList(const Activity &activity) { - qCInfo(lcActivity) << "Successfully added to the activity list: " << activity._subject; + qCDebug(lcActivity) << "Successfully added to the activity list: " << activity._subject; addEntriesToActivityList({activity}); _syncFileItemLists.prepend(activity); } From 8c842ca0fa3f72266c052c5d8b609fbac6af2c25 Mon Sep 17 00:00:00 2001 From: Matthieu Gallien Date: Mon, 12 Jun 2023 10:33:03 +0200 Subject: [PATCH 5/7] enable "Processing" log lines again but with some removed data Signed-off-by: Matthieu Gallien --- src/libsync/discovery.cpp | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/src/libsync/discovery.cpp b/src/libsync/discovery.cpp index 689496da4..ff9441f90 100644 --- a/src/libsync/discovery.cpp +++ b/src/libsync/discovery.cpp @@ -421,7 +421,7 @@ void ProcessDirectoryJob::processFile(PathTuple path, const char *hasLocal = localEntry.isValid() ? "true" : _queryLocal == ParentNotChanged ? "db" : "false"; const auto serverFileIsLocked = (serverEntry.isValid() ? (serverEntry.locked == SyncFileItem::LockStatus::LockedItem ? "locked" : "not locked") : ""); const auto localFileIsLocked = dbEntry._lockstate._locked ? "locked" : "not locked"; - qCDebug(lcDisco).nospace() << "Processing " << path._original + qCInfo(lcDisco).nospace() << "Processing " << path._original << " | (db/local/remote)" << " | valid: " << dbEntry.isValid() << "/" << hasLocal << "/" << hasServer << " | mtime: " << dbEntry._modtime << "/" << localEntry.modtime << "/" << serverEntry.modtime @@ -430,7 +430,6 @@ void ProcessDirectoryJob::processFile(PathTuple path, << " | checksum: " << dbEntry._checksumHeader << "//" << serverEntry.checksumHeader << " | perm: " << dbEntry._remotePerm << "//" << serverEntry.remotePerm << " | fileid: " << dbEntry._fileId << "//" << serverEntry.fileId - << " | inode: " << dbEntry._inode << "/" << localEntry.inode << "/" << " | type: " << dbEntry._type << "/" << localEntry.type << "/" << (serverEntry.isDirectory ? ItemTypeDirectory : ItemTypeFile) << " | e2ee: " << dbEntry.isE2eEncrypted() << "/" << serverEntry.isE2eEncrypted() << " | e2eeMangledName: " << dbEntry.e2eMangledName() << "/" << serverEntry.e2eMangledName From bfaa59e6cab2d0c0cf7c161312b27a059de85a2b Mon Sep 17 00:00:00 2001 From: Matthieu Gallien Date: Mon, 12 Jun 2023 11:02:16 +0200 Subject: [PATCH 6/7] less info logs during discovery those log lines mostly duplicate info we already have at info level Signed-off-by: Matthieu Gallien --- src/libsync/discovery.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/libsync/discovery.cpp b/src/libsync/discovery.cpp index ff9441f90..e50817cb3 100644 --- a/src/libsync/discovery.cpp +++ b/src/libsync/discovery.cpp @@ -552,7 +552,7 @@ void ProcessDirectoryJob::processFileAnalyzeRemoteInfo( item->_lockEditorApp = serverEntry.lockEditorApp; item->_lockTime = serverEntry.lockTime; item->_lockTimeout = serverEntry.lockTimeout; - qCInfo(lcDisco()) << item->_locked << item->_lockOwnerDisplayName << item->_lockOwnerId << item->_lockOwnerType << item->_lockEditorApp << item->_lockTime << item->_lockTimeout; + qCDebug(lcDisco()) << item->_locked << item->_lockOwnerDisplayName << item->_lockOwnerId << item->_lockOwnerType << item->_lockEditorApp << item->_lockTime << item->_lockTimeout; // Check for missing server data { @@ -581,7 +581,7 @@ void ProcessDirectoryJob::processFileAnalyzeRemoteInfo( // Add on a second as a precaution, sometimes we catch the server before it has had a chance to update const auto lockExpirationTimeout = qMax(5LL, timeRemaining + 1); - qCInfo(lcDisco) << "File:" << path._original << "is locked." + qCDebug(lcDisco) << "File:" << path._original << "is locked." << "Lock expires in:" << lockExpirationTimeout << "seconds." << "A sync run will be scheduled for around that time."; From dddbe9193d6d30874d38f4ed700c8d5b07b92e6c Mon Sep 17 00:00:00 2001 From: Matthieu Gallien Date: Mon, 12 Jun 2023 12:57:17 +0200 Subject: [PATCH 7/7] rotate logs based on the lines count instead of teh file size will omit querying teh file size repeatedly (and not cost free) Signed-off-by: Matthieu Gallien --- src/libsync/logger.cpp | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/src/libsync/logger.cpp b/src/libsync/logger.cpp index cab592adf..fffbbc14c 100644 --- a/src/libsync/logger.cpp +++ b/src/libsync/logger.cpp @@ -36,7 +36,7 @@ namespace { constexpr int CrashLogSize = 20; -constexpr int MaxLogSizeBytes = 1024 * 1024 * 30; +constexpr auto MaxLogLinesCount = 50000; static bool compressLog(const QString &originalName, const QString &targetName) { @@ -118,7 +118,8 @@ bool Logger::isLoggingToFile() const void Logger::doLog(QtMsgType type, const QMessageLogContext &ctx, const QString &message) { - const QString msg = qFormatLogMessage(type, ctx, message); + static long long int linesCounter = 0; + const auto &msg = qFormatLogMessage(type, ctx, message); #if defined(Q_OS_WIN) && defined(QT_DEBUG) // write logs to Output window of Visual Studio { @@ -146,10 +147,12 @@ void Logger::doLog(QtMsgType type, const QMessageLogContext &ctx, const QString { QMutexLocker lock(&_mutex); - if (_logFile.size() >= MaxLogSizeBytes) { + if (linesCounter >= MaxLogLinesCount) { + linesCounter = 0; closeNoLock(); enterNextLogFileNoLock(); } + ++linesCounter; _crashLogIndex = (_crashLogIndex + 1) % CrashLogSize; _crashLog[_crashLogIndex] = msg;