[Bug]: S3 as external storage keeps syncing

tobiasKaminsky commented 1 year ago

⚠️ This issue respects the following points: ⚠️

[X] This is a bug, not a question or a configuration/webserver/proxy issue.
[X] This issue is not already reported on Github (I've searched it).
[X] Nextcloud Server is up to date. See Maintenance and Release Schedule for supported versions.
[X] Nextcloud Server is running on 64bit capable CPU, PHP and OS.
[X] I agree to follow Nextcloud's Code of Conduct.

Bug description

I added Contabo S3 storage (https://contabo.com/en/object-storage) as external storage with

Amazon S3
Access Key
enable ssl
enable path style
enable previews
enable sharing

Steps to reproduce

enable S3 as external storage
add data
see that data is in S3 bucket (contabo can list this)
see that Desktop is uploading/downloading it all the time
see that web says "pending" every now and then

Expected behavior

Sync / usage should be as flawless as internal storage

Installation method

No response

Operating system

No response

PHP engine version

No response

Web server

No response

Database engine version

No response

Is this bug present after an update or on a fresh install?

No response

Are you using the Nextcloud Server Encryption module?

No response

What user-backends are you using?

[ ] Default user-backend (database)
[ ] LDAP/ Active Directory
[ ] SSO - SAML
[ ] Other

Configuration report

{
    "system": {
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "nextcloud.kaminsky.me"
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "mysql",
        "version": "23.0.3.2",
        "overwrite.cli.url": "https:\/\/nextcloud.kaminsky.me",
        "htaccess.RewriteBase": "\/",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "memcache.local": "\\OC\\Memcache\\APCu",
        "filelocking.enabled": "true",
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 6379,
            "timeout": 1.5
        },
        "debug": false,
        "forcessl": true,
        "loglevel": 0,
        "theme": "",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpmode": "sendmail",
        "mail_sendmailmode": "smtp",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpsecure": "tls",
        "mail_smtpauth": 1,
        "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
        "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
        "forceSSLforSubdomains": true,
        "enabledPreviewProviders": [
            "OC\\Preview\\Image",
            "OC\\Preview\\MP3",
            "OC\\Preview\\TXT",
            "OC\\Preview\\Movie",
            "OC\\Preview\\MarkDown",
            "OC\\Preview\\PDF",
            "OC\\Preview\\OpenDocument",
            "OC\\Preview\\PNG",
            "OC\\Preview\\JPEG",
            "OC\\Preview\\GIF",
            "OC\\Preview\\Illustrator",
            "OC\\Preview\\Postscript",
            "OC\\Preview\\Photoshop",
            "OC\\Preview\\TIFF",
            "OC\\Preview\\SVG",
            "OC\\Preview\\MP4"
        ],
        "log_rotate_size": 104857600,
        "maintenance": false,
        "updater.release.channel": "stable",
        "trashbin_retention_obligation": "auto, 90",
        "updater.server.url": "https:\/\/updates.nextcloud.com\/internal_updater_server\/",
        "mail_smtpauthtype": "PLAIN",
        "mail_smtpport": "587",
        "mysql.utf8mb4": true,
        "app_install_overwrite": [
            "spreed",
            "news",
            "dropit",
            "cookbook",
            "analytics",
            "files_fulltextsearch_tesseract",
            "files_retention",
            "twofactor_webauthn",
            "admin_notifications",
            "richdocuments",
            "bookmarks",
            "grocerylist",
            "previewgenerator",
            "polls",
            "tasks",
            "twofactor_nextcloud_notification",
            "qownnotesapi",
            "end_to_end_encryption"
        ],
        "has_rebuilt_cache": true,
        "log_query": false,
        "auth.bruteforce.protection.enabled": false,
        "preview_max_x": "2048",
        "preview_max_y": "2048",
        "jpeg_quality": "60",
        "default_phone_region": "DE"
    }
}

List of activated Apps

Enabled:
  - accessibility: 1.9.0
  - activity: 2.15.0
  - analytics: 4.2.1
  - bookmarks: 10.2.1
  - calendar: 3.2.2
  - circles: 23.1.0
  - cloud_federation_api: 1.6.0
  - comments: 1.13.0
  - contacts: 4.1.0
  - contactsinteraction: 1.4.0
  - cookbook: 0.9.11
  - dashboard: 7.3.0
  - dav: 1.21.0
  - encryption: 2.11.0
  - end_to_end_encryption: 1.9.1
  - event_update_notification: 1.4.0
  - federatedfilesharing: 1.13.0
  - federation: 1.13.0
  - files: 1.18.0
  - files_automatedtagging: 1.13.0
  - files_external: 1.15.0
  - files_pdfviewer: 2.4.0
  - files_retention: 1.12.0
  - files_sharing: 1.15.0
  - files_trashbin: 1.13.0
  - files_versions: 1.16.0
  - files_videoplayer: 1.12.0
  - firstrunwizard: 2.12.0
  - grocerylist: 0.0.1
  - guests: 2.1.0
  - logreader: 2.8.0
  - lookup_server_connector: 1.11.0
  - mail: 1.12.0
  - news: 18.1.0
  - notes: 4.3.1
  - notifications: 2.11.1
  - oauth2: 1.11.0
  - password_policy: 1.13.0
  - photos: 1.5.0
  - polls: 3.5.4
  - privacy: 1.7.0
  - provisioning_api: 1.13.0
  - qownnotesapi: 21.12.0
  - richdocuments: 5.0.4
  - serverinfo: 1.13.0
  - settings: 1.5.0
  - sharebymail: 1.13.0
  - spreed: 13.0.4
  - systemtags: 1.13.0
  - tasks: 0.14.4
  - text: 3.4.1
  - theming: 1.14.0
  - twofactor_backupcodes: 1.12.0
  - twofactor_nextcloud_notification: 3.3.1
  - twofactor_totp: 6.2.0
  - twofactor_u2f: 6.3.0
  - updatenotification: 1.13.0
  - user_status: 1.3.1
  - viewer: 1.7.0
  - workflowengine: 2.5.0
Disabled:
  - admin_audit: 1.13.0
  - admin_notifications: 1.0.2
  - announcementcenter: 6.1.1
  - deck: 1.6.1
  - documentserver_community: 0.1.12
  - dropit: 0.4.0
  - external: 3.10.2
  - facerecognition: 0.9.1
  - files_fulltextsearch: 23.0.0
  - files_fulltextsearch_tesseract: 22.0.0
  - files_rightclick: 1.1.0
  - fulltextsearch: 23.0.0
  - fulltextsearch_elasticsearch: 23.0.0
  - grocerylist_
  - maps: 0.1.10
  - nextcloud_announcements: 1.11.0
  - onlyoffice: 7.3.2
  - previewgenerator: 4.0.0
  - radio: 1.0.2
  - recommendations: 1.2.0
  - support: 1.5.0
  - survey_client: 1.10.0
  - twofactor_webauthn: 0.3.1
  - user_ldap
  - weather: 1.7.6
  - weather_status: 1.2.0

Nextcloud Signing status

No response

Nextcloud Logs

No response

Additional info

No response

PVince81 commented 1 year ago

Next steps:

Pick 1-2 files that keep up/downloading and check if the etag in oc_filecache is stable or whether it changes all the time
Check the client log to see if those files are uploading, downloading or both because the conditions can be different

tobiasKaminsky commented 1 year ago

Hm. I've removed some folders via Desktop client, they are still on server and now Desktop tries to sync them again…

I will start with a fresh folder, to try to reproduce it.

tobiasKaminsky commented 1 year ago

Interesting:

add new S3 storage
add 10 files
create subfolder "temp"
move 9 files to "temp"
see them in S3
see error delete 500 within Desktop client
after second retry it worked

tobiasKaminsky commented 1 year ago

Next observation: Client was quiet, everything fine. Then I opened s3 storage within web and now I have all the time problems with client syncing it:

PVince81 commented 1 year ago

please try https://github.com/nextcloud/server/issues/33785#issuecomment-1233832720

if something is changing the etag on the server without any interaction, then there's a bug of sorts

I assume you don't have a cron job running "occ files:scan" on the storage periodically ? (which I wouldn't recommend)

