[Bug]: Upgrade fails with 'The column "webhook_uri" on table "oc_taskprocessing_tasks" already exists.'

bpmartin20 commented 1 day 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 OR Nextcloud Community Forum (I've searched it).
[x] Nextcloud Server is up to date. See Maintenance and Release Schedule for supported versions.
[x] I agree to follow Nextcloud's Code of Conduct.

Bug description

Upgrade from 29.0.9 to 30.0.2 fails to a table column already existing. See "Steps to reproduce" below for details.

Steps to reproduce

1.sudo -u www-data php /var/www/nextcloud/updater/updater.phar

I receive normal messages (backups, downloading, etc.) and then during the upgrade:

Updating database schema Exception: Database error when running migration 30000Date20240717111406 for app core The column "webhook_uri" on table "oc_taskprocessing_tasks" already exists. Update failed

Expected behavior

I expected the upgrade to complete normally, of course. I've run upgrades since version 14, and usually they go quite well.

Nextcloud Server version

29

Operating system

Debian/Ubuntu

PHP engine version

PHP 8.3

Web server

Apache (supported)

Database engine version

MySQL

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

Upgraded to a MAJOR version (ex. 28 to 29)

Are you using the Nextcloud Server Encryption module?

Encryption is Disabled

What user-backends are you using?

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

Configuration report

Before upgrade attempt ...
Enabled:
  - activity: 2.21.1
  - admin_audit: 1.19.0
  - appointments: 2.1.12
  - apporder: 0.15.0
  - calendar: 4.7.16
  - cfg_share_links: 6.1.1
  - cloud_federation_api: 1.12.0
  - comments: 1.19.0
  - contacts: 6.0.0
  - dav: 1.30.1
  - extract: 1.3.6
  - federatedfilesharing: 1.19.0
  - files: 2.1.1
  - files_accesscontrol: 1.19.1
  - files_automatedtagging: 1.19.0
  - files_downloadlimit: 2.0.0
  - files_markdown: 2.4.1
  - files_notify_redis: 0.3.4
  - files_pdfviewer: 2.10.0
  - files_reminders: 1.2.0
  - files_sharing: 1.21.0
  - files_trashbin: 1.19.0
  - files_versions: 1.22.0
  - firstrunwizard: 2.18.0
  - groupfolders: 17.0.5
  - guests: 3.2.0
  - impersonate: 1.16.0
  - issuetemplate: 0.7.0
  - lookup_server_connector: 1.17.0
  - mail: 3.7.9
  - maps: 1.4.0
  - memories: 7.4.1
  - nextcloud_announcements: 1.18.0
  - notes: 4.11.0
  - notifications: 2.17.0
  - notify_push: 0.7.0
  - oauth2: 1.17.1
  - password_policy: 1.19.0
  - phonetrack: 0.8.1
  - photos: 2.5.0
  - previewgenerator: 5.6.0
  - privacy: 1.13.0
  - provisioning_api: 1.19.0
  - recognize: 7.1.0
  - related_resources: 1.4.0
  - settings: 1.12.0
  - sharebymail: 1.19.0
  - systemtags: 1.19.0
  - tasks: 0.16.1
  - text: 3.10.1
  - theming: 2.4.0
  - theming_customcss: 1.17.0
  - twofactor_backupcodes: 1.18.0
  - updatenotification: 1.19.1
  - viewer: 2.3.0
  - workflowengine: 2.11.0
Disabled:
  - bruteforcesettings: 2.9.0 (installed 2.7.0)
  - circles: 29.0.0-dev (installed 23.1.0)
  - contactsinteraction: 1.10.0 (installed 1.4.0)
  - dashboard: 7.9.0 (installed 7.3.0)
  - encryption: 2.17.0
  - external: 5.4.1 (installed 5.4.1)
  - federation: 1.19.0 (installed 1.8.0)
  - files_external: 1.21.0
  - logreader: 2.14.0 (installed 2.13.0)
  - onlyoffice: 9.5.0 (installed 9.5.0)
  - recommendations: 2.1.0 (installed 0.6.0)
  - serverinfo: 1.19.0 (installed 1.13.0)
  - support: 1.12.0 (installed 1.1.1)
  - survey_client: 1.17.0 (installed 1.11.0)
  - suspicious_login: 7.0.0 (installed 5.0.0)
  - twofactor_totp: 11.0.0-dev
  - user_ldap: 1.20.0
  - user_status: 1.9.0 (installed 1.3.1)
  - weather_status: 1.9.0 (installed 1.3.0)
root@nextcloud:/var/www/nextcloud# 
root@nextcloud:/var/www/nextcloud# occ config:list system
{
    "system": {
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "localhost",
            "nextcloud.dmz.silverflash.net",
            "nextcloud.silverflash.net",
            "192.168.124.126"
        ],
        "trusted_proxies": "***REMOVED SENSITIVE VALUE***",
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "overwrite.cli.url": "http:\/\/localhost",
        "overwriteprotocol": "https",
        "overwritehost": "nextcloud.silverflash.net",
        "dbtype": "mysql",
        "default_phone_region": "US",
        "version": "29.0.9.2",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "mysql.utf8mb4": true,
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "filesystem_check_changes": 1,
        "installed": true,
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpmode": "smtp",
        "mail_smtpauthtype": "LOGIN",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": "25",
        "maintenance": false,
        "maintenance_window_start": 3,
        "loglevel": 2,
        "memcache.local": "\\OC\\Memcache\\APCu",
        "memcache.distributed": "\\OC\\Memcache\\Redis",
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 6379
        },
        "trashbin_retention_obligation": 15,
        "updater.release.channel": "stable",
        "theme": "",
        "log_type": "syslog",
        "logtimezone": "America\/Los_Angeles",
        "data-fingerprint": "48986e3741f6036d8afe2eec916c5fec",
        "app_install_overwrite": [
            "gallery",
            "phonetrack",
            "issuetemplate",
            "previewgenerator",
            "documentserver_community",
            "apporder",
            "cfg_share_links",
            "files_markdown",
            "extract"
        ],
        "mail_sendmailmode": "smtp",
        "memories.exiftool": "\/var\/www\/nextcloud\/apps\/memories\/bin-ext\/exiftool-amd64-glibc",
        "memories.vod.path": "\/var\/www\/nextcloud\/apps\/memories\/bin-ext\/go-vod-amd64",
        "memories.gis_type": 1,
        "enabledPreviewProviders": [
            "OC\\Preview\\Image"
        ],
        "memories.vod.ffmpeg": "\/usr\/bin\/ffmpeg",
        "memories.vod.ffprobe": "\/usr\/bin\/ffprobe",
        "memories.db.triggers.fcu": true
    }
}

