Re-synchronizing (some) virtual files again, and again

[BurninLeo]

Expected behaviour

Virtual files shall be created, and then they shall not be sychonized unless there is a change on the server or client.

Actual behaviour

In general the (experimental) virtual files feature works great (see my other issue report for sophisticated praises 👍), but from time to time, I encounter the issue that files are synchronized over and over, again.

In one case, the files had been deleted from the server.

In a more recent case, many directories have been copied into the directory on PC 1 (no virtual files in use), and then on PC 2 (using the virtual files feature) most files worked fine. But a few hundret were synchronized every few seconds.

In both cases, on ythe virtual placeholders were on the PC, the complete files had not yet been downloaded. And the tab "sync protocol" said that the files were "ignored", but I was unable to see any reason for that. Also the file were not listed in the "not synchronized" tab.

The problem could be resolved by disabling the synchronization, deleting the folder contents, and re-adding the folder synchronization.

Steps to reproduce

I was not yet able to reproduce the problem reliably, sorry :(

Server configuration

Operating system: Ubuntu

Web server: nginx

Database: MySQL

PHP version: 7.4

ownCloud version: 10.3.2.2 (hacked to accept PHP 7.4)

Storage backend (external storage): filesystem

Client configuration

Client version: 2.7.4 (problem occured before and after the update)

Operating system: Windows 10

OS language: German

Logs

Sorry, did not enable logging before solving the issue. Will do when the issue returns.

[stylefieber]

I have the same issue (Windows). We try to use it at our company but occasionally this happens to us. I cannot tell HOW to reproduce it, but some colleagues tempt to use strange folder names. So it might be caused by folder names which are okay for mac and linux but not okay for windows (Just guessing).

The client then tries to sync the files every 2 seconds or so but in the protocol under "action" there you can just see the word "ignored".

Here is a part of the client log:

01-05 11:02:16:492 [ info sync.propagator ]: Starting CSyncEnums::CSYNC_INSTRUCTION_IGNORE propagation of "Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/VersicherungsJournal/4. Mediaplanung_Termine/201113_FINAL_xdf Reservierungen_Newsletter_MIT ANPASSUNGEN.xlsx" by OCC::PropagateIgnoreJob(0x4c16aa0)
01-05 11:02:16:492 [ info sync.propagator ]: Completed propagation of "Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/VersicherungsJournal/4. Mediaplanung_Termine/201113_FINAL_xdf Reservierungen_Newsletter_MIT ANPASSUNGEN.xlsx" by OCC::PropagateIgnoreJob(0x4c16aa0) with status OCC::SyncFileItem::FileIgnored
01-05 11:02:16:492 [ debug sync.statustracker ] [ OCC::SyncFileStatusTracker::slotItemCompleted ]: Item completed "Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/VersicherungsJournal/4. Mediaplanung_Termine/201113_FINAL_xdf Reservierungen_Newsletter_MIT ANPASSUNGEN.xlsx" OCC::SyncFileItem::FileIgnored CSyncEnums::CSYNC_INSTRUCTION_IGNORE
01-05 11:02:16:493 [ debug sync.localdiscoverytracker ] [ OCC::LocalDiscoveryTracker::slotItemCompleted ]: wiped successful item "Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/VersicherungsJournal/4. Mediaplanung_Termine/201113_FINAL_xdf Reservierungen_Newsletter_MIT ANPASSUNGEN.xlsx"
01-05 11:02:16:497 [ info gui.folderwatcher ]: Detected changes in paths: QSet("C:/Users/b.heart/ownCloud3/Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/VersicherungsJournal/4. Mediaplanung_Termine/201113_FINAL_xdf Reservierungen_Newsletter_MIT ANPASSUNGEN.xlsx")
01-05 11:02:16:497 [ debug sync.localdiscoverytracker ] [ OCC::LocalDiscoveryTracker::addTouchedPath ]: inserted touched "Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/VersicherungsJournal/4. Mediaplanung_Termine/201113_FINAL_xdf Reservierungen_Newsletter_MIT ANPASSUNGEN.xlsx"
01-05 11:02:16:497 [ debug sync.database.sql ] [ OCC::SqlQuery::bindValue ]: SQL bind 1 -3555695886359200705
01-05 11:02:16:497 [ debug sync.database.sql ] [ OCC::SqlQuery::exec ]: SQL exec "SELECT path, inode, modtime, type, md5, fileid, remotePerm, filesize, ignoredChildrenRemote, contentchecksumtype.name || ':' || contentChecksum FROM metadata LEFT JOIN checksumtype as contentchecksumtype ON metadata.contentChecksumTypeId == contentchecksumtype.id WHERE phash=?1"
01-05 11:02:16:497 [ debug sync.database.sql ] [ OCC::SqlQuery::bindValue ]: SQL bind 1 1
01-05 11:02:16:497 [ debug sync.database.sql ] [ OCC::SqlQuery::exec ]: SQL exec "SELECT path FROM selectivesync WHERE type=?1"
01-05 11:02:16:498 [ info sync.propagator ]: Starting CSyncEnums::CSYNC_INSTRUCTION_IGNORE propagation of "Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/VersicherungsJournal/4. Mediaplanung_Termine/201127_PRINT_Buchung_VersicherungsJournal.png" by OCC::PropagateIgnoreJob(0x4c16aa0)
01-05 11:02:16:498 [ info sync.propagator ]: Completed propagation of "Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/VersicherungsJournal/4. Mediaplanung_Termine/201127_PRINT_Buchung_VersicherungsJournal.png" by OCC::PropagateIgnoreJob(0x4c16aa0) with status OCC::SyncFileItem::FileIgnored
01-05 11:02:16:498 [ debug sync.statustracker ] [ OCC::SyncFileStatusTracker::slotItemCompleted ]: Item completed "Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/VersicherungsJournal/4. Mediaplanung_Termine/201127_PRINT_Buchung_VersicherungsJournal.png" OCC::SyncFileItem::FileIgnored CSyncEnums::CSYNC_INSTRUCTION_IGNORE
01-05 11:02:16:498 [ debug sync.localdiscoverytracker ] [ OCC::LocalDiscoveryTracker::slotItemCompleted ]: wiped successful item "Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/VersicherungsJournal/4. Mediaplanung_Termine/201127_PRINT_Buchung_VersicherungsJournal.png"
01-05 11:02:16:502 [ info gui.folderwatcher ]: Detected changes in paths: QSet("C:/Users/b.heart/ownCloud3/Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/VersicherungsJournal/4. Mediaplanung_Termine/201127_PRINT_Buchung_VersicherungsJournal.png")
01-05 11:02:16:502 [ debug sync.localdiscoverytracker ] [ OCC::LocalDiscoveryTracker::addTouchedPath ]: inserted touched "Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/VersicherungsJournal/4. Mediaplanung_Termine/201127_PRINT_Buchung_VersicherungsJournal.png"
01-05 11:02:16:502 [ debug sync.database.sql ] [ OCC::SqlQuery::bindValue ]: SQL bind 1 3002363283304642029
01-05 11:02:16:502 [ debug sync.database.sql ] [ OCC::SqlQuery::exec ]: SQL exec "SELECT path, inode, modtime, type, md5, fileid, remotePerm, filesize, ignoredChildrenRemote, contentchecksumtype.name || ':' || contentChecksum FROM metadata LEFT JOIN checksumtype as contentchecksumtype ON metadata.contentChecksumTypeId == contentchecksumtype.id WHERE phash=?1"
01-05 11:02:16:502 [ debug sync.database.sql ] [ OCC::SqlQuery::bindValue ]: SQL bind 1 1
01-05 11:02:16:503 [ debug sync.database.sql ] [ OCC::SqlQuery::exec ]: SQL exec "SELECT path FROM selectivesync WHERE type=?1"
01-05 11:02:16:503 [ info sync.propagator ]: Starting CSyncEnums::CSYNC_INSTRUCTION_IGNORE propagation of "Folder/MEDIA/2260_Media 2021/ANGEBOTE_AUFTR�GE_Mediadaten_Spezifikationen/Versicherungsmagazin/1. Mediadaten + Spezifikationen + Korrespondenz/Corporate_Content_Formate_HBG.pdf" by OCC::PropagateIgnoreJob(0x4c16aa0)

[TheOneRing]

Can you check your logs for "Virtual file without db" if you find lines like that... I'm about to fix the issue.

[stylefieber]

Can you check your logs for "Virtual file without db" if you find lines like that... I'm about to fix the issue.

Yes! I can found this string a lot in the logs. You really fixed it? Awesome, thank you. Can I test it with a nightly build or something?

[TheOneRing]

Should be ready tomorrow hopefully

[michaelstingl]

Can I test it with a nightly build or something?

@stylefieber fix should be included in todays daily builds:
https://download.owncloud.com/desktop/ownCloud/daily/2.7/win/?sort=time&order=desc

[stylefieber]

Can I test it with a nightly build or something?

@stylefieber fix should be included in todays daily builds:
https://download.owncloud.com/desktop/ownCloud/daily/2.7/win/?sort=time&order=desc

Thank you @michaelstingl , unfortunately I get 2 missing dll errors. Is this normal when using daily builds and I have to care about this dll files my self?

It's pcre2-16.dll and libpng16.dll

[michaelstingl]

No, sounds strange. What exact installer did you try?

[TheOneRing]

We accidentally merged a revert to our msi scripts... should be fixed now :)

[stylefieber]

Thank you :)
I can confirm that the bug is fixed. No sync-loop anymore.