Merge pull request #7028 from nextcloud/feature/permanentDeleteLog

create a permanent log of delete actions

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 {

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()

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();

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);
     }
 }
 

src/libsync/discovery.cpp

@@ -528,29 +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 << '/';
-
-    if (localEntry.isValid()
-        && !serverEntry.isValid()
-        && !dbEntry.isValid()
-        && localEntry.modtime < _lastSyncTimestamp) {
-        qCWarning(lcDisco) << "File" << path._original << "was modified before the last sync run and is not in the sync journal and server";
-    }
+
+    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 (_discoveryData->isRenamed(path._original)) {
         qCDebug(lcDisco) << "Ignoring renamed";
@@ -562,6 +559,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;

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

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 @@ class OWNCLOUDSYNC_EXPORT Logger : public QObject
     QString logFile() const;
     void setLogFile(const QString &name);
 
+    void setPermanentDeleteLogFile(const QString &name);
+
     void setLogExpire(int expire);
 
     QString logDir() const;
@@ -88,28 +96,31 @@ class OWNCLOUDSYNC_EXPORT Logger : public QObject
     void guiMessage(const QString &, const QString &);
 
 public slots:
-    void enterNextLogFile();
+    void enterNextLogFile(const QString &baseFileName, OCC::Logger::LogType type);
 
 private:
     Logger(QObject *parent = nullptr);
     ~Logger() override;
 
     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

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;

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;
 

src/libsync/syncfileitem.h

@@ -339,6 +339,8 @@ class OWNCLOUDSYNC_EXPORT SyncFileItem
 
     bool _isAnyInvalidCharChild = false;
     bool _isAnyCaseClashChild = false;
+
+    QString _discoveryResult;
 };
 
 inline bool operator<(const SyncFileItemPtr &item1, const SyncFileItemPtr &item2)

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