nextcloud / server

☁️ Nextcloud server, a safe home for all your data
https://nextcloud.com
GNU Affero General Public License v3.0
27.33k stars 4.06k forks source link

[Bug]: High UI latency and COPY failures with object storage + encryption #41794

Open christianwolfcodesorcerer opened 11 months ago

christianwolfcodesorcerer commented 11 months ago

⚠️ This issue respects the following points: ⚠️

Bug description

Copying folders with files and subfolders when object storage as primary storage is configured is unreliable and very slow.

Installation details:

helm chart nextcloud-3.5.21 image: tag: 26.0.5-apache db: mariadb redis: enabled

Object Storage as primary storage: MinIO Configured according to the following documentation: https://docs.nextcloud.com/server/13/admin_manual/configuration_files/primary_storage.html#simple-storage-service-s3

Steps to reproduce

  1. Create a folder with a subfolder. The folder should be around 600 MB. Create 10 files in the folder, 10 files in the subfolder. Some of the files should be around 100 MB, others only 2 MB
  2. Copy the folder via API (https://docs.nextcloud.com/server/19/developer_manual/client_apis/WebDAV/basic.html#copying-files-and-folders-rfc4918) or via Nextcloud UI.

Expected behavior

The COPY command should function reliable. What also is remarkable is the overall latency of the UI and the COPY command. The UI is nearly unusable due to latency issues (showing folders and files in the overview, copying them, ...). For example the COPY command takes > 60s. On a similar installation without object storage as primary storage the requests take < 5s and work reliable. Also the overall latency of the UI is much better.

Installation method

None

Nextcloud Server version

26

Operating system

None

PHP engine version

None

Web server

None

Database engine version

None

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

None

Are you using the Nextcloud Server Encryption module?

None

What user-backends are you using?

Configuration report

No response

List of activated Apps

No response

Nextcloud Signing status

No response

Nextcloud Logs

No response

Additional info

No response

christianwolfcodesorcerer commented 11 months ago

Hi, there is one additional important finding from our side: The problem seems not to be related to object storage as primary storage but to server side encryption. We could reproduce this with the following steps:

  1. Start the following docker-compose setup
version: '3.8'

services:
  nextcloud:
    image: nextcloud:26.0.5-apache
    ports:
      - 8082:80
    depends_on:
      - mariadb
      - redis
      - minio
    environment:
      - NEXTCLOUD_ADMIN_USER=nadmin
      - NEXTCLOUD_ADMIN_PASSWORD=nadmin
      - MYSQL_HOST=mariadb
      - MYSQL_USER=nextcloud
      - MYSQL_PASSWORD=nextcloud
      - MYSQL_DATABASE=nextcloud
      - REDIS_HOST=redis
      - OBJECTSTORE_S3_HOST=minio
      - OBJECTSTORE_S3_BUCKET=nextcloud
      - OBJECTSTORE_S3_KEY=minio
      - OBJECTSTORE_S3_SECRET=minio123
      - OBJECTSTORE_S3_PORT=9000
      - OBJECTSTORE_S3_SSL=false
      - OBJECTSTORE_S3_REGION=us-east-1
      - OBJECTSTORE_S3_USEPATH_STYLE=true
      - OBJECTSTORE_S3_LEGACYAUTH=false
      - OBJECTSTORE_S3_AUTOCREATE=true

  mariadb:
    image: mariadb
    environment:
      - MYSQL_ROOT_PASSWORD=root
      - MYSQL_PASSWORD=nextcloud
      - MYSQL_DATABASE=nextcloud
      - MYSQL_USER=nextcloud

  redis:
    image: redis:alpine

  minio:
    image: quay.io/minio/minio
    ports: 
      - 9090:9090
    environment:
      - MINIO_ROOT_USER=minio
      - MINIO_ROOT_PASSWORD=minio123
    command: server /data --console-address ":9090"
  1. Install App: Default encryption module
  2. Enable Server-side encryption (Administrative Settings -> Security -> Server-side encryption)
  3. Create a folder with a subfolder. The folder should be around 600 MB. Create 10 files in the folder, 10 files in the subfolder. Some of the files should be around 100 MB, others only 2 MB
  4. Copy folder
joshtrichards commented 11 months ago

Hi @christianwolfcodesorcerer - I can't reproduce this behavior, using your Compose file, even with Encryption activated.

No copy errors, no noted latency in the UI, and copy performance seems reasonable on this relatively low-end bare metal box (i7-i8700 w/ Samsung SSD).

What hardware and/or underlying platform are you running this on? Since it seems tied to Encryption for you, are you running on hardware that either has AES-NI disabled (in the BIOS or in the VM environment) - or even outright doesn't support it?

EDIT: I did do one thing differently: I did the test with v26.0.9 (rather than outdated v26.0.5), but that's what I'd suggest testing with anyhow. :)