Macs75 commented 1 year ago

I had the same problem with a different storage provider. The files were uploaded, but then disappear from nextcloud after briefly showing. Checking on the S3 drive directly I can see and download the files. Turn out the issue was with the option "path style" that I used to have different space for each user. To do a test I removed it and changed the configuration to a fixed value and the files are showing correctly now, but obviously I can't keep this configuration and everyone will see the files of everybody else.

tobiasKaminsky commented 1 year ago

For me, I have to keep "enable path style" enabled, otherwise I see a config error. It is also written here: https://docs.contabo.com/docs/products/Object-Storage/Tools/nextcloud/

tobiasKaminsky commented 1 year ago

SQL: SELECT fileid, name, etag FROM oc_filecache WHERE fileid in (15641644, 15641596, 15641520, 15641601);

{"fileid":"15641520","name":"Neues Textdokument.md","etag":"\"04e287dc9691f156bd00bfecdb156b2e\""}, {"fileid":"15641596","name":"temp","etag":"631600ce9ae07"}, {"fileid":"15641601","name":"20210207_121658.jpg","etag":"\"487a5eab0bddab96ee572aa9116e610f\""}, {"fileid":"15641644","name":"513d1d4b1ff757e464cc7622a7cf3d96cda26a89.pdf","etag":"6311c519b32c0"}

