[QA] WinVFS: opening a file during a long sync run causes Operation Cancelled and/or explorer Not Responding

[jnweiger]

Pre-submission Checks

• I checked for similar issues, but could not find any. I also checked the closed issues. I could not contribute additional information to any existing issue.
• I will take the time to fill in all the required fields. I know that the bug report may be dismissed otherwise due to lack of information.

Describe the QA issue

Seen with win10_21H1 client 2.10.1 connected to cloud.damken.com on a small sync root folder only (ca 300 MB of files)

• The client takes some time to crawl the folder.

  • This is okayish, when the folder is small. (see e.g. Selective Sync and VFS should not be exclusive #7320)

• After the crawl is done, Windows explorer shows a cloud status icon for all subfolders and files.

• Select all folders and files, and right click 'Always keep on this device'

• All status icons change to blue circling arrows.

  • The folder the mouse was on, is synced down first, and the cloud icon changes to a green checkmark.
  • other folders and files have the circling arrows for some longer time as downloads continue.

• Click open a file that still has the circling arrows.
  -> The running download is aborted with red error messages in the client. (Still visible in the screenshot below)
  -> A download progress window appears

• Without waiting for the file to actually open, click open another file that has circling arrows.
  -> Now the explorer window becomes gray and the title bar changes to '...(Not Responding)'
  

• After a while, the situation resolves by itself, The requested file is opened, and the sync completes.

Steps to reproduce the issue

.

Screenshots

.

Expected behavior

No response

Actual behavior

No response

[jnweiger]

Retested on a Win11 VM:

Select all, and choose keep locally as above.
While the client is busy, click open one file that still has the circling arrow icon
-> an error occurs:

On another attempt, the file 'hood-bend.svg' apparently started to load, but windows never succeeded:

[jnweiger]

Re-testing with owncloud-2.10.2-daily20220630.7904.x68.GPO.msi on win10_21H1 connected to cloud.damken.com

• select all, trigger mass download via 'make available locally
• try open one file that still has the circling icon -> operation cancelled
• after minute the client recovers, the file opens.
• try another file, that still has the circling arrows icon ->
  
• wait a few minutes. Both, client and explorer recover, the file opens

-> Behaviour is unchanged. sorry.

Explorer on Win11 also goes into not responding state, and then recovers a minute later. (Not exaclty the same as before. Before win11 has some error messages)

[TheOneRing]

We receive the callback from Windows in a thread pool but then jump to the main thread using QMetaObject::invokeMethod.
If we have flooded the client already with events, as we do during an initial vfs sync, it can take a while till the invoke is executed.

The only solution to this issue might be to invest in performance for example #7973

[TheOneRing]

Related: https://github.com/KDAB/KDToolBox/tree/master/qt/ui_watchdog

[jnweiger]

Re-tested on a native Win11 system with 2.10.2daily20220704 build 7921

• select all, trigger mass download via 'make available locally'
• one file that still has the circling icon, click 'make availble locally' -> the client shows operation cancelled
• both client and explorer show '...(Not responding)' for ca 1 minute.
• After both recover, the explorer shows a mixed state of cloud, cricling arrows, and green checkmark status icons.
  

---

• the files with circling arrows remains
  • even when oher files and folders are synced up/down happily.
  • force sync or rename of the file, or restart of the client does not help
  • move into subfolder simply also adds the circling arrows icon to that subfolder.
  • click 'make available locally' again on that file -> client and browser freeze again for 1 minute, circling arows are still shown on that file.
  • click open the file freezes the explorer, then shows the well known 0x800704C8 error.
  • rename of the file on the server causes the client to show a (working) file with the new name. The broken entry remains.

The system cannot access the affected file any more.

Client log generated while trying to recover that file
20220704_1716_owncloud.log.0.zip

[TheOneRing]

@dragotin any idea why we emit two signals within 3 lines of codde
https://github.com/owncloud/client/blob/2.10/src/libsync/syncengine.cpp#L455

[TheOneRing]

@dragotin any idea why we emit two signals within 3 lines of codde https://github.com/owncloud/client/blob/2.10/src/libsync/syncengine.cpp#L455

Its not used but only emitted once so it should not hurt

[dragotin]

still a bit insane

[TheOneRing]

Removed in #9863

[TheOneRing]

@jnweiger can you give https://jenkins.int.owncloud.com/job/client-trigger-drone/1022/ or a later build a try?
Thx!

[jnweiger]

Re-testing with ownCloud-2.10.2-daily20220706.7950.x64.GPO.msi ab8f9e

• select all, trigger mass download via 'make available locally'
• one file that still has the circling icon, click 'make availble locally' (no cancelled operations in the client, this time)
• both client and explorer show '...(Not responding)' for ca 1 minute. - Okayish
• After both recover, the explorer shows a mixed state of cloud, cricling arrows, and green checkmark status icons.
• A file with permanent circling arrows is also found, but clicking 'free up space', / 'make available locally' resolves the state. - OK

I could provoke a few windows error popups by clicking wildly:

---

but in any case, the sync resumed just fine after 'Abbrechen' . Okayish.
Note, that the error 0x899704C8 was not reproducable any more. It's now 'only' a timeout 0x800701AA.

All this works the same, with the sync root folder that was created with a previous client, as well as a fresh sync root folder.

@TheOneRing I think, you fixed something! 📣

[TheOneRing]

I reduced the CPU load. A good idea in any case.
Still there is a lot we can make better, however not in a minor release.

[TheOneRing]

Thx for testing

[jnweiger]

I can confirm the reduced CPU load.
Before: When switching an entire tree of 400 files from physical to 'free up space' I was able to click on a few files while they had circling arrows for a few seconds.
Now: Everything switches to cloud status icon almost immediately.

[cdamken]

Wow, this looks like a huge improvement!