nextcloud / docker

⛴ Docker image of Nextcloud
https://hub.docker.com/_/nextcloud/
GNU Affero General Public License v3.0
5.95k stars 1.82k forks source link

[Bug]: Update Failure on v26 #2273

Open kn0wmad opened 9 months ago

kn0wmad commented 9 months ago

⚠️ This issue respects the following points: ⚠️

Bug description

Attempting to update and migrate from v25.0.5 to v26.0.x (tried .6 and .8), v26 update code fails with the following error:

Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: 2023-12-05 18:56:40.114 UTC [148] ERROR:  relation "oc_files_versions" already exists
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: 2023-12-05 18:56:40.114 UTC [148] STATEMENT:  CREATE TABLE oc_files_versions (id BIGSERIAL NOT NULL, file_id BIGINT NOT NULL, timestamp BIGINT NOT NULL, size BIGINT NOT NULL, mimetype BIGINT NOT NULL, metadata JSON NOT NULL, PRIMARY KEY(id))
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Exception: Database error when running migration 1020Date20221114144058 for app files_versions
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: An exception occurred while executing a query: SQLSTATE[42P07]: Duplicate table: 7 ERROR:  relation "oc_files_versions" already exists

This is using nextcloud's docker images and coming from apache-bullseye with postgres13 and apache and going to fpm-alpine with postgres 15 and nginx

Steps to reproduce

  1. Attempt db migration and update from v25.0.5
  2. Migration succeeds
  3. Update fails with above error

Expected behavior

Update completes

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

root@nextcloud:/var/www/html# sudo -u www-data php occ config:list system
sudo: unable to send audit message: Operation not permitted

Warning: Failed to set memory limit to 0 bytes (Current memory usage is 2097152 bytes) in Unknown on line 0
The current PHP memory limit is below the recommended value of 512MB.
{
    "system": {
        "htaccess.RewriteBase": "\/",
        "memcache.local": "\\OC\\Memcache\\APCu",
        "apps_paths": [
            {
                "path": "\/var\/www\/html\/apps",
                "url": "\/apps",
                "writable": false
            },
            {
                "path": "\/var\/www\/html\/custom_apps",
                "url": "\/custom_apps",
                "writable": true
            }
        ],
        "trusted_proxies": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "localhost",
            "qc2n6xno3vuzupx5n4bogk2m7fhzxw5w27det5luxu4iqvhfunp5h3yd.onion",
            "qc2n6xno3vuzupx5n4bogk2m7fhzxw5w27det5luxu4iqvhfunp5h3yd.local",
            "nextcloud.embassy"
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "pgsql",
        "overwriteprotocol": "https",
        "version": "25.0.5.1",
        "overwrite.cli.url": "https:\/\/qc2n6xno3vuzupx5n4bogk2m7fhzxw5w27det5luxu4iqvhfunp5h3yd.local",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "default_locale": "en_US",
        "default_phone_region": "US",
        "updatechecker": false,
        "updater.server.url": "nextcloud.embassy",
        "preview_max_memory": 2048,
        "preview_max_filesize_image": 256,
        "preview_max_x": 2048,
        "preview_max_y": 2048,
        "enabledPreviewProviders": [
            "OC\\Preview\\Image",
            "OC\\Preview\\HEIC",
            "OC\\Preview\\TIFF",
            "OC\\Preview\\Movie",
            "OC\\Preview\\MKV",
            "OC\\Preview\\MP4",
            "OC\\Preview\\AVI"
        ]
    }
}

List of activated Apps

sudo: unable to send audit message: Operation not permitted

Warning: Failed to set memory limit to 0 bytes (Current memory usage is 2097152 bytes) in Unknown on line 0
The current PHP memory limit is below the recommended value of 512MB.
Enabled:
  - activity: 2.17.0
  - calendar: 4.6.0
  - circles: 25.0.0
  - cloud_federation_api: 1.8.0
  - comments: 1.15.0
  - contacts: 5.4.2
  - contactsinteraction: 1.6.0
  - dashboard: 7.5.0
  - dav: 1.24.0
  - federatedfilesharing: 1.15.0
  - federation: 1.15.0
  - files: 1.20.1
  - files_pdfviewer: 2.6.0
  - files_rightclick: 1.4.0
  - files_sharing: 1.17.0
  - files_trashbin: 1.15.0
  - files_versions: 1.18.0
  - firstrunwizard: 2.14.0
  - logreader: 2.10.0
  - lookup_server_connector: 1.13.0
  - maps: 1.1.0
  - nextcloud_announcements: 1.14.0
  - notes: 4.8.1
  - notifications: 2.13.1
  - oauth2: 1.13.0
  - password_policy: 1.15.0
  - photos: 2.0.1
  - privacy: 1.9.0
  - provisioning_api: 1.15.0
  - recommendations: 1.4.0
  - related_resources: 1.0.4
  - serverinfo: 1.15.0
  - settings: 1.7.0
  - sharebymail: 1.15.0
  - support: 1.8.0
  - survey_client: 1.13.0
  - systemtags: 1.15.0
  - text: 3.6.0
  - theming: 2.0.1
  - twofactor_backupcodes: 1.14.0
  - updatenotification: 1.15.0
  - user_status: 1.5.0
  - viewer: 1.9.0
  - weather_status: 1.5.0
  - workflowengine: 2.7.0
Disabled:
  - admin_audit
  - bruteforcesettings
  - encryption
  - files_external
  - suspicious_login
  - twofactor_totp
  - user_ldap

Nextcloud Signing status

No errors have been found.

Nextcloud Logs

