"Make always available" locally does not persist across client restarts #7779

georgebarnett · 2020-02-29T01:35:25Z

Expected behaviour

When I choose "Make always available locally", the client should keep the files/folders I have selected available on the local disk.

Actual behaviour

When the client is restarted, all files in the tree are replaced with their virtual equivalents, meaning the locally stored copy is removed. This is particularly an issue with scripts where the client additionally loses +x permissions (#3199 - Also occurs on Mac OSX).

It would appear, based on the log that on startup, the sync check itself is kicking off a sync which then causes the file to be made virtual.

Steps to reproduce

Find a file or folder that is virtual (i.e. filename.owncloud)
Right click and select the menu item make the folder available locally
Files will download and be available locally
Restart the desktop client
Watch in sadness as the client scans the tree and sweeps your files into the virtual file bitbucket.

Server configuration

Operating system:

Web server:

Database:

PHP version:

ownCloud version:

Storage backend (external storage):

Client configuration

Client version:
2.6.1 (Build 13096)

Operating system:
OSX 10.15.3
Darwin Juliet 19.3.0 Darwin Kernel Version 19.3.0: Thu Jan 9 20:58:23 PST 2020; root:xnu-6153.81.5~1/RELEASE_X86_64 x86_64 i386 MacBook9,1 Darwin

OS language: English Australia
Installation path of client: /Applications

Logs

Please use Gist (https://gist.github.com/) or a similar code paster for longer
logs.

Template for output < 10 lines

Client logfile:

02-29 12:22:43:592 [ info sync.discovery ]: Processing "00-09 Meta/01 Environment/01.03 Bitbar Scripts/nightscout.1m.sh" | valid: true/true/db | mtime: 1579297964/1579297964/0 | size: 2695/2695/0 | etag: "c1dfe8e5ae8cf48aeca1b8329bae6ad3"//"" | checksum: "SHA1:fade5ad6b3454abca3ab87ceac75c646b14cba7a"//"" | perm: WDNVR// | fileid: "00228872ocv1qho3c66u"//"" | inode: 8631644248/8631644248/ | type: 6/0/0
02-29 12:22:43:592 [ info sync.discovery ]: Discovered "00-09 Meta/01 Environment/01.03 Bitbar Scripts/nightscout.1m.sh" INSTRUCTION_SYNC OCC::SyncFileItem::Down 6
02-29 12:23:02:533 [ info gui.socketapi ]:  Sending SocketAPI message --> "STATUS:SYNC:/Users/xx/ownCloud/00-09 Meta/01 Environment/01.03 Bitbar Scripts/nightscout.1m.sh.owncloud" to SocketApiSocket(0x7fd21e04dd60)
02-29 12:23:02:535 [ info gui.socketapi ]:  Sending SocketAPI message --> "STATUS:SYNC:/Users/xx/ownCloud/00-09 Meta/01 Environment/01.03 Bitbar Scripts" to SocketApiSocket(0x7fd21e04dd60)
02-29 12:23:02:536 [ info gui.socketapi ]:  Sending SocketAPI message --> "STATUS:SYNC:/Users/xx/ownCloud/00-09 Meta/01 Environment" to SocketApiSocket(0x7fd21e04dd60)
02-29 12:23:02:588 [ info gui.socketapi ]:  Sending SocketAPI message --> "STATUS:IGNORE:/Users/xx/ownCloud/00-09 Meta/.DS_Store" to SocketApiSocket(0x7fd21e04dd60)
02-29 12:23:02:589 [ info gui.socketapi ]:  Sending SocketAPI message --> "STATUS:IGNORE:/Users/xx/ownCloud/00-09 Meta/01 Environment/.DS_Store" to SocketApiSocket(0x7fd21e04dd60)
02-29 12:23:02:686 [ info sync.engine ]:  #### Reconcile (aboutToPropagate OK) ####################################################  19209 ms
02-29 12:23:02:687 [ info sync.engine ]:  #### Post-Reconcile end ####################################################  19211 ms
02-29 12:23:02:688 [ info gui.folder ]: #### Propagation start ####################################################
02-29 12:23:02:688 [ info gui.application ]:  Sync state changed for folder  "https://xxx/owncloud/remote.php/dav/files/xx/" :  "Sync Running"
02-29 12:23:02:692 [ info sync.propagator ]:  Starting INSTRUCTION_SYNC propagation of "00-09 Meta/01 Environment/01.03 Bitbar Scripts/nightscout.1m.sh.owncloud" by OCC::PropagateDownloadFile(0x7fd21d336400)
02-29 12:23:02:694 [ info sync.database ]:  Updating file record for path: "00-09 Meta/01 Environment/01.03 Bitbar Scripts/nightscout.1m.sh.owncloud" inode: 8631646727 modtime: 1579297964 type: 4 etag: "c1dfe8e5ae8cf48aeca1b8329bae6ad3" fileId: "00228872ocv1qho3c66u" remotePerm: "WDNVR" fileSize: 2695 checksum: "SHA1:fade5ad6b3454abca3ab87ceac75c646b14cba7a"
02-29 12:23:02:694 [ info sync.propagator ]:  Completed propagation of "00-09 Meta/01 Environment/01.03 Bitbar Scripts/nightscout.1m.sh.owncloud" by OCC::PropagateDownloadFile(0x7fd21d336400) with status OCC::SyncFileItem::Success
02-29 12:23:02:694 [ info gui.socketapi ]:  Sending SocketAPI message --> "STATUS:OK:/Users/xx/ownCloud/00-09 Meta/01 Environment/01.03 Bitbar Scripts/nightscout.1m.sh.owncloud" to SocketApiSocket(0x7fd21e04dd60)
02-29 12:23:02:695 [ info gui.socketapi ]:  Sending SocketAPI message --> "STATUS:OK:/Users/xx/ownCloud/00-09 Meta/01 Environment/01.03 Bitbar Scripts" to SocketApiSocket(0x7fd21e04dd60)
02-29 12:23:02:696 [ info gui.socketapi ]:  Sending SocketAPI message --> "STATUS:OK:/Users/xx/ownCloud/00-09 Meta/01 Environment" to SocketApiSocket(0x7fd21e04dd60)

Web server error log:
Server logfile: ownCloud log (data/owncloud.log):

The text was updated successfully, but these errors were encountered:

michaelstingl · 2020-03-02T11:22:02Z

@ogoffart Could you check if this is an easy fix?

ogoffart · 2020-03-25T12:19:05Z

I could not reproduce the problem on Linux following the step to reproduce.

The pinning state is stored on the DB and this is respected.

Maybe there are other errors in the sync that causes this problem?

s1mm0n · 2020-05-12T08:25:14Z

We can reproduce this on macOS 10.15.4 on 170 Clients ;)

Do you need additional Informations we could provide? What do you need?

michaelstingl · 2020-05-12T08:55:36Z

We can reproduce this on macOS 10.15.4 on 170 Clients ;)