test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:06 +0000] "PUT /ocs/v2.php/apps/user_status/api/v1/heartbeat?format=json HTTP/1.1" 200 978 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:08 +0000] "GET /ocs/v2.php/apps/text/workspace?path=%2FtestFolder%2FtestDeeperFolder HTTP/1.1" 404 951 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:08 +0000] "PROPFIND /remote.php/dav/files/nadmin/testFolder/testDeeperFolder HTTP/1.1" 207 1915 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:08 +0000] "GET /apps/files/api/v1/stats?dir=%2FtestFolder%2FtestDeeperFolder HTTP/1.1" 200 968 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:08 +0000] "PROPFIND /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper HTTP/1.1" 207 1885 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:08 +0000] "GET /ocs/v2.php/apps/text/workspace?path=%2FtestFolder%2FtestDeeperFolder%2FevenDeeper HTTP/1.1" 404 950 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:08 +0000] "GET /apps/files/api/v1/stats?dir=%2FtestFolder%2FtestDeeperFolder%2FevenDeeper HTTP/1.1" 200 969 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:13 +0000] "GET /apps/files/api/v1/showgridview HTTP/1.1" 200 864 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:13 +0000] "PROPFIND /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper HTTP/1.1" 207 1802 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:23 +0000] "MKCOL /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper/wayDeeper HTTP/1.1" 201 695 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:23 +0000] "PROPFIND /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper/wayDeeper HTTP/1.1" 207 1400 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:24 +0000] "PROPFIND /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper/wayDeeper HTTP/1.1" 207 1400 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:26 +0000] "COPY /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper/Nextcloud%20Server%20Administration%20Manual.pdf HTTP/1.1" 201 694 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:27 +0000] "GET /ocs/v2.php/apps/notifications/api/v2/notifications HTTP/1.1" 304 820 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:27 +0000] "PROPFIND /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper HTTP/1.1" 207 1922 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:27 +0000] "GET /apps/files/api/v1/stats?dir=%2FtestFolder%2FtestDeeperFolder%2FevenDeeper HTTP/1.1" 200 969 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:26 +0000] "COPY /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper/server-27.0.2.tar.gz HTTP/1.1" 201 695 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:29 +0000] "PROPFIND /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper HTTP/1.1" 207 1922 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:26 +0000] "COPY /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper/server-27.0.1.tar.gz HTTP/1.1" 201 695 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:29 +0000] "GET /apps/files/api/v1/stats?dir=%2FtestFolder%2FtestDeeperFolder%2FevenDeeper HTTP/1.1" 200 969 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:29 +0000] "PROPFIND /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper HTTP/1.1" 207 1922 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:29 +0000] "GET /apps/files/api/v1/stats?dir=%2FtestFolder%2FtestDeeperFolder%2FevenDeeper HTTP/1.1" 200 969 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:26 +0000] "COPY /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper/nextcloud-PR-6238-00a13dd2424bbbcef8bdaa6cf39fdb4f3c27090f-x86_64.AppImage HTTP/1.1" 201 695 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:31 +0000] "PROPFIND /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper HTTP/1.1" 207 1921 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:31 +0000] "GET /apps/files/api/v1/stats?dir=%2FtestFolder%2FtestDeeperFolder%2FevenDeeper HTTP/1.1" 200 969 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:26 +0000] "COPY /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper/latest.zip HTTP/1.1" 201 695 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:33 +0000] "PROPFIND /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper HTTP/1.1" 207 1923 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:33 +0000] "GET /apps/files/api/v1/stats?dir=%2FtestFolder%2FtestDeeperFolder%2FevenDeeper HTTP/1.1" 200 969 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:27 +0000] "COPY /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper/512m.bin HTTP/1.1" 201 694 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:44 +0000] "GET /apps/files/api/v1/stats HTTP/1.1" 200 968 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:44 +0000] "PROPFIND /remote.php/dav/files/nadmin/testFolder/testDeeperFolder/evenDeeper HTTP/1.1" 207 1922 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:44 +0000] "GET /apps/files/api/v1/stats?dir=%2FtestFolder%2FtestDeeperFolder%2FevenDeeper HTTP/1.1" 200 969 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 192.168.88.67 - - [29/Nov/2023:22:23:44 +0000] "GET /apps/files/api/v1/stats?dir=%2FtestFolder%2FtestDeeperFolder%2FevenDeeper HTTP/1.1" 200 969 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0"
test-nc27-minio-i41794-nextcloud-1  | 127.0.0.1 - - [29/Nov/2023:22:23:50 +0000] "OPTIONS * HTTP/1.0" 200 126 "-" "Apache/2.4.57 (Debian) PHP/8.2.13 (internal dummy connection)"
christianwolfcodesorcerer commented 11 months ago