tobiasKaminsky commented 1 year ago

Right now it keeps re-downloading "Neues Textdokument.md" with stable etag on server side.

tobiasKaminsky commented 1 year ago

20220905_1608_owncloud.log.9:2022-09-05 16:08:51:251 [ debug nextcloud.gui.folder /build/nextcloud-client/src/nextcloud-client/src/gui/folder.cpp:580 ] [ OCC::Folder::slotWatchedPathChanged ]:        Changed path was touched by SyncEngine, ignoring: "/home/tobi/nextcloud/test2/Neues Textdokument.md

@mgallien

mgallien commented 1 year ago

20220905_1608_owncloud.log.9:2022-09-05 16:08:51:251 [ debug nextcloud.gui.folder /build/nextcloud-client/src/nextcloud-client/src/gui/folder.cpp:580 ] [ OCC::Folder::slotWatchedPathChanged ]:        Changed path was touched by SyncEngine, ignoring: "/home/tobi/nextcloud/test2/Neues Textdokument.md

@mgallien

could you share your full log ?

tobiasKaminsky commented 1 year ago

Shared internally: https://cloud.nextcloud.com/index.php/f/6474148

tobiasKaminsky commented 1 year ago

If wanted, I can also create a test user with this S3, so you can test/debug on your own :)

mgallien commented 1 year ago

looks very much like the etag received by desktop client has extra quotes around the value. they are not stripped by desktop client leading to an always differing etag leading to always syncing the same files again and again

tobiasKaminsky commented 1 year ago

So external storage app is doing something wrong when creating/storing eTag?

We do this also on Android, but in general I doubt that we should have different eTag syntax (with / without " ")…

tobiasKaminsky commented 1 year ago

@PVince81 while testing I found: Hm. This seems to be unrelated to client, as it happens also in this case:

note down etag: 123
stop client
refresh parent folder (where problematic folder is in) -> no change
open folder via web
see changing eTag

--> so it is enough to enter this folder to have a flipping etag

PR by Claudio still helps a lot, as now "only" problematic folder has a changing etag, but content remains the same, so Desktop client does not have to do actual work.

DaphneMuller commented 1 year ago

A small service provider bumped into this issue, might be worth to fix before large customers run into this problem

juliushaertl commented 1 year ago

I cannot reproduce with minio, but maybe also failed to get the steps right.

From a first look at the code the changing etag on the folder seems expected according to:

https://github.com/nextcloud/server/blob/54c05bcdb96fcbab8a8c552e6558dc18b1571af3/apps/files_external/lib/Lib/Storage/AmazonS3.php#L755-L763

For the extra quote on the Tag, it seems that this is passed through from the object storage these days, so maybe we should trim those in https://github.com/nextcloud/server/blob/54c05bcdb96fcbab8a8c552e6558dc18b1571af3/apps/files_external/lib/Lib/Storage/AmazonS3.php#L699

@tobiasKaminsky Do you have a test account that you could share temporarily to see if the actual storage service makes a difference there?

juliushaertl commented 1 year ago

@tobiasKaminsky Maybe to check back on your findings. Entering the folder changing the root etag would be expected if the external storage is configured to always check for changes. Otherwise the desktop client would never get aware if files are changed outside of Nextcloud directly on the S3 bucket.

With the desktop client related fixes, do you still see issues with syncing already synced files?

tobiasKaminsky commented 1 year ago

Sorry for coming back this late. Now I often receive a 504 gateway timeout. I am actually not sure if this as a NC problem, or if the service quality of the S3 provider is this poor.

rfreytag1 commented 1 year ago

With the desktop client related fixes, do you still see issues with syncing already synced files?

I have the same issue with the latest desktop client.

szaimen commented 1 year ago

Hi, please update to 24.0.9 or better 25.0.3 and report back if it fixes the issue. Thank you!