This is the log from update, as it is more relevant (cut the head as it was too long):

Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]:  Starting ...
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]:     0/0 [>---------------------------]   0%
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Clean up old calendar subscriptions from deleted users that were not cleaned-up
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]:
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]:  Starting ...
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]:     0/0 [->--------------------------]   0%
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <dav> to 1.25.0
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <files_sharing> ...
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updating database schema
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <files_sharing> to 1.18.0
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <files_trashbin> ...
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updated database
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <files_trashbin> to 1.16.0
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <files_versions> ...
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <circles> ...
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: 2023-12-05 18:56:38.599 UTC [148] ERROR:  relation "oc_circle_circles" does not exist at character 15
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: 2023-12-05 18:56:38.599 UTC [148] STATEMENT:  SELECT * FROM "oc_circle_circles"
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <circles> to 26.0.1
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <cloud_federation_api> ...
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <cloud_federation_api> to 1.9.0
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <dav> ...
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Fix broken values of calendar objects
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]:
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]:  Starting ...
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]:     0/0 [>---------------------------]   0%
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Clean up old calendar subscriptions from deleted users that were not cleaned-up
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]:
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]:  Starting ...
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]:     0/0 [->--------------------------]   0%
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <dav> to 1.25.0
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <files_sharing> ...
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <files_sharing> to 1.18.0
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <files_trashbin> ...
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <files_trashbin> to 1.16.0
Dec 05 18:56:38 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <files_versions> ...
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <files_versions> to 1.19.1
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <sharebymail> ...
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <sharebymail> to 1.16.0
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <workflowengine> ...
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <workflowengine> to 2.8.0
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <comments> ...
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <comments> to 1.16.0
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <firstrunwizard> ...
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <firstrunwizard> to 2.15.0
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <nextcloud_announcements> ...
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Updated <nextcloud_announcements> to 1.15.0
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Updating <notifications> ...
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: 2023-12-05 18:56:40.114 UTC [148] ERROR:  relation "oc_files_versions" already exists
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: 2023-12-05 18:56:40.114 UTC [148] STATEMENT:  CREATE TABLE oc_files_versions (id BIGSERIAL NOT NULL, file_id BIGINT NOT NULL, timestamp BIGINT NOT NULL, size BIGINT NOT NULL, mimetype BIGINT NOT NULL, metadata JSON NOT NULL, PRIMARY KEY(id))
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Exception: Database error when running migration 1020Date20221114144058 for app files_versions
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: An exception occurred while executing a query: SQLSTATE[42P07]: Duplicate table: 7 ERROR:  relation "oc_files_versions" already exists
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Update failed
Dec 05 18:56:40 tedious-packet nextcloud_Migration.embassy[1136314]: Maintenance mode is kept active

Additional info

Thank you for your time

joshtrichards commented 9 months ago

Are you certain you're pointed at the right database and/or not using a previously upgraded already db?

That db migration, Version1020Date20221114144058, is the only one the exists for file_versions and it's the one that literally creates the files_versions db table (known as `oc_files_versions in most installations) for the very first time. It didn't even exist in NC25.

https://github.com/nextcloud/server/blob/master/apps/files_versions/lib/Migration/Version1020Date20221114144058.php

So it's impossible to have had this table already unless... Well I'm not even sure how.

Also there's a check for it's prior existence that at the top of the migration that should have kicked in anyhow... so I'm kind of baffled.

Are you using stock Docker images or self built ones?

Sounds like you're also upgrading/moving your own db environment at the same time? Maybe something got crossed there?

There's never been a similar report and NC26 is hardly new... 🤔

kn0wmad commented 9 months ago

Thank you for the timely response, which lead to a fix!

We determined that the /entrypoint.sh from the official alpine docker image and occ upgrade were running concurrently. We stopped the entrypoint before running the upgrade and everything went smoothly. It seems like occ upgrade is not safe to run concurrently.

joshtrichards commented 9 months ago

Glad you got it worked out, but sounds like you're doing something unconventional. The entrypoint is what runs occ upgrade:

https://github.com/nextcloud/docker/blob/d1dbc77e0b5e851105cf8606942e74b7d21fe682/docker-entrypoint.sh#L257

How are you updating and upgrading?

kn0wmad commented 9 months ago

Very unconventional. Our Linux-based StartOS grants one-click installs of a Nextcloud server (and many other services) to non-technical users.

I was not referring to the docker-entrypoint, but the 26/entrypoint.sh within the image. Our container entrypoint is custom.

We very much appreciate the assist and look forward to helping create more sovereign Nextcloud server operators!

dr-bonez commented 9 months ago

The entrypoint is what runs occ upgrade:

StartOS needs to separate migration from runtime code, so we need to be able to upgrade it separately. I had assumed that we couldn't just call occ upgrade before the entrypoint had run, because otherwise it would be the wrong occ, seeing as the contents of /var/www/html would be the old version. Am I incorrect in this assumption? Alternatively, is it possible to know when the upgrade portion of /entrypoint.sh is complete, so we can know we can safely send it a sigterm and know for sure it has already been upgraded?

kn0wmad commented 9 months ago

StartOS needs to separate migration from runtime code, so we need to be able to upgrade it separately. I had assumed that we couldn't just call occ upgrade before the entrypoint had run, because otherwise it would be the wrong occ, seeing as the contents of /var/www/html would be the old version. Am I incorrect in this assumption? Alternatively, is it possible to know when the upgrade portion of /entrypoint.sh is complete, so we can know we can safely send it a sigterm and know for sure it has already been upgraded?

Bump. @joshtrichards can you lend some insight here?

kn0wmad commented 8 months ago

Ping @joshtrichards - could really use an answer here if you have a moment.