add log statements for each new assert about invalid modified time

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

4 files changed, 63 insertions, 0 deletions

diff --git a/src/libsync/propagatedownload.cpp b/src/libsync/propagatedownload.cpp
index b06a4d115..443ebfdac 100644
--- a/src/libsync/propagatedownload.cpp
+++ b/src/libsync/propagatedownload.cpp
@@ -565,6 +565,9 @@ void PropagateDownloadFile::startAfterIsEncryptedIsChecked()
             || checksum_header.startsWith("MD5:");
     };
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateDownload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     if (_item->_instruction == CSYNC_INSTRUCTION_CONFLICT
         && _item->_size == _item->_previousSize
         && !_item->_checksumHeader.isEmpty()
@@ -594,6 +597,9 @@ void PropagateDownloadFile::conflictChecksumComputed(const QByteArray &checksumT
         // and local mtimes end up identical
         auto fn = propagator()->fullLocalPath(_item->_file);
         Q_ASSERT(_item->_modtime > 0);
+        if (_item->_modtime <= 0) {
+            qCWarning(lcPropagateDownload()) << "invalid modified time" << _item->_file << _item->_modtime;
+        }
         if (_item->_modtime != _item->_previousModtime) {
             Q_ASSERT(_item->_modtime > 0);
             FileSystem::setModTime(fn, _item->_modtime);
@@ -601,6 +607,9 @@ void PropagateDownloadFile::conflictChecksumComputed(const QByteArray &checksumT
         }
         _item->_modtime = FileSystem::getModTime(fn);
         Q_ASSERT(_item->_modtime > 0);
+        if (_item->_modtime <= 0) {
+            qCWarning(lcPropagateDownload()) << "invalid modified time" << _item->_file << _item->_modtime;
+        }
         updateMetadata(/*isConflict=*/false);
         return;
     }
@@ -825,6 +834,9 @@ void PropagateDownloadFile::slotGetFinished()
         // so make sure we have the up-to-date time
         _item->_modtime = job->lastModified();
         Q_ASSERT(_item->_modtime > 0);
+        if (_item->_modtime <= 0) {
+            qCWarning(lcPropagateDownload()) << "invalid modified time" << _item->_file << _item->_modtime;
+        }
     }
 
     _tmpFile.close();
@@ -1068,6 +1080,9 @@ void PropagateDownloadFile::downloadFinished()
         return;
     }
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateDownload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     FileSystem::setModTime(_tmpFile.fileName(), _item->_modtime);
     // We need to fetch the time again because some file systems such as FAT have worse than a second
     // Accuracy, and we really need the time from the file system. (#3103)
@@ -1077,6 +1092,9 @@ void PropagateDownloadFile::downloadFinished()
         return;
     }
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateDownload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
 
     bool previousFileExists = FileSystem::fileExists(fn);
     if (previousFileExists) {
diff --git a/src/libsync/propagateupload.cpp b/src/libsync/propagateupload.cpp
index b86f737e5..c18fe7069 100644
--- a/src/libsync/propagateupload.cpp
+++ b/src/libsync/propagateupload.cpp
@@ -211,6 +211,9 @@ void PropagateUploadFileCommon::start()
         _item->_file = _item->_renameTarget;
         _item->_modtime = FileSystem::getModTime(newFilePathAbsolute);
         Q_ASSERT(_item->_modtime > 0);
+        if (_item->_modtime <= 0) {
+            qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+        }
     }
 
     SyncJournalFileRecord parentRec;
@@ -314,6 +317,9 @@ void PropagateUploadFileCommon::slotComputeContentChecksum()
     // probably temporary one.
     _item->_modtime = FileSystem::getModTime(filePath);
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
 
     const QByteArray checksumType = propagator()->account()->capabilities().preferredUploadChecksumType();
 
@@ -390,6 +396,9 @@ void PropagateUploadFileCommon::slotStartUpload(const QByteArray &transmissionCh
             SyncFileItem::SoftError, tr("Local file has invalid modified time. Do not upload to the server."));
     }
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     time_t prevModtime = _item->_modtime; // the _item value was set in PropagateUploadFile::start()
     // but a potential checksum calculation could have taken some time during which the file could
     // have been changed again, so better check again here.