@joshtrichards this is the error that we are getting from the logs:

[Thu Nov 30 17:00:58.092402 2023] [php:error] [pid 5018] [client 80.187.74.85:0] PHP Fatal error:  Allowed memory size of 536870912 bytes exhausted (tried to allocate 96469024 bytes) in /var/www/html/3rdparty/guzzlehttp/psr7/src/Stream.php on line 254

And some additional infos:

AndyScherzinger commented 11 months ago

looping in @juliushaertl and @icewind1991

@icewind1991 could you have a first look into this one please? Thanks in advance

christianwolfcodesorcerer commented 11 months ago

The problem occurs somewhere between folder sizes of 500 GB and 700 GB on the local machine. 500 GB works, 700 GB not.

christianwolfcodesorcerer commented 11 months ago

when we increase PHP_MEMORY_LIMIT and PHP_UPLOAD_LIMIT the error disappears on the local machine. Unfortunately on the productive system the error changes to the initial errors depending on the overwrite flag:

overwrite true: 423 Locked, Exception: OCA\DAV\Connector\Sabre\Exception\FileLocked, message: "xxx" is locked, existing lock on file: exclusive

overwrite false: 412 Precondition Failed, Exception: Sabre\DAV\Exception\PreconditionFailed, message: The destination node already exists, and the overwrite header is set to false

On the local system we can not reproduce this unfortunately. The productive setup is similar with the local docker compose setup we have provided and the additional configuration:

We would really like to parse the config from php occ config:list here, but it contains a lot of sensitive information and therefore this is not possible (removing them manual is too risky).

joshtrichards commented 11 months ago

What is your redis.cluster failover_mode set to?

christianwolfcodesorcerer commented 11 months ago

@joshtrichards we are using the nextcloud helm chart for redis installation: https://github.com/nextcloud/helm/blob/main/charts/nextcloud/values.yaml#L336 The values are:

redis:
  enabled: true
  auth:
    password: 'xxxx'
  replica:
    replicaCount: 2
nextcloud-command commented 10 months ago

This issue has been automatically marked as stale because it has not had recent activity and seems to be missing some essential information. It will be closed if no further activity occurs. Thank you for your contributions.