List of activated Apps

Before upgrade attempt ....

Enabled:
  - activity: 2.21.1
  - admin_audit: 1.19.0
  - appointments: 2.1.12
  - apporder: 0.15.0
  - calendar: 4.7.16
  - cfg_share_links: 6.1.1
  - cloud_federation_api: 1.12.0
  - comments: 1.19.0
  - contacts: 6.0.0
  - dav: 1.30.1
  - extract: 1.3.6
  - federatedfilesharing: 1.19.0
  - files: 2.1.1
  - files_accesscontrol: 1.19.1
  - files_automatedtagging: 1.19.0
  - files_downloadlimit: 2.0.0
  - files_markdown: 2.4.1
  - files_notify_redis: 0.3.4
  - files_pdfviewer: 2.10.0
  - files_reminders: 1.2.0
  - files_sharing: 1.21.0
  - files_trashbin: 1.19.0
  - files_versions: 1.22.0
  - firstrunwizard: 2.18.0
  - groupfolders: 17.0.5
  - guests: 3.2.0
  - impersonate: 1.16.0
  - issuetemplate: 0.7.0
  - lookup_server_connector: 1.17.0
  - mail: 3.7.9
  - maps: 1.4.0
  - memories: 7.4.1
  - nextcloud_announcements: 1.18.0
  - notes: 4.11.0
  - notifications: 2.17.0
  - notify_push: 0.7.0
  - oauth2: 1.17.1
  - password_policy: 1.19.0
  - phonetrack: 0.8.1
  - photos: 2.5.0
  - previewgenerator: 5.6.0
  - privacy: 1.13.0
  - provisioning_api: 1.19.0
  - recognize: 7.1.0
  - related_resources: 1.4.0
  - settings: 1.12.0
  - sharebymail: 1.19.0
  - systemtags: 1.19.0
  - tasks: 0.16.1
  - text: 3.10.1
  - theming: 2.4.0
  - theming_customcss: 1.17.0
  - twofactor_backupcodes: 1.18.0
  - updatenotification: 1.19.1
  - viewer: 2.3.0
  - workflowengine: 2.11.0
