Virtual files deleted after moving to its parent virtual folder

[Athorus]

Hello,

On Windows with file explorer, when I try to move a virtual file from a virtual folder to its parent one, the file is moved, then few seconds later, when the sync is finished, the file is deleted (I can restore it to its original folder thank to the web page). If I move a virtual file to a virtual child folder, the file is moved properly.

If I move files available locally, all works as expected.

I’m using Nextcloud 21.0.1 on Debian Buster for the server part and Windows client 3.2.1.

Regards,
David.

[allexzander]

@Athorus

Is there anything special about that file? I tried locally with a random file, but, couldn't get to reproduce it. Could you do a short screen recording of how this happens for you? (no worries about personal files, you can just use a random non-sensitive file to demonstrate it). Thank you in advance.

[Athorus]

@allexzander

Here a little video showing the issue.

VirtualFileBug.zip

[Athorus]

Here what I get in nextcloud.log :

{"reqId":"T2yP3zg6dQj6DCaRNzXI","level":0,"time":"2021-05-12T13:35:30+00:00","remoteAddr":"xxx.xxx.xxx.xxx","user":"xxxxxx","app":"files_sharing","method":"PROPFIND","url":"/remote.php/dav/files/orus/Bug/folder/file.md","message":"/appinfo/app.php is deprecated, use \\OCP\\AppFramework\\Bootstrap\\IBootstrap on the application class instead.","userAgent":"Mozilla/5.0 (Windows) mirall/3.2.1stable-Win64 (build 20210428) (Nextcloud, windows-10.0.19042 ClientArchitecture: x86_64 OsArchitecture: x86_64)","version":"21.0.1.1"} {"reqId":"T2yP3zg6dQj6DCaRNzXI","level":0,"time":"2021-05-12T13:35:30+00:00","remoteAddr":"xxx.xxx.xxx.xxx","user":"xxxxxx","app":"webdav","method":"PROPFIND","url":"/remote.php/dav/files/orus/Bug/folder/file.md","message":{"Exception":"Sabre\\DAV\\Exception\\NotFound","Message":"File with name //Bug could not be located","Code":0,"Trace":[{"file":"/var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Tree.php","line":78,"function":"getChild","class":"OCA\\DAV\\Connector\\Sabre\\Directory","type":"->","args":["Bug"]},{"file":"/var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Tree.php","line":73,"function":"getNodeForPath","class":"Sabre\\DAV\\Tree","type":"->","args":["files/orus/Bug"]},{"file":"/var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Tree.php","line":73,"function":"getNodeForPath","class":"Sabre\\DAV\\Tree","type":"->","args":["files/orus/Bug/folder"]},{"file":"/var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":971,"function":"getNodeForPath","class":"Sabre\\DAV\\Tree","type":"->","args":["files/orus/Bug/folder/file.md"]},{"file":"/var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":1661,"function":"getPropertiesIteratorForPath","class":"Sabre\\DAV\\Server","type":"->","args":["files/orus/Bug/folder/file.md",["{DAV:}getetag"],0]},{"file":"/var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":1646,"function":"writeMultiStatus","class":"Sabre\\DAV\\Server","type":"->","args":[{"elementMap":[],"contextUri":"/remote.php/dav/","namespaceMap":{"DAV:":"d","http://sabredav.org/ns":"s","http://owncloud.org/ns":"oc","http://nextcloud.org/ns":"nc"},"classMap":[],"__class__":"Sabre\\Xml\\Writer"},{"__class__":"Generator"},false]},{"file":"/var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/CorePlugin.php","line":346,"function":"generateMultiStatus","class":"Sabre\\DAV\\Server","type":"->","args":[{"__class__":"Generator"},false]},{"file":"/var/www/html/nextcloud/3rdparty/sabre/event/lib/WildcardEmitterTrait.php","line":89,"function":"httpPropFind","class":"Sabre\\DAV\\CorePlugin","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":472,"function":"emit","class":"Sabre\\DAV\\Server","type":"->","args":["method:PROPFIND",[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]]},{"file":"/var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":253,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->","args":[{"__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/var/www/html/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php","line":321,"function":"start","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/nextcloud/apps/dav/lib/Server.php","line":332,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/nextcloud/apps/dav/appinfo/v2/remote.php","line":35,"function":"exec","class":"OCA\\DAV\\Server","type":"->","args":[]},{"file":"/var/www/html/nextcloud/remote.php","line":167,"args":["/var/www/html/nextcloud/apps/dav/appinfo/v2/remote.php"],"function":"require_once"}],"File":"/var/www/html/nextcloud/apps/dav/lib/Connector/Sabre/Directory.php","Line":234,"CustomMessage":"--"},"userAgent":"Mozilla/5.0 (Windows) mirall/3.2.1stable-Win64 (build 20210428) (Nextcloud, windows-10.0.19042 ClientArchitecture: x86_64 OsArchitecture: x86_64)","version":"21.0.1.1"} {"reqId":"YKwKW5iFg3AG8oyZQhxF","level":0,"time":"2021-05-12T13:35:30+00:00","remoteAddr":"xxx.xxx.xxx.xxx","user":"xxxxxx","app":"files_sharing","method":"DELETE","url":"/remote.php/dav/files/orus/Sauvegarde/Bug/folder/file.md","message":"/appinfo/app.php is deprecated, use \\OCP\\AppFramework\\Bootstrap\\IBootstrap on the application class instead.","userAgent":"Mozilla/5.0 (Windows) mirall/3.2.1stable-Win64 (build 20210428) (Nextcloud, windows-10.0.19042 ClientArchitecture: x86_64 OsArchitecture: x86_64)","version":"21.0.1.1"}