@@ -400,6 +409,9 @@ void PropagateUploadFileCommon::slotStartUpload(const QByteArray &transmissionCh
             SyncFileItem::SoftError, tr("Local file has invalid modified time. Do not upload to the server."));
     }
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     if (prevModtime != _item->_modtime) {
         propagator()->_anotherSyncNeeded = true;
         qDebug() << "prevModtime" << prevModtime << "Curr" << _item->_modtime;
@@ -598,6 +610,9 @@ void PropagateUploadFileCommon::startPollJob(const QString &path)
     info._url = path;
     info._modtime = _item->_modtime;
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     info._fileSize = _item->_size;
     propagator()->_journal->setPollInfo(info);
     propagator()->_journal->commit("add poll info");
@@ -721,6 +736,9 @@ QMap<QByteArray, QByteArray> PropagateUploadFileCommon::headers()
     QMap<QByteArray, QByteArray> headers;
     headers[QByteArrayLiteral("Content-Type")] = QByteArrayLiteral("application/octet-stream");
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     headers[QByteArrayLiteral("X-OC-Mtime")] = QByteArray::number(qint64(_item->_modtime));
     if (qEnvironmentVariableIntValue("OWNCLOUD_LAZYOPS"))
         headers[QByteArrayLiteral("OC-LazyOps")] = QByteArrayLiteral("true");
diff --git a/src/libsync/propagateuploadng.cpp b/src/libsync/propagateuploadng.cpp
index 674298cbf..8e14fb69c 100644
--- a/src/libsync/propagateuploadng.cpp
+++ b/src/libsync/propagateuploadng.cpp
@@ -84,6 +84,9 @@ void PropagateUploadFileNG::doStartUpload()
 
     const SyncJournalDb::UploadInfo progressInfo = propagator()->_journal->getUploadInfo(_item->_file);
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     if (progressInfo._valid && progressInfo.isChunked() && progressInfo._modtime == _item->_modtime
             && progressInfo._size == _item->_size) {
         _transferId = progressInfo._transferid;
@@ -231,6 +234,9 @@ void PropagateUploadFileNG::startNewUpload()
 {
     ASSERT(propagator()->_activeJobList.count(this) == 1);
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     _transferId = uint(Utility::rand() ^ uint(_item->_modtime) ^ (uint(_fileToUpload._size) << 16) ^ qHash(_fileToUpload._file));
     _sent = 0;
     _currentChunk = 0;
@@ -241,6 +247,9 @@ void PropagateUploadFileNG::startNewUpload()
     pi._valid = true;
     pi._transferid = _transferId;
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     pi._modtime = _item->_modtime;
     pi._contentChecksum = _item->_checksumHeader;
     pi._size = _item->_size;
@@ -427,6 +436,9 @@ void PropagateUploadFileNG::slotPutFinished()
 
     // Check whether the file changed since discovery - this acts on the original file.
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     if (!FileSystem::verifyFileUnchanged(fullFilePath, _item->_size, _item->_modtime)) {
         propagator()->_anotherSyncNeeded = true;
         if (!_finished) {
diff --git a/src/libsync/propagateuploadv1.cpp b/src/libsync/propagateuploadv1.cpp
index 04683add0..f4eb84caa 100644
--- a/src/libsync/propagateuploadv1.cpp
+++ b/src/libsync/propagateuploadv1.cpp
@@ -40,11 +40,17 @@ void PropagateUploadFileV1::doStartUpload()
     _chunkCount = int(std::ceil(_fileToUpload._size / double(chunkSize())));
     _startChunk = 0;
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     _transferId = uint(Utility::rand()) ^ uint(_item->_modtime) ^ (uint(_fileToUpload._size) << 16);
 
     const SyncJournalDb::UploadInfo progressInfo = propagator()->_journal->getUploadInfo(_item->_file);
 
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     if (progressInfo._valid && progressInfo.isChunked() && progressInfo._modtime == _item->_modtime && progressInfo._size == _item->_size
         && (progressInfo._contentChecksum == _item->_checksumHeader || progressInfo._contentChecksum.isEmpty() || _item->_checksumHeader.isEmpty())) {
         _startChunk = progressInfo._chunk;
@@ -59,6 +65,9 @@ void PropagateUploadFileV1::doStartUpload()
         pi._chunk = 0;
         pi._transferid = 0; // We set a null transfer id because it is not chunked.
         Q_ASSERT(_item->_modtime > 0);
+        if (_item->_modtime <= 0) {
+            qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+        }
         pi._modtime = _item->_modtime;
         pi._errorCount = 0;
         pi._contentChecksum = _item->_checksumHeader;
@@ -249,6 +258,9 @@ void PropagateUploadFileV1::slotPutFinished()
 
     // Check whether the file changed since discovery. the file check here is the original and not the temprary.
     Q_ASSERT(_item->_modtime > 0);
+    if (_item->_modtime <= 0) {
+        qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+    }
     if (!FileSystem::verifyFileUnchanged(fullFilePath, _item->_size, _item->_modtime)) {
         propagator()->_anotherSyncNeeded = true;
         if (!_finished) {
@@ -288,6 +300,9 @@ void PropagateUploadFileV1::slotPutFinished()
         pi._chunk = (currentChunk + _startChunk + 1) % _chunkCount; // next chunk to start with
         pi._transferid = _transferId;
         Q_ASSERT(_item->_modtime > 0);
+        if (_item->_modtime <= 0) {
+            qCWarning(lcPropagateUpload()) << "invalid modified time" << _item->_file << _item->_modtime;
+        }
         pi._modtime = _item->_modtime;
         pi._errorCount = 0; // successful chunk upload resets
         pi._contentChecksum = _item->_checksumHeader;