Client: macos: make virtual does not make virtual

[jnweiger]

=== testpilotcloud-client 2.5.1 daily 20141025 (build 10754) pkg on MacOS 10.14 Mojave

connected to demo.owncloud.org with virtual files feature enabled.

The finder integration works after restarting finder.

Folder Photos contains squirrel.jpg
Right Click -> Replace File by virtual File

The log only says

10-25 20:47:13:648 [ info gui.socketapi ]:      Received SocketAPI message <-- "REPLACE_VIRTUAL_FILE:/Users/testy/testpilotcloud2/Photos/Squirrel.jpg" from SocketApiSocket(0x7fefb793ced0)

and file Squirrel.jpg gets renamed to Squirrel.jpg.testpilotcloud_virtual but its content remains intact.

A manual mkdir Photos/foo
triggers the remaining replace action: The file Squirrel.jpg.testpilotcloud_virtual is now 1 bytes.

The log now says

10-25 20:50:59:901 [ info sync.engine ]:        #### Post-Reconcile end ####################################################  193 ms
10-25 20:50:59:901 [ info sync.propagator ]:    Starting INSTRUCTION_NEW propagation of "Photos/foo" by OCC::PropagateRemoteMkdir(0x7fefb7885530)
10-25 20:50:59:901 [ info sync.accessmanager ]: 6 "MKCOL" "https://demo.owncloud.org/remote.php/dav/files/demo/Photos/foo" has X-Request-ID "5f43dfe7-23c0-4583-b238-7544461ed821"
10-25 20:50:59:902 [ info sync.networkjob ]:    OCC::MkColJob created for "https://demo.owncloud.org" + "/Photos/foo" "OCC::PropagateRemoteMkdir"
10-25 20:50:59:902 [ info gui.folder ]: #### Propagation start ####################################################
10-25 20:50:59:903 [ info gui.application ]:    Sync state changed for folder  "https://demo.owncloud.org/remote.php/dav/files/demo/" :  "Sync Running"
10-25 20:50:59:904 [ info sync.propagator ]:    Starting INSTRUCTION_IGNORE propagation of "System Volume Information" by OCC::PropagateIgnoreJob(0x7fefb78d0960)
10-25 20:50:59:904 [ warning sync.propagator ]: Could not complete propagation of "System Volume Information" by OCC::PropagateIgnoreJob(0x7fefb78d0960) with status 6 and error: "File is listed on the ignore list."
10-25 20:50:59:904 [ info gui.socketapi ]:      Sending SocketAPI message --> "STATUS:IGNORE:/Users/testy/testpilotcloud2/System Volume Information" to SocketApiSocket(0x7fefb793ced0)
10-25 20:50:59:907 [ info sync.propagator ]:    Starting INSTRUCTION_NEW propagation of "Photos/Squirrel.jpg.testpilotcloud_virtual" by OCC::PropagateDownloadFile(0x7fefb559a260)
10-25 20:50:59:907 [ info sync.database ]:      Updating file record for path: "Photos/Squirrel.jpg.testpilotcloud_virtual" inode: 12885653753 modtime: 1540490539 type: 4 etag: "f71e80a50b3565fe77bbf52e8ca4bae6" fileId: "00000017o
cevn3f7my3m" remotePerm: "WDNVR" fileSize: 233724 checksum: "SHA1:ed266b89065e74483248da7ff71cb80e3cca40a5"
10-25 20:50:59:908 [ info sync.propagator ]:    Completed propagation of "Photos/Squirrel.jpg.testpilotcloud_virtual" by OCC::PropagateDownloadFile(0x7fefb559a260) with status 4
10-25 20:50:59:908 [ info gui.socketapi ]:      Sending SocketAPI message --> "STATUS:OK:/Users/testy/testpilotcloud2/Photos/Squirrel.jpg.testpilotcloud_virtual" to SocketApiSocket(0x7fefb793ced0)
10-25 20:51:00:282 [ info sync.networkjob.mkcol ]:      MKCOL of QUrl("https://demo.owncloud.org/remote.php/dav/files/demo/Photos/foo") FINISHED WITH STATUS "OK"
10-25 20:51:00:283 [ info sync.database ]:      Updating file record for path: "Photos/foo" inode: 12885653750 modtime: 1540493457 type: 2 etag: "" fileId: "00000043ocevn3f7my3m" remotePerm: "" fileSize: 64 checksum: ""
10-25 20:51:00:283 [ info sync.propagator ]:    Completed propagation of "Photos/foo" by OCC::PropagateRemoteMkdir(0x7fefb7885530) with status 4
10-25 20:51:00:284 [ info gui.socketapi ]:      Sending SocketAPI message --> "STATUS:OK:/Users/testy/testpilotcloud2/Photos/foo" to SocketApiSocket(0x7fefb793ced0)
10-25 20:51:00:285 [ info gui.socketapi ]:      Sending SocketAPI message --> "STATUS:OK:/Users/testy/testpilotcloud2/Photos" to SocketApiSocket(0x7fefb793ced0)
10-25 20:51:00:288 [ info sync.database ]:      Updating file record for path: "Photos/foo" inode: 12885653750 modtime: 1540493457 type: 2 etag: "" fileId: "00000043ocevn3f7my3m" remotePerm: "" fileSize: 64 checksum: ""
10-25 20:51:00:289 [ info sync.database ]:      Closing DB "/Users/testy/testpilotcloud2/._sync_f3502dd50375.db"
10-25 20:51:00:297 [ info sync.engine ]:        CSync run took  588 ms

[ckamm]

Yes, the dehydration is only signaled by the rename: a sync is necessary to actually make the change. The socketapi action should schedule a sync run on the folder.

[ckamm]

@jnweiger I can't reproduce the problem. For me, it gets renamed and the folder gets scheduled - the code looks fine too. Is there something specific I can do to reproduce?

[jnweiger]

@michaelstingl do you have a different reproducer? Am I missing something that is special in our setup?

[nielsoo]

I have the same, client v2.5.1 build 10819 on macos mojave, first I copy a new file to the synced folder, let it sync, and then when I issue a 'make virtual', the file is being renamed to it's orignal name + .owncloud but the contents and size remain the original, and even force sync doesn't help..

the file only gets correctly replaced by it's 1 byte virtual companion as soon as I quit and "restart" the owncloud client.

[ogoffart]

Ah, the problem is that we do not mark the files as touched locally.
I think the OSX file system watcher does not report changes done by our own process, which is the case here. (@guruz will correct me if i'm wrong)

https://github.com/owncloud/client/pull/6882 should fix it in 2.6, but i can try to fix it in 2.5

even force sync doesn't help..

Because that does not force the local discovery either, the CTRL+F6 shortcut should help.
Otherwise you have to wait one hours. and it should also do it.

[ogoffart]

The fix should be there: https://github.com/owncloud/client/pull/6902
I did not test on mac since i don't have one.

@nielsoo : thanks for your comment, this is how i figured what the problem is.

[lazawan]

tested on macos 10.14

@ogoffart i have just tested the 2.5.2 client on macos 10.4
virtual-files-function works fine but now there is problem with folders
please see the issue #6977

[ckamm]

Continued in follow up ticket