[allexzander]

@Athorus
Is external storage used on the server-side by any chance?

[Athorus]

@allexzander
What do you mean by "external storage" ? It is a lvm logical volume and all physical volumes are internal sata drives.

[Athorus]

root@serveur:/media# mount |grep next
/dev/mapper/vg-nextcloud on /media/nextcloud type ext4 (rw,relatime,commit=60)

root@serveur:/media# ll /media/nextcloud/
total 68
drwxr-xr-x 11 www-data www-data  4096 avril 24 14:59 appdata_ocvnwxpjzciu
-rw-r--r--  1 www-data www-data     0 avril 24 14:17 index.html
drwx------  2 root     root     16384 avril 24 14:06 lost+found
-rw-r-----  1 www-data www-data 40392 mai   12 15:47 nextcloud.log
drwxr-xr-x  5 www-data www-data  4096 avril 28 22:08 orus
drwxr-xr-x  5 www-data www-data  4096 avril 24 14:35 root

[Athorus]

root@serveur:/media# cat /var/www/html/nextcloud/config/config.php
<?php
$CONFIG = array (
  'instanceid' => 'ocvnwxpjzciu',
  'passwordsalt' => 'xxxxxxxxxxxxxxxxxxxxx',
  'secret' => 'xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx',
  'trusted_domains' =>
  array (
    0 => '192.168.0.1',
    1 => 'serveur',
    2 => 'xxxx.xxxx.xxx',
    3 => 'xxxx.xxxxr.xxxx',
  ),
  'loglevel' => 2,
  'filesystem_check_changes' => 0,
  'datadirectory' => '/media/nextcloud',
  'dbtype' => 'mysql',
  'version' => '21.0.1.1',
  'overwrite.cli.url' => 'http://192.168.0.1/nextcloud',
  'dbname' => 'nextcloud',
  'dbhost' => 'localhost',
  'dbport' => '',
  'dbtableprefix' => 'oc_',
  'mysql.utf8mb4' => true,
  'dbuser' => 'nextcloud',
  'dbpassword' => 'xxxxxxxxxx',
  'installed' => true,
  'memcache.local' => '\\OC\\Memcache\\APCu',
  'default_phone_region' => 'FR',
  'owerwriteprotocol' => 'https',
  'twofactor_enforced' => 'false',
  'twofactor_enforced_groups' =>
  array (
  ),
  'twofactor_enforced_excluded_groups' =>
  array (
  ),
  'maintenance' => false,
);