My goal is to add a label like e.g. 25-feedback to this ticket of an up-to-date major Nextcloud version where the bug could be reproduced. However this is not going to work without your help. So thanks for all your effort!

If you don't manage to reproduce the issue in time and the issue gets closed but you can reproduce the issue afterwards, feel free to create a new bug report with up-to-date information by following this link: https://github.com/nextcloud/server/issues/new?assignees=&labels=bug%2C0.+Needs+triage&template=BUG_REPORT.yml&title=%5BBug%5D%3A+

rfreytag1 commented 1 year ago

I am using version 25.0.3 now and the issue still persists. It also affects the thumbnail generation. Only after visiting the folders using the android app the thumbnails work again.

mrAceT commented 1 year ago

Just a thought, I built a "S3->local" and a "local->S3" migration script. To perform a good migration I had to include a bunch of checks. I now also once in a while run that script to perform a "sanity check" of my nextcloud instance..

You could run it and see if it detects anything "odd"?

https://github.com/mrAceT/nextcloud-S3-local-S3-migration

rfreytag1 commented 1 year ago

I have installed 25.0.4 now and after a complete resync it seems to work fine now. Thumbnails are still broken in the webinterface, but I suppose that's a different issue.

ZE3kr commented 1 year ago

Hello. I am using the 26.0.0 on the server's end and the 3.8.0 desktop version on the macOS. The problem still persists. I am using external storage.

I am not a contributor to Nextcloud, but I know programming and I know a little bit about PHP. So here is my debugging process:

The error I see on my client:

Failed to find a valid token/etag combination for xxx

I searched this string in the code and located it here at /var/www/nextcloud/3rdparty/sabre/dav/lib/DAV/Server.php:1483

And I added an error_log

                /* somecode */
                if (($tokenValid && $etagValid) ^ $token['negate']) {
                    // Both were valid, so we can go to the next condition.
                    continue 2;
                }
                /* Added error_log */
                error_log("\r\n\r\n".print_r($token['etag'], true)."\r\n".print_r($node->getETag(), true)."\r\n\r\n", 3, '/var/www/nextcloud/data/test.log');
            }

            // If we ended here, it means there was no valid ETag + token
            // combination found for the current condition. This means we fail!
            throw new Exception\PreconditionFailed('Failed to find a valid token/etag combination for '.$uri, 'If');
        }

Then I saw something like this in '/var/www/nextcloud/data/test.log'.

4045ebdcba4faf227e41739a93bd4b9c-1
"4045ebdcba4faf227e41739a93bd4b9c-1"

So @juliushaertl is right. It is because the extra quotes. The clients will keep syncing while receiving the same error again and again, and the new files will never uploaded to S3. I also used the MySQL to see the oc_filecache table. Here is what I got from SELECT path, etag FROM oc_filecache WHERE path LIKE "%global333.less%". This file is created by Nextcloud in my External Storage (which is the S3 backend)

+--------------------+---------------+
| path               | etag          |
+--------------------+---------------+
| global333.less     | 642e55ac1a537 |
+--------------------+---------------+
1 rows in set (0.007 sec)

However, when I try to find a file that is already in S3 before I mounted it at Nextcloud, here is what I got:

+-----------------------------------+--------------------------------------+
| path                              | etag                                 |
+-----------------------------------+--------------------------------------+
| 2016/2016-08-07/ZE3_3819-Pano.dng | "51d4ffd5d95ceb68f32828fd5c39456a-1" |
+-----------------------------------+--------------------------------------+
1 row in set (0.008 sec)

So changing server/apps/files_external/lib/Lib/Storage/AmazonS3.php is not enough for existing installs. But changing this should solve this for new installs. The database is also needed to be updated to remove the extra quotes.

ZE3kr commented 1 year ago

This bug is reproducible. Here is what to do to reproduce this bug:

Create an empty S3 bucket. (I am using AWS S3)
Put some files in that S3 bucket.
Mount that S3 bucket on the Nextcloud Server with the External storage app.
On the desktop side, edit the synced file on the external storage, and save it with the same name. I am using the virtual files feature.
Wait for the sync.
When the upload is completed, the error Failed to find a valid token/etag combination for XXX appears.
Check the etag column in the oc_filecache table. There are extra quotes.

I hope this info is helpful.

ZE3kr commented 1 year ago

I applied the patch https://github.com/nextcloud/server/pull/37611 and re-installed Nextcloud. Then I mount the S3 and the ETag seems to be working correctly. The database also reflects the corrected ETag.

nextcloud / server