Disabled:
  - bruteforcesettings: 2.9.0 (installed 2.7.0)
  - circles: 29.0.0-dev (installed 23.1.0)
  - contactsinteraction: 1.10.0 (installed 1.4.0)
  - dashboard: 7.9.0 (installed 7.3.0)
  - encryption: 2.17.0
  - external: 5.4.1 (installed 5.4.1)
  - federation: 1.19.0 (installed 1.8.0)
  - files_external: 1.21.0
  - logreader: 2.14.0 (installed 2.13.0)
  - onlyoffice: 9.5.0 (installed 9.5.0)
  - recommendations: 2.1.0 (installed 0.6.0)
  - serverinfo: 1.19.0 (installed 1.13.0)
  - support: 1.12.0 (installed 1.1.1)
  - survey_client: 1.17.0 (installed 1.11.0)
  - suspicious_login: 7.0.0 (installed 5.0.0)
  - twofactor_totp: 11.0.0-dev
  - user_ldap: 1.20.0
  - user_status: 1.9.0 (installed 1.3.1)
  - weather_status: 1.9.0 (installed 1.3.0)

Nextcloud Signing status

Before upgrade attempt:     No errors have been found.

Nextcloud Logs

*Updater Log*
2024-11-20T20:20:21+0000 iERGwkeygn [info] updater started
2024-11-20T20:20:21+0000 iERGwkeygn [info] executeStep request for step "1"
2024-11-20T20:20:21+0000 iERGwkeygn [info] startStep("1")
2024-11-20T20:20:21+0000 iERGwkeygn [info] checkForExpectedFilesAndFolders()
2024-11-20T20:20:21+0000 iERGwkeygn [info] end of checkForExpectedFilesAndFolders()
2024-11-20T20:20:21+0000 iERGwkeygn [info] endStep("1")
2024-11-20T20:20:21+0000 iERGwkeygn [info] executeStep request for step "2"
2024-11-20T20:20:21+0000 iERGwkeygn [info] startStep("2")
2024-11-20T20:20:21+0000 iERGwkeygn [info] checkWritePermissions()
2024-11-20T20:20:21+0000 iERGwkeygn [info] end of checkWritePermissions()
2024-11-20T20:20:21+0000 iERGwkeygn [info] endStep("2")
2024-11-20T20:20:21+0000 iERGwkeygn [info] executeStep request for step "3"
2024-11-20T20:20:21+0000 iERGwkeygn [info] startStep("3")
2024-11-20T20:20:21+0000 iERGwkeygn [info] createBackup()
2024-11-20T20:20:21+0000 iERGwkeygn [info] backup folder location: /usr/local/nextcloud/data/updater-oc6zbizkfbbs/backups/nextcloud-29.0.9.2-1732134021/
2024-11-20T20:20:33+0000 iERGwkeygn [info] end of createBackup()
2024-11-20T20:20:33+0000 iERGwkeygn [info] endStep("3")
2024-11-20T20:20:33+0000 iERGwkeygn [info] executeStep request for step "4"
2024-11-20T20:20:33+0000 iERGwkeygn [info] startStep("4")
2024-11-20T20:20:33+0000 iERGwkeygn [info] downloadUpdate()
2024-11-20T20:20:33+0000 iERGwkeygn [info] getUpdateServerResponse()
2024-11-20T20:20:33+0000 iERGwkeygn [info] updaterServer: https://updates.nextcloud.com/updater_server/
2024-11-20T20:20:33+0000 iERGwkeygn [info] releaseChannel: stable
2024-11-20T20:20:33+0000 iERGwkeygn [info] internal version: 29.0.9.2
2024-11-20T20:20:33+0000 iERGwkeygn [info] updateURL: https://updates.nextcloud.com/updater_server/?version=29x0x9x2xxxstablexx2024-11-07T08%3A54%3A42%2B00%3A00+b35875a225e754cb4fc60e9b1d45d4178ac59d6dx8x3x6
2024-11-20T20:20:33+0000 iERGwkeygn [info] getUpdateServerResponse response: Array
(
    [version] => 30.0.2.2
    [versionstring] => Nextcloud 30.0.2
    [url] => https://download.nextcloud.com/server/releases/nextcloud-30.0.2.zip
    [web] => https://docs.nextcloud.com/server/30/admin_manual/maintenance/upgrade.html
    [changes] => https://updates.nextcloud.com/changelog_server/?version=30.0.2
    [autoupdater] => 1
    [eol] => 0
    [signature] => [REDACTED - don't know if this is sensitive]
)

2024-11-20T20:20:33+0000 iERGwkeygn [info] storage location exists
2024-11-20T20:20:48+0000 iERGwkeygn [info] end of downloadUpdate()
2024-11-20T20:20:48+0000 iERGwkeygn [info] endStep("4")
2024-11-20T20:20:48+0000 iERGwkeygn [info] executeStep request for step "5"
2024-11-20T20:20:48+0000 iERGwkeygn [info] startStep("5")
2024-11-20T20:20:48+0000 iERGwkeygn [info] verifyIntegrity()
2024-11-20T20:20:48+0000 iERGwkeygn [info] getUpdateServerResponse()
2024-11-20T20:20:48+0000 iERGwkeygn [info] updaterServer: https://updates.nextcloud.com/updater_server/
2024-11-20T20:20:48+0000 iERGwkeygn [info] releaseChannel: stable
2024-11-20T20:20:48+0000 iERGwkeygn [info] internal version: 29.0.9.2
2024-11-20T20:20:48+0000 iERGwkeygn [info] updateURL: https://updates.nextcloud.com/updater_server/?version=29x0x9x2xxxstablexx2024-11-07T08%3A54%3A42%2B00%3A00+b35875a225e754cb4fc60e9b1d45d4178ac59d6dx8x3x6
2024-11-20T20:20:49+0000 iERGwkeygn [info] getUpdateServerResponse response: Array
(
    [version] => 30.0.2.2
    [versionstring] => Nextcloud 30.0.2
    [url] => https://download.nextcloud.com/server/releases/nextcloud-30.0.2.zip
    [web] => https://docs.nextcloud.com/server/30/admin_manual/maintenance/upgrade.html
    [changes] => https://updates.nextcloud.com/changelog_server/?version=30.0.2
    [autoupdater] => 1
    [eol] => 0
    [signature] => [REDACTED - don't know if this is sensitive]
)

2024-11-20T20:20:49+0000 iERGwkeygn [info] storage location: /usr/local/nextcloud/data/updater-oc6zbizkfbbs/downloads/
2024-11-20T20:20:49+0000 iERGwkeygn [info] end of verifyIntegrity()
2024-11-20T20:20:49+0000 iERGwkeygn [info] endStep("5")
2024-11-20T20:20:49+0000 iERGwkeygn [info] executeStep request for step "6"
2024-11-20T20:20:49+0000 iERGwkeygn [info] startStep("6")
2024-11-20T20:20:49+0000 iERGwkeygn [info] extractDownload()
2024-11-20T20:20:49+0000 iERGwkeygn [info] storage location: /usr/local/nextcloud/data/updater-oc6zbizkfbbs/downloads/
2024-11-20T20:20:51+0000 iERGwkeygn [info] end of extractDownload()
2024-11-20T20:20:51+0000 iERGwkeygn [info] endStep("6")
2024-11-20T20:20:51+0000 iERGwkeygn [info] executeStep request for step "7"
2024-11-20T20:20:51+0000 iERGwkeygn [info] startStep("7")
2024-11-20T20:20:51+0000 iERGwkeygn [info] setMaintenanceMode("true")
2024-11-20T20:20:51+0000 iERGwkeygn [info] configFileName /var/www/nextcloud/updater/../config/config.php
2024-11-20T20:20:51+0000 iERGwkeygn [info] end of setMaintenanceMode()
2024-11-20T20:20:51+0000 iERGwkeygn [info] endStep("7")
2024-11-20T20:20:51+0000 iERGwkeygn [info] executeStep request for step "8"
2024-11-20T20:20:51+0000 iERGwkeygn [info] startStep("8")
2024-11-20T20:20:51+0000 iERGwkeygn [info] replaceEntryPoints()
2024-11-20T20:20:51+0000 iERGwkeygn [info] replace index.php
2024-11-20T20:20:51+0000 iERGwkeygn [info] replace status.php
2024-11-20T20:20:51+0000 iERGwkeygn [info] replace remote.php
2024-11-20T20:20:51+0000 iERGwkeygn [info] replace public.php
2024-11-20T20:20:51+0000 iERGwkeygn [info] replace ocs/v1.php
2024-11-20T20:20:51+0000 iERGwkeygn [info] replace ocs/v2.php
2024-11-20T20:20:51+0000 iERGwkeygn [info] end of replaceEntryPoints()
2024-11-20T20:20:51+0000 iERGwkeygn [info] endStep("8")
2024-11-20T20:20:51+0000 iERGwkeygn [info] executeStep request for step "9"
2024-11-20T20:20:51+0000 iERGwkeygn [info] startStep("9")
2024-11-20T20:20:51+0000 iERGwkeygn [info] deleteOldFiles()
2024-11-20T20:20:51+0000 iERGwkeygn [info] config sample exists
2024-11-20T20:20:51+0000 iERGwkeygn [info] themes README exists
2024-11-20T20:20:51+0000 iERGwkeygn [info] end of deleteOldFiles()
2024-11-20T20:20:51+0000 iERGwkeygn [info] endStep("9")
2024-11-20T20:20:51+0000 iERGwkeygn [info] executeStep request for step "10"
2024-11-20T20:20:51+0000 iERGwkeygn [info] startStep("10")
2024-11-20T20:20:51+0000 iERGwkeygn [info] moveNewVersionInPlace()
2024-11-20T20:20:51+0000 iERGwkeygn [info] storage location: /usr/local/nextcloud/data/updater-oc6zbizkfbbs/downloads/nextcloud/
2024-11-20T20:20:52+0000 iERGwkeygn [info] end of moveNewVersionInPlace()
2024-11-20T20:20:52+0000 iERGwkeygn [info] endStep("10")
2024-11-20T20:20:52+0000 iERGwkeygn [info] executeStep request for step "12"
2024-11-20T20:20:52+0000 iERGwkeygn [info] startStep("12")
2024-11-20T20:20:52+0000 iERGwkeygn [info] finalize()
2024-11-20T20:20:52+0000 iERGwkeygn [info] storage location: /usr/local/nextcloud/data/updater-oc6zbizkfbbs/downloads/nextcloud/
2024-11-20T20:20:52+0000 iERGwkeygn [info] call opcache_reset()
2024-11-20T20:20:52+0000 iERGwkeygn [info] end of finalize()
2024-11-20T20:20:52+0000 iERGwkeygn [info] endStep("12")
2024-11-20T20:20:52+0000 iERGwkeygn [info] update of code successful.
2024-11-20T20:23:09+0000 iERGwkeygn [info] maintenance mode is disabled - return code: 0

nextcloud.log is empty.

Additional info

After one failed attempt, I examined the named table and found no data in that column. I deleted the column and retried, but it failed the same way. Examining a mysql backup taken just before the update, I found that the column did exist prior to initiating the upgrade.

joshtrichards commented 1 day ago

Exception: Database error when running migration 30000Date20240717111406 for app core The column "webhook_uri" on table "oc_taskprocessing_tasks" already exists.

I don't see how you could have this column when upgrading from v29. It didn't even exist until v30 (#46579) and was never backported. It doesn't even exist in the v29 code base.

After one failed attempt, I examined the named table and found no data in that column. I deleted the column and retried, but it failed the same way.

Say what? 🤔

Examining a mysql backup taken just before the update, I found that the column did exist prior to initiating the upgrade.

Still a mystery.

Are you sure you don't have multiple Nextcloud instances deployed or something? Like another test instance (maybe that isn't even around anymore) that was previously upgraded that is somehow connected to the same db? Or maybe you attempted a v30 upgrade previously that was aborted for some reason? (Just tossing out ideas to brainstorm: I'm not sure why you encountered this).

There was one similar (but not exactly the same) report in #48372. We can easily check for the column in the migration (before adding the column - basically like #48480), but I fear that's just working around a situation that doesn't make sense to start with. :-)

joshtrichards commented 1 day ago

One thing to comes to mind: #46889 / #46476. Though my understanding is those annotations are just metadata so they really shouldn't be a culprit.

bpmartin20 commented 1 day ago

Thank you for the amazingly prompt response. Yes, I've tried the upgrade several times, and apparently I failed to roll the database back successfully somewhere along the line. That explains why I'm the only one seeing this ~~bug~~ issue.

Now the question is how to move forward. Enough time has passed since my first attempts at the upgrade that I can't really roll the database back even if I knew when to roll it back to. I am now running a complete duplicate of my Nextcloud server on a separate machine, so I can test stuff without impacting my production environment. I tried dropping the webhook_uri and webhook_method columns from oc_taskprocessing_tasks, which by the way is an empty table. With that, I was able to run the upgrade successfully in my test environment.

Given that, how would you recommend I proceed? I can do the above, something more, or go as far as reinstalling Nextcloud from scratch if that's what you recommend, so long as when I get done we have all our users, passwords, calendar entries, etc., etc. Any guidance would be greatly appreciated.

nextcloud / server