[Athorus]

One more comment, if I move the file with the webpage, everything is fine.

[AndyXheli]

I can confirm this. Same thing happens to me. First i created a folder then i moved a folder with in that i took all the file and moved them out of the folder and the client was showing syncing but the status never chnaged to show the cloud icon so then i moved them back to the original folder and all files are deleted.

[AndyXheli]

Also once i moved the files out of the test folder i cant even delete the folder looks like it locked it. I had to run the following commend into mysql DELETE FROM oc_file_locks WHERE 1; then i was able to deleted the folder. To me it seems like when yo have the vertual drive enabled and the files are not available locally and moved them around the client dose not properly do that because i dont see this issue happening when im using the regular file sync. I hope this helps

[allexzander]

@Athorus
Is external storage used on the server-side by any chance?

I mean external storage set via plug-in with the same name. But, looks like you're not using it.

[allexzander]

Weird, the same scenario doesn't bring any issues in my case.

Could you also share the logs archive created right after you've reproduced the issue? @Athorus

Client logs, I mean.

[AndyXheli]

where are the client logs located and id be happy to share them

[Athorus]

@allexzander
What are the logs archive ? Do you mean the nextcloud.log file or something else ?

I’ve seen logs can be activated on the client side, I’m working on it.

[Athorus]

@AndyXheli press F12 to activate clients logs after opening the nextcloud window.

[Athorus]

@AndyXheli restart your NextCloud client if you don’t see logs.

[Athorus]

Here the logs from the client

20210512_1747_owncloud.log.0.gz
20210512_1747_owncloud.log.1.gz
20210512_1747_owncloud.log.2.gz
20210512_1747_owncloud.log.3.gz

[AndyXheli]

Here are my logs

Logs.zip

[allexzander]

Thx. Looks like I see what went wrong:
Line 630: 2021-05-12 17:47:53:346 [ info sync.discovery ]: Can't rename because the etag has changed or the directory is gone "Bug/folder/file.md" Line 631: 2021-05-12 17:47:53:346 [ warning sync.discovery ]: Wiping virtual file without db entry for "Bug/file.md" Line 632: 2021-05-12 17:47:53:346 [ info sync.discovery ]: Discovered "Bug/file.md" CSyncEnums::CSYNC_INSTRUCTION_REMOVE OCC::SyncFileItem::Down CSyncEnums::ItemTypeVirtualFile

Probably related to #3270

[allexzander]

@AndyXheli Your logs seem very recent to me. I couldn't find lines similar to ones in my previous comment. Also, there is no CSYNC_INSTRUCTION_REMOVE in your logs. I guess, it's because they are just created and stored into a temporary folder, since you've used F12 and set that checkbox. Kindly uncheck it, and then, create a debug archive with your logs from the default location. You can do it via UI after unchecking the temporary folder checkbox and then restarting the app. Note: If the issue happened more than 24 hours ago, those logs are wiped already. In any case, I'd suggest you reproduce an issue again and then, create debug logs archive right away. Just to make sure we don't lose important lines and then I'll be able to check if your case is the same as the one that @Athorus encountered.

Also, please state the file name that was deleted.

[allexzander]

I'll be working on fix later this week. Thank you for reporting.

[AndyXheli]

@allexzander here you go let me know if you need anything else. the issue happened about 2 hours ago from now hopefully its in the logs i just uploaded :) thanks for all your help :)

NC Logs.zip

[AndyXheli]

Also the sync status never change back to offline when moving files from folder to another. Just stays at syncing.

Also wanted to add even if I exit out the nextcloud client the status still shows syncing

[claell]

@AndyXheli see #3440