create a permanent log of delete actions

will log all deletions with the result of the discovery by the sync
enginre

should enable analyze even long time after such a delete occured

Signed-off-by: Matthieu Gallien <matthieu.gallien@nextcloud.com>

diff --git a/src/csync/csync.h b/src/csync/csync.h
index ee5cee05024139d7b71bd0e00058cbff94c7cb78..5c8fbc0978b6ba327a7cb64393e91dd102453d4b 100644 (file)
--- a/src/csync/csync.h
+++ b/src/csync/csync.h
@@ -32,22 +32,24 @@
 #ifndef _CSYNC_H
 #define _CSYNC_H
 
-#include "std/c_private.h"
-#include "ocsynclib.h"
-
-#include <sys/stat.h>
+#include <QByteArray>
+#include <QVariant>
+#include <QLoggingCategory>
 
 #include <cstdint>
+#include <sys/stat.h>
 #include <sys/types.h>
-#include <config_csync.h>
 #include <functional>
 #include <memory>
-#include <QByteArray>
-#include <QVariant>
 
+#include "ocsynclib.h"
+#include "config_csync.h"
+#include "std/c_private.h"
 #include "common/remotepermissions.h"
 
 namespace OCC {
+Q_DECLARE_LOGGING_CATEGORY(lcPermanentLog)
+
 class SyncJournalFileRecord;
 
 namespace EncryptionStatusEnums {

diff --git a/src/gui/application.cpp b/src/gui/application.cpp
index 46b652c6d1f69da30354211b7ef41a20637de97f..7aee62a2020408f55ce8dffefde6821074cfb71e 100644 (file)
--- a/src/gui/application.cpp
+++ b/src/gui/application.cpp
@@ -716,7 +716,8 @@ void Application::setupLogging()
     logger->setLogDebug(true);
 #endif
 
-    logger->enterNextLogFile();
+    logger->enterNextLogFile(QStringLiteral("nextcloud.log"), OCC::Logger::LogType::Log);
+    logger->enterNextLogFile(QStringLiteral("permanent_delete.log"), OCC::Logger::LogType::DeleteLog);
 
     qCInfo(lcApplication) << "##################" << _theme->appName()
                           << "locale:" << QLocale::system().name()

diff --git a/src/gui/logbrowser.cpp b/src/gui/logbrowser.cpp
index 38f59930a9506cc998512d86b914daa8d22c5d61..46357edc50a5dbe2596005cc73c2456a74a37397 100644 (file)
--- a/src/gui/logbrowser.cpp
+++ b/src/gui/logbrowser.cpp
@@ -118,7 +118,7 @@ void LogBrowser::togglePermanentLogging(bool enabled)
     if (enabled) {
         if (!logger->isLoggingToFile()) {
             logger->setupTemporaryFolderLogDir();
-            logger->enterNextLogFile();
+            logger->enterNextLogFile(QStringLiteral("nextcloud.log"), OCC::Logger::LogType::Log);
         }
     } else {
         logger->disableTemporaryFolderLogDir();

diff --git a/src/gui/owncloudgui.cpp b/src/gui/owncloudgui.cpp
index 0f8b186fd511bcafd175e11fad5fe9a0e267b98f..ff7a6fee010dd5b5413d08ce6804b2e93a53c913 100644 (file)
--- a/src/gui/owncloudgui.cpp
+++ b/src/gui/owncloudgui.cpp
@@ -250,7 +250,7 @@ void ownCloudGui::slotSyncStateChange(Folder *folder)
         || result.status() == SyncResult::Problem
         || result.status() == SyncResult::SyncAbortRequested
         || result.status() == SyncResult::Error) {
-        Logger::instance()->enterNextLogFile();
+        Logger::instance()->enterNextLogFile(QStringLiteral("nextcloud.log"), OCC::Logger::LogType::Log);
     }
 }
 

diff --git a/src/libsync/discovery.cpp b/src/libsync/discovery.cpp
index 277190f460d0f37939948f63c85e15ce7347f8af..ad0c2f69ead4ec9f3026863b1f8f8cad79202eb0 100644 (file)
--- a/src/libsync/discovery.cpp
+++ b/src/libsync/discovery.cpp
@@ -528,22 +528,26 @@ void ProcessDirectoryJob::processFile(PathTuple path,
     const auto localFileIsLocked = dbEntry._lockstate._locked ? "locked" : "not locked";
     const auto serverFileLockType = serverEntry.isValid() ? QString::number(static_cast<int>(serverEntry.lockOwnerType)) : QStringLiteral("");
     const auto localFileLockType = dbEntry._lockstate._locked ? QString::number(static_cast<int>(dbEntry._lockstate._lockOwnerType)) : QStringLiteral("");
-    qCInfo(lcDisco).nospace() << "Processing " << path._original
-                              << " | (db/local/remote)"
-                              << " | valid: " << dbEntry.isValid() << "/" << hasLocal << "/" << hasServer
-                              << " | mtime: " << dbEntry._modtime << "/" << localEntry.modtime << "/" << serverEntry.modtime
-                              << " | size: " << dbEntry._fileSize << "/" << localEntry.size << "/" << serverEntry.size
-                              << " | etag: " << dbEntry._etag << "//" << serverEntry.etag
-                              << " | 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
-                              << " | file lock: " << localFileIsLocked << "//" << serverFileIsLocked
-                              << " | file lock type: " << localFileLockType << "//" << serverFileLockType
-                              << " | metadata missing: /" << localEntry.isMetadataMissing << '/';
+
+    QString processingLog;
+    QDebug deleteLogger{&processingLog};
+    deleteLogger.nospace() << "Processing " << path._original
+                           << " | (db/local/remote)"
+                           << " | valid: " << dbEntry.isValid() << "/" << hasLocal << "/" << hasServer
+                           << " | mtime: " << dbEntry._modtime << "/" << localEntry.modtime << "/" << serverEntry.modtime
+                           << " | size: " << dbEntry._fileSize << "/" << localEntry.size << "/" << serverEntry.size
+                           << " | etag: " << dbEntry._etag << "//" << serverEntry.etag
+                           << " | checksum: " << dbEntry._checksumHeader << "//" << serverEntry.checksumHeader
+                           << " | perm: " << dbEntry._remotePerm << "//" << serverEntry.remotePerm
+                           << " | fileid: " << dbEntry._fileId << "//" << serverEntry.fileId
+                           << " | type: " << dbEntry._type << "/" << localEntry.type << "/" << (serverEntry.isDirectory ? ItemTypeDirectory : ItemTypeFile)
+                           << " | e2ee: " << dbEntry.isE2eEncrypted() << "/" << serverEntry.isE2eEncrypted()
+                           << " | e2eeMangledName: " << dbEntry.e2eMangledName() << "/" << serverEntry.e2eMangledName
+                           << " | file lock: " << localFileIsLocked << "//" << serverFileIsLocked
+                           << " | file lock type: " << localFileLockType << "//" << serverFileLockType
+                           << " | metadata missing: /" << localEntry.isMetadataMissing << '/';
+
+    qCInfo(lcDisco).nospace() << processingLog;
 
     if (localEntry.isValid()
         && !serverEntry.isValid()
@@ -562,6 +566,7 @@ void ProcessDirectoryJob::processFile(PathTuple path,
     item->_originalFile = path._original;
     item->_previousSize = dbEntry._fileSize;
     item->_previousModtime = dbEntry._modtime;
+    item->_discoveryResult = std::move(processingLog);
 
     if (dbEntry._modtime == localEntry.modtime && dbEntry._type == ItemTypeVirtualFile && localEntry.type == ItemTypeFile) {
         item->_type = ItemTypeFile;

diff --git a/src/libsync/logger.cpp b/src/libsync/logger.cpp
index 64acb2b7b465ce2476aca9ae7458e207de25476f..060705ba6c8ef15e286b174ba497aa5be25bb2f2 100644 (file)
--- a/src/libsync/logger.cpp
+++ b/src/libsync/logger.cpp
@@ -68,6 +68,8 @@ static bool compressLog(const QString &originalName, const QString &targetName)
 
 namespace OCC {
 
+Q_LOGGING_CATEGORY(lcPermanentLog, "nextcloud.log.permanent")
+
 Logger *Logger::instance()
 {
     static Logger log;
@@ -151,7 +153,7 @@ void Logger::doLog(QtMsgType type, const QMessageLogContext &ctx, const QString
                 _logstream->flush();
             }
             closeNoLock();
-            enterNextLogFileNoLock();
+            enterNextLogFileNoLock(QStringLiteral("nextcloud.log"), LogType::Log);
         }
         ++linesCounter;
 
@@ -163,6 +165,13 @@ void Logger::doLog(QtMsgType type, const QMessageLogContext &ctx, const QString
             if (_doFileFlush)
                 _logstream->flush();
         }
+        if (_permanentDeleteLogStream && strcmp(ctx.category, lcPermanentLog().categoryName()) == 0) {
+            (*_permanentDeleteLogStream) << msg << "\n";
+            _permanentDeleteLogStream->flush();
+            if (_permanentDeleteLogFile.size() > 10LL * 1024LL) {
+                enterNextLogFileNoLock(QStringLiteral("permanent_delete.log"), LogType::DeleteLog);
+            }
+        }
         if (type == QtFatalMsg) {
             closeNoLock();
 #if defined(Q_OS_WIN)
@@ -197,6 +206,12 @@ void Logger::setLogFile(const QString &name)
     setLogFileNoLock(name);
 }
 
+void Logger::setPermanentDeleteLogFile(const QString &name)
+{
+    QMutexLocker locker(&_mutex);
+    setPermanentDeleteLogFileNoLock(name);
+}
+
 void Logger::setLogExpire(int expire)
 {
     _logExpire = expire;
@@ -249,7 +264,7 @@ void Logger::disableTemporaryFolderLogDir()
     if (!_temporaryFolderLogDir)
         return;
 
-    enterNextLogFile();
+    enterNextLogFile("nextcloud.log", LogType::Log);
     setLogDir(QString());
     setLogDebug(false);
     setLogFile(QString());
@@ -279,7 +294,7 @@ void Logger::dumpCrashLog()
     }
 }
 
-void Logger::enterNextLogFileNoLock()
+void Logger::enterNextLogFileNoLock(const QString &baseFileName, LogType type)
 {
     if (!_logDirectory.isEmpty()) {
 
@@ -291,29 +306,44 @@ void Logger::enterNextLogFileNoLock()
         // Tentative new log name, will be adjusted if one like this already exists
         const auto now = QDateTime::currentDateTime();
         const auto cLocale = QLocale::c(); // Some system locales generate strings that are incompatible with filesystem
-        QString newLogName = cLocale.toString(now, QStringLiteral("yyyyMMdd_HHmm")) + QStringLiteral("_nextcloud.log");
+        QString newLogName = cLocale.toString(now, QStringLiteral("yyyyMMdd_HHmm")) + QStringLiteral("_%1").arg(baseFileName);
 
         // Expire old log files and deal with conflicts
-        QStringList files = dir.entryList(QStringList("*owncloud.log.*"), QDir::Files, QDir::Name) +
-            dir.entryList(QStringList("*nextcloud.log.*"), QDir::Files, QDir::Name);
-        static const QRegularExpression rx(QRegularExpression::anchoredPattern(R"(.*(next|own)cloud\.log\.(\d+).*)"));
-        int maxNumber = -1;
-        foreach (const QString &s, files) {
+        const auto files = dir.entryList({QStringLiteral("*owncloud.log.*"), QStringLiteral("*%1.*").arg(baseFileName)}, QDir::Files, QDir::Name);
+        for (const auto &s : files) {
             if (_logExpire > 0) {
                 QFileInfo fileInfo(dir.absoluteFilePath(s));
                 if (fileInfo.lastModified().addSecs(60 * 60 * _logExpire) < now) {
                     dir.remove(s);
                 }
             }
-            const auto rxMatch = rx.match(s);
-            if (s.startsWith(newLogName) && rxMatch.hasMatch()) {
-                maxNumber = qMax(maxNumber, rxMatch.captured(2).toInt());
+        }
+
+        const auto regexpText = QString{"%1\\.(\\d+).*"}.arg(QRegularExpression::escape(newLogName));
+        const auto anchoredPatternRegexpText = QRegularExpression::anchoredPattern(regexpText);
+        const QRegularExpression rx(regexpText);
+        int maxNumber = -1;
+        const auto collidingFileNames = dir.entryList({QStringLiteral("%1.*").arg(newLogName)}, QDir::Files, QDir::Name);
+        for(const auto &fileName : collidingFileNames) {
+            const auto rxMatch = rx.match(fileName);
+            if (rxMatch.hasMatch()) {
+                maxNumber = qMax(maxNumber, rxMatch.captured(1).toInt());
             }
         }
         newLogName.append("." + QString::number(maxNumber + 1));
 
-        auto previousLog = _logFile.fileName();
-        setLogFileNoLock(dir.filePath(newLogName));
+        auto previousLog = QString{};
+        switch (type)
+        {
+        case OCC::Logger::LogType::Log:
+            previousLog = _logFile.fileName();
+            setLogFileNoLock(dir.filePath(newLogName));
+            break;
+        case OCC::Logger::LogType::DeleteLog:
+            previousLog = _permanentDeleteLogFile.fileName();
+            setPermanentDeleteLogFileNoLock(dir.filePath(newLogName));
+            break;
+        }
 
         // Compress the previous log file. On a restart this can be the most recent
         // log file.
@@ -361,10 +391,40 @@ void Logger::setLogFileNoLock(const QString &name)
     _logstream.reset(new QTextStream(&_logFile));
 }
 
-void Logger::enterNextLogFile()
+void Logger::setPermanentDeleteLogFileNoLock(const QString &name)
+{
+    if (_permanentDeleteLogStream) {
+        _permanentDeleteLogStream.reset(nullptr);
+        _permanentDeleteLogFile.close();
+    }
+
+    if (name.isEmpty()) {
+        return;
+    }
+
+    bool openSucceeded = false;
+    if (name == QLatin1String("-")) {
+        openSucceeded = _permanentDeleteLogFile.open(stdout, QIODevice::WriteOnly);
+    } else {
+        _permanentDeleteLogFile.setFileName(name);
+        openSucceeded = _permanentDeleteLogFile.open(QIODevice::WriteOnly);
+    }
+
+    if (!openSucceeded) {
+        postGuiMessage(tr("Error"),
+                       QString(tr("<nobr>File \"%1\"<br/>cannot be opened for writing.<br/><br/>"
+                                  "The log output <b>cannot</b> be saved!</nobr>"))
+                           .arg(name));
+        return;
+    }
+
+    _permanentDeleteLogStream.reset(new QTextStream(&_permanentDeleteLogFile));
+}
+
+void Logger::enterNextLogFile(const QString &baseFileName, LogType type)
 {
     QMutexLocker locker(&_mutex);
-    enterNextLogFileNoLock();
+    enterNextLogFileNoLock(baseFileName, type);
 }
 
 } // namespace OCC

diff --git a/src/libsync/logger.h b/src/libsync/logger.h
index bfcb2989d5db06cddf710d5f2513aa712aa8c6be..2d9dce3193edd1194705388f4b982c3ac021dfb3 100644 (file)
--- a/src/libsync/logger.h
+++ b/src/libsync/logger.h
@@ -20,7 +20,7 @@
 #include <QDateTime>
 #include <QFile>
 #include <QTextStream>
-#include <qmutex.h>
+#include <QRecursiveMutex>
 
 #include "common/utility.h"
 #include "owncloudlib.h"
@@ -35,6 +35,12 @@ class OWNCLOUDSYNC_EXPORT Logger : public QObject
 {
     Q_OBJECT
 public:
+    enum class LogType {
+        Log,
+        DeleteLog,
+    };
+    Q_ENUM(LogType)
+
     bool isLoggingToFile() const;
 
     void doLog(QtMsgType type, const QMessageLogContext &ctx, const QString &message);
@@ -47,6 +53,8 @@ public:
     QString logFile() const;
     void setLogFile(const QString &name);
 
+    void setPermanentDeleteLogFile(const QString &name);
+
     void setLogExpire(int expire);
 
     QString logDir() const;
@@ -88,7 +96,7 @@ signals:
     void guiMessage(const QString &, const QString &);
 
 public slots:
-    void enterNextLogFile();
+    void enterNextLogFile(const QString &baseFileName, OCC::Logger::LogType type);
 
 private:
     Logger(QObject *parent = nullptr);
@@ -96,20 +104,23 @@ private:
 
     void closeNoLock();
     void dumpCrashLog();
-    void enterNextLogFileNoLock();
+    void enterNextLogFileNoLock(const QString &baseFileName, LogType type);
     void setLogFileNoLock(const QString &name);
+    void setPermanentDeleteLogFileNoLock(const QString &name);
 
     QFile _logFile;
     bool _doFileFlush = false;
     int _logExpire = 0;
     bool _logDebug = false;
     QScopedPointer<QTextStream> _logstream;
-    mutable QMutex _mutex;
+    mutable QRecursiveMutex _mutex;
     QString _logDirectory;
     bool _temporaryFolderLogDir = false;
     QSet<QString> _logRules;
     QVector<QString> _crashLog;
     int _crashLogIndex = 0;
+    QFile _permanentDeleteLogFile;
+    QScopedPointer<QTextStream> _permanentDeleteLogStream;
 };
 
 } // namespace OCC

diff --git a/src/libsync/propagateremotedelete.cpp b/src/libsync/propagateremotedelete.cpp
index 7bc5be95288898c3d156837398fa4671f9cd5e25..708b0f2ed2a0a95dcbcb6cac87bd933e289bca78 100644 (file)
--- a/src/libsync/propagateremotedelete.cpp
+++ b/src/libsync/propagateremotedelete.cpp
@@ -29,6 +29,7 @@ Q_LOGGING_CATEGORY(lcPropagateRemoteDelete, "nextcloud.sync.propagator.remotedel
 void PropagateRemoteDelete::start()
 {
     qCInfo(lcPropagateRemoteDelete) << "Start propagate remote delete job for" << _item->_file;
+    qCInfo(lcPermanentLog) << "delete" << _item->_file << _item->_discoveryResult;
 
     if (propagator()->_abortRequested)
         return;

diff --git a/src/libsync/propagatorjobs.cpp b/src/libsync/propagatorjobs.cpp
index 0a0a84e0d4934abbeebfc5312513d5293420662a..bcdf5a4697e695d6ef71d59e49148c511a80b5da 100644 (file)
--- a/src/libsync/propagatorjobs.cpp
+++ b/src/libsync/propagatorjobs.cpp
@@ -101,6 +101,7 @@ bool PropagateLocalRemove::removeRecursively(const QString &path)
 void PropagateLocalRemove::start()
 {
     qCInfo(lcPropagateLocalRemove) << "Start propagate local remove job";
+    qCInfo(lcPermanentLog) << "delete" << _item->_file << _item->_discoveryResult;
 
     _moveToTrash = propagator()->syncOptions()._moveFilesToTrash;
 

diff --git a/src/libsync/syncfileitem.h b/src/libsync/syncfileitem.h
index 4bf481a138c86b783dc22bd47f598635e45aa62b..a4619535561b1061c53ceab1437b347bdcbf8e09 100644 (file)
--- a/src/libsync/syncfileitem.h
+++ b/src/libsync/syncfileitem.h
@@ -339,6 +339,8 @@ public:
 
     bool _isAnyInvalidCharChild = false;
     bool _isAnyCaseClashChild = false;
+
+    QString _discoveryResult;
 };
 
 inline bool operator<(const SyncFileItemPtr &item1, const SyncFileItemPtr &item2)

diff --git a/src/libsync/syncfilestatustracker.cpp b/src/libsync/syncfilestatustracker.cpp
index 67ad27ad0e59edf538dee2724d30710e7afcd78f..2b934806fa08cd18901745aa8b6f2cc0aa19cea0 100644 (file)
--- a/src/libsync/syncfilestatustracker.cpp
+++ b/src/libsync/syncfilestatustracker.cpp
@@ -249,6 +249,9 @@ void SyncFileStatusTracker::slotAboutToPropagate(SyncFileItemVector &items)
         }
 
         SharedFlag sharedFlag = item->_remotePerm.hasPermission(RemotePermissions::IsShared) ? Shared : NotShared;
+        if (item->_instruction != CSyncEnums::CSYNC_INSTRUCTION_REMOVE) {
+            item->_discoveryResult.clear();
+        }
         if (item->_instruction != CSYNC_INSTRUCTION_NONE
             && item->_instruction != CSYNC_INSTRUCTION_UPDATE_METADATA
             && item->_instruction != CSYNC_INSTRUCTION_IGNORE