@s1mm0n what is the exact client version you are using? Detailed steps to reproduce would help. Reliable way to trigger this?

s1mm0n · 2020-05-12T09:00:41Z

Hi,

Version 2.6.1 (build 13096)
MacOS 10.15.4 (19E287)

@georgebarnett has the perfect description on this bug. See "Steps to reproduce"

A simple restart on the Client will replace all Files which are set to "always local" into a virtual ".owncloud" file.

michaelstingl · 2020-05-12T09:13:49Z

A simple restart on the Client will replace all Files which are set to "always local" into a virtual ".owncloud" file.

thanks, I'll check again

michaelstingl · 2020-06-22T10:30:37Z

Seems macOS behaviour is regression from 2.5.4 to 2.6.x.

TheOneRing · 2020-07-13T12:55:30Z

I can't reproduce it too.
Even if I kill the client during the make available sync and start it again it continues to download the files.

TheOneRing · 2020-07-13T12:59:45Z

@s1mm0n could you pls report the output of the --version command?

ownCloud version 2.6.3 (build 13765)
Git revision f28dd972e941986edc3e1803a25cf067f520b7e3
Using Qt 5.12.7, built against Qt 5.12.7
Using 'OpenSSL 1.1.1g  21 Apr 2020'

s1mm0n · 2020-07-13T13:15:19Z

Hi, we can reproduce this on every of our 170 Macs.

Version 2.6.3 (build 13765) 
Gebaut aus der GIT-Revision f28dd9 am Jun 12 2020, 15:57:18; verwendet Qt 5.12.7, OpenSSL 1.1.1g 21 Apr 2020

macOS Catalina 10.15.4 (19E287)

i have attached a small video showing the Problem. A simple restart of the Client and all files in the ownCloud folder will be replaced by a virtual .owncloud File.

Owncloud VFS Demo.mov.zip

TheOneRing · 2020-07-14T09:00:34Z

I do believe you, that definitely should not happen.....
Would it be possible for you to share two logs with me, the one where the file is downloaded and the one where it is reverted to a placeholder? Either here or hvonreth@owncloud.com

s1mm0n · 2020-07-17T07:22:25Z

Hello,

i think this is the log part which is relevant, but i'll send you the full log via E-Mail too.

The File used for this Demo is "meeting.ics"

07-17 09:14:28:676 [ info sync.discovery ]: Processing "ownCloud Demo" | valid: true/true/true | mtime: 1574673567/1594970026/1574673567 | size: 0/96/0 | etag: "5ddb9c9f9685d"//"5ddb9c9f9685d" | checksum: ""//"" | perm: DNVCKRS//DNVCKRS | fileid: "07765455oc9ekchhkcz3"//"07765455oc9ekchhkcz3" | inode: 10108082/10108082/ | type: CSyncEnums::ItemTypeDirectory/CSyncEnums::ItemTypeDirectory/CSyncEnums::ItemTypeDirectory
07-17 09:14:28:676 [ info sync.discovery ]: Discovered "ownCloud Demo" INSTRUCTION_NONE OCC::SyncFileItem::None CSyncEnums::ItemTypeDirectory
07-17 09:14:28:676 [ debug sync.database.sql ] [ OCC::SqlQuery::bindValue ]: SQL bind 1 QVariant(QByteArray, "ownCloud Demo")
07-17 09:14:28:676 [ debug sync.database.sql ] [ OCC::SqlQuery::exec ]: SQL exec "SELECT pinState FROM flags WHERE ((?1 == path OR (?1 > (path||'/') AND ?1 < (path||'0'))) OR path == '') AND pinState is not null AND pinState != 0 ORDER BY length(path) DESC LIMIT 1;"
07-17 09:14:28:676 [ debug sync.networkjob ] [ OCC::AbstractNetworkJob::slotFinished ]: Network job OCC::LsColJob finished for "/"
07-17 09:14:28:676 [ info sync.discovery ]: STARTING "ownCloud Demo" OCC::ProcessDirectoryJob::ParentNotChanged "ownCloud Demo" OCC::ProcessDirectoryJob::NormalQuery
07-17 09:14:28:677 [ debug sync.database.sql ] [ OCC::SqlQuery::bindValue ]: SQL bind 1 QVariant(qlonglong, 5795774987267436216)
07-17 09:14:28:677 [ 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 parent_hash(path) = ?1 ORDER BY path||'/' ASC"
07-17 09:14:28:677 [ debug sync.database.sql ] [ OCC::SqlQuery::bindValue ]: SQL bind 1 QVariant(qlonglong, -3445894622663553643)
07-17 09:14:28:677 [ 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 parent_hash(path) = ?1 ORDER BY path||'/' ASC"
07-17 09:14:28:677 [ debug sync.database.sql ] [ OCC::SqlQuery::bindValue ]: SQL bind 1 QVariant(QByteArray, "ownCloud Demo/meeting.ics")
07-17 09:14:28:677 [ debug sync.database.sql ] [ OCC::SqlQuery::exec ]: SQL exec "SELECT pinState FROM flags WHERE path == ?1;"
07-17 09:14:28:677 [ info sync.discovery ]: Processing "ownCloud Demo/meeting.ics" | valid: true/true/db | mtime: 1574168650/1574168650/0 | size: 4915/4915/0 | etag: "40b7fee84066d97d9e175ca6a78f2ecb"//"" | checksum: "SHA1:652454a6067bb3ae721eabb611c51fc9e1799149"//"" | perm: WDNVR// | fileid: "08496613oc9ekchhkcz3"//"" | inode: 37235783/37235783/ | type: CSyncEnums::ItemTypeVirtualFileDehydration/CSyncEnums::ItemTypeFile/CSyncEnums::ItemTypeFile
07-17 09:14:28:677 [ info sync.discovery ]: Discovered "ownCloud Demo/meeting.ics" INSTRUCTION_SYNC OCC::SyncFileItem::Down CSyncEnums::ItemTypeVirtualFileDehydration
07-17 09:14:28:677 [ debug sync.database.sql ] [ OCC::SqlQuery::bindValue ]: SQL bind 1 QVariant(QString, "ownCloud Demo/meeting.ics")
07-17 09:14:28:677 [ debug sync.database.sql ] [ OCC::SqlQuery::exec ]: SQL exec "SELECT lastTryEtag, lastTryModtime, retrycount, errorstring, lastTryTime, ignoreDuration, renameTarget, errorCategory, requestId FROM blacklist WHERE path=?1 COLLATE NOCASE"
07-17 09:14:28:677 [ info sync.engine ]: #### Discovery end #################################################### 328 ms
07-17 09:14:28:678 [ debug sync.database.sql ] [ OCC::SqlQuery::exec ]: SQL exec "SELECT fingerprint FROM datafingerprint"
07-17 09:14:28:678 [ info sync.engine ]: #### Reconcile (aboutToPropagate) #################################################### 328 ms

TheOneRing · 2020-07-17T08:00:13Z

Thx I'll look into it.

TheOneRing · 2020-07-23T12:12:35Z

Hi could you give https://download.owncloud.com/desktop/ownCloud/testing/2.7.0.1870-pr7969/ a try?
(Please activate logging :) )

TheOneRing · 2020-08-11T10:11:55Z

@s1mm0n could you give the above build a run?

s1mm0n · 2020-08-24T13:24:51Z

Hi, this build does not solve the Problem. I've sent you the logfiles via E-Mail.

TheOneRing · 2020-09-11T12:06:14Z

Hi so we indeed get the new info message 08-24 14:18:56:415 [ info gui.folder.manager ]: Migrate: From usePlaceholders to PinState::OnlineOnly
I assume you only run the client once?

s1mm0n · 2020-09-14T09:09:57Z

Hi, checked again, im running the client only once.

"Migrate: From usePlaceholders to PinState::OnlineOnly" is everytime in the logs.

TheOneRing · 2020-09-14T10:35:09Z

But with the code change Migrate: From usePlaceholders to PinState::OnlineOnly" is everytime in the logs. should only occur once and when the client is run a second time it should not happen again

s1mm0n · 2020-09-14T10:39:57Z

Okay, do you need any further Information?

TheOneRing · 2020-09-14T10:40:20Z

aaa ... my fault
Should be fixed now.
Could you check with a build from ~~https://github.com/owncloud/client/actions/runs/253669687~~
https://github.com/owncloud/client/pull/7969/checks

Fixes: owncloud#7779

Fixes: #7779

TheOneRing · 2020-09-14T11:06:01Z

The change was merged to 2.7 https://github.com/owncloud/client/actions/runs/253699443

s1mm0n · 2020-09-15T10:17:46Z

Tested with "Version 2.7.0 (build 1960)" (Daily Build from 08/15/2020 12:34:02 AM) seems to work as expected.

THANK YOU VERY MUCH!

TheOneRing · 2020-09-15T11:09:08Z

THANK YOU! :D
That was a nasty one.

michaelstingl added the feature:vfs native virtual files and placeholder implementation label Mar 2, 2020

michaelstingl added the regression label Jun 22, 2020

TheOneRing mentioned this issue Jul 20, 2020

Online only #7969

Merged

TheOneRing added the Needs info label Jul 28, 2020

TheOneRing added a commit to TheOneRing/client that referenced this issue Sep 14, 2020

Fix placeholders are reverted to OnlineOnly

f30ef39

Fixes: owncloud#7779

TheOneRing added a commit to TheOneRing/client that referenced this issue Sep 14, 2020

Fix placeholders are reverted to OnlineOnly

a9b7815

Fixes: owncloud#7779

TheOneRing added a commit to TheOneRing/client that referenced this issue Sep 14, 2020

Fix placeholders are reverted to OnlineOnly

69c68ff

Fixes: owncloud#7779

TheOneRing added a commit that referenced this issue Sep 14, 2020

Fix placeholders are reverted to OnlineOnly

b121854

Fixes: #7779

TheOneRing closed this as completed Sep 15, 2020

jnweiger mentioned this issue Oct 13, 2020

Release 2.7.4 #7966

Closed

63 tasks

TheOneRing mentioned this issue Nov 16, 2020

Fix usePlaceholders migration #8229

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

"Make always available" locally does not persist across client restarts #7779

"Make always available" locally does not persist across client restarts #7779

georgebarnett commented Feb 29, 2020 •

edited

Loading

michaelstingl commented Mar 2, 2020

ogoffart commented Mar 25, 2020

s1mm0n commented May 12, 2020

michaelstingl commented May 12, 2020

s1mm0n commented May 12, 2020

michaelstingl commented May 12, 2020

michaelstingl commented Jun 22, 2020

TheOneRing commented Jul 13, 2020

TheOneRing commented Jul 13, 2020

s1mm0n commented Jul 13, 2020 •

edited

Loading

TheOneRing commented Jul 14, 2020

s1mm0n commented Jul 17, 2020

TheOneRing commented Jul 17, 2020

TheOneRing commented Jul 23, 2020

TheOneRing commented Aug 11, 2020

s1mm0n commented Aug 24, 2020

TheOneRing commented Sep 11, 2020

s1mm0n commented Sep 14, 2020

TheOneRing commented Sep 14, 2020

s1mm0n commented Sep 14, 2020

TheOneRing commented Sep 14, 2020 •

edited

Loading

TheOneRing commented Sep 14, 2020

s1mm0n commented Sep 15, 2020

TheOneRing commented Sep 15, 2020

"Make always available" locally does not persist across client restarts #7779

"Make always available" locally does not persist across client restarts #7779

Comments

georgebarnett commented Feb 29, 2020 • edited Loading

Expected behaviour

Actual behaviour

Steps to reproduce

Server configuration

Client configuration

Logs

michaelstingl commented Mar 2, 2020

ogoffart commented Mar 25, 2020

s1mm0n commented May 12, 2020

michaelstingl commented May 12, 2020

s1mm0n commented May 12, 2020

michaelstingl commented May 12, 2020

michaelstingl commented Jun 22, 2020

TheOneRing commented Jul 13, 2020

TheOneRing commented Jul 13, 2020

s1mm0n commented Jul 13, 2020 • edited Loading

TheOneRing commented Jul 14, 2020

s1mm0n commented Jul 17, 2020

TheOneRing commented Jul 17, 2020

TheOneRing commented Jul 23, 2020

TheOneRing commented Aug 11, 2020

s1mm0n commented Aug 24, 2020

TheOneRing commented Sep 11, 2020

s1mm0n commented Sep 14, 2020

TheOneRing commented Sep 14, 2020

s1mm0n commented Sep 14, 2020

TheOneRing commented Sep 14, 2020 • edited Loading

TheOneRing commented Sep 14, 2020

s1mm0n commented Sep 15, 2020

TheOneRing commented Sep 15, 2020

georgebarnett commented Feb 29, 2020 •

edited

Loading

s1mm0n commented Jul 13, 2020 •

edited

Loading

TheOneRing commented Sep 14, 2020 •

edited

Loading