Stuck in maintenance mode after successful update to 10.0.10.4

droid001 · January 10, 2019, 8:51pm

I’ve gone through a successful update from 10.0.3 to 10.0.10.4 but after some problems from attempting to update via the web update link in the admin panel.
I noticed that the /config folder which had previously been symlinked to an external disk wasn’t there any longer. I have since copied the config.php file on the external disk to the oc root config directory.
I managed to disable the apps via command-line sudo -u www-data php occ app:disable xyz and do the update sudo -u www-data php occ upgrade. The permission are now hardened, I took the instance out of maintenance mode with sudo -u www-data php occ maintenance:mode --off and the server is rebooted.
My ownCloud instance is still in maintenance mode though. Can there be something still hanging in the database which keeps it in maintenance mode?

Server configuration

Debian 9 (headless server)
Apache
MariaDB
PHP 7.0.33-0+deb9u1 (cli)
ownCloud 10.0.10.4, updated from 10.0.3 from debian package management

Signing status (ownCloud 9.0 and above):

Login as admin user into your ownCloud and access 
http://example.com/index.php/settings/integrity/failed 
paste the results into https://gist.github.com/ and puth the link here.

Unable to login to above mentioned link as oc instance is in maintenance mode

The content of config/config.php:

{
    "system": {
        "instanceid": "ocbee371e3ba",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            0 => '192.168.200.50',
            1 => 'pacolola.net',
        ],
        "datadirectory": "\/freecom\/owncloud\/data",
        "overwrite.cli.url": "http:\/\/192.168.200.50\/owncloud",
        "dbtype": "mysql",
        "version": "10.0.10.4",
        "dbname": "owncloud",
        "dbhost": "localhost",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "forcessl": true,
        "loglevel": "1",
        "mail_smtpmode": "smtp",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpauthtype": "LOGIN",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": "465",
        "mail_smtpauth": 1,
        "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
        "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpsecure": "ssl",
        "updatechecker": false,
        "maintenance": true,
        "singleuser": false
    }
}

List of activated apps:

Enabled:
  - dav: 0.4.0
  - federatedfilesharing: 0.3.1
  - federation: 0.1.0
  - files: 1.5.1
  - files_external: 0.7.1
Disabled:
  - comments
  - configreport
  - encryption
  - external
  - files_sharing
  - files_trashbin
  - files_versions
  - files_videoplayer
  - firstrunwizard
  - market
  - notifications
  - provisioning_api
  - systemtags
  - updatenotification
  - user_external

Are you using external storage, if yes which one: no

Are you using encryption: no

Are you using an external user-backend, if yes which one: no

Client configuration

Operating system:

Logs

Web server error log

[Thu Jan 10 06:25:04.849797 2019] [mpm_prefork:notice] [pid 31116] AH00163: Apache/2.4.25 (Debian) OpenSSL/1.0.2q configured -- resuming normal operations
[Thu Jan 10 06:25:04.849850 2019] [core:notice] [pid 31116] AH00094: Command line: '/usr/sbin/apache2'
[Thu Jan 10 06:35:31.902687 2019] [mpm_prefork:notice] [pid 31116] AH00169: caught SIGTERM, shutting down
[Thu Jan 10 06:35:32.551962 2019] [mpm_prefork:notice] [pid 23815] AH00163: Apache/2.4.25 (Debian) OpenSSL/1.0.2q configured -- resuming normal operations
[Thu Jan 10 06:35:32.552344 2019] [core:notice] [pid 23815] AH00094: Command line: '/usr/sbin/apache2'
[Thu Jan 10 06:37:58.607386 2019] [mpm_prefork:notice] [pid 23815] AH00169: caught SIGTERM, shutting down
[Thu Jan 10 06:37:59.264973 2019] [mpm_prefork:notice] [pid 23860] AH00163: Apache/2.4.25 (Debian) OpenSSL/1.0.2q configured -- resuming normal operations
[Thu Jan 10 06:37:59.265361 2019] [core:notice] [pid 23860] AH00094: Command line: '/usr/sbin/apache2'
[Thu Jan 10 07:03:40.897263 2019] [mpm_prefork:notice] [pid 23860] AH00169: caught SIGTERM, shutting down
[Thu Jan 10 07:03:41.552586 2019] [mpm_prefork:notice] [pid 24181] AH00163: Apache/2.4.25 (Debian) OpenSSL/1.0.2q configured -- resuming normal operations
[Thu Jan 10 07:03:41.552971 2019] [core:notice] [pid 24181] AH00094: Command line: '/usr/sbin/apache2'
[Thu Jan 10 07:51:46.735036 2019] [mpm_prefork:notice] [pid 24181] AH00169: caught SIGTERM, shutting down
[Thu Jan 10 12:22:43.651665 2019] [mpm_prefork:notice] [pid 26799] AH00163: Apache/2.4.25 (Debian) OpenSSL/1.0.2q configured -- resuming normal operations
[Thu Jan 10 12:22:43.652139 2019] [core:notice] [pid 26799] AH00094: Command line: '/usr/sbin/apache2'

ownCloud log (data/owncloud.log)

gist.github.com

https://gist.github.com/droid001/c77c58b8adc6843476206d11ab272641

owncloud-2019-01-10

{"reqId":"49W3zuOCQoEOrJlbiqYJ","level":4,"time":"2019-01-10T06:06:47+00:00","remoteAddr":"80.216.185.28","user":"--","app":"webdav","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/","message":"Exception: HTTP\/1.1 503 System in maintenance mode.: {\"Exception\":\"Sabre\\\\DAV\\\\Exception\\\\ServiceUnavailable\",\"Message\":\"System in maintenance mode.\",\"Code\":0,\"Trace\":\"#0 [internal function]: OCA\\\\DAV\\\\Connector\\\\Sabre\\\\MaintenancePlugin->checkMaintenanceMode(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#1 \\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#2 \\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(466): Sabre\\\\Event\\\\EventEmitter->emit('beforeMethod', Array)\\n#3 \\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#4 \\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Server.php(298): Sabre\\\\DAV\\\\Server->exec()\\n#5 \\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(31): OCA\\\\DAV\\\\Server->exec()\\n#6 \\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/remote.php(165): require_once('\\\/var\\\/www\\\/pacolo...')\\n#7 {main}\",\"File\":\"\\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/MaintenancePlugin.php\",\"Line\":82}"}
{"reqId":"WYf8m54CRrSKUovsob4V","level":0,"time":"2019-01-10T06:07:29+00:00","remoteAddr":"","user":"--","app":"core","method":"--","url":"--","message":"starting upgrade from 10.0.3 to 10.0.10.4"}
{"reqId":"WYf8m54CRrSKUovsob4V","level":3,"time":"2019-01-10T06:07:30+00:00","remoteAddr":"","user":"--","app":"PHP","method":"--","url":"--","message":"str_repeat(): Second argument has to be greater than or equal to 0 at \/var\/www\/owncloud\/lib\/composer\/symfony\/console\/Helper\/ProgressBar.php#512"}
{"reqId":"WYf8m54CRrSKUovsob4V","level":3,"time":"2019-01-10T06:07:30+00:00","remoteAddr":"","user":"--","app":"PHP","method":"--","url":"--","message":"str_repeat(): Second argument has to be greater than or equal to 0 at \/var\/www\/owncloud\/lib\/composer\/symfony\/console\/Helper\/ProgressBar.php#512"}
{"reqId":"WYf8m54CRrSKUovsob4V","level":3,"time":"2019-01-10T06:07:30+00:00","remoteAddr":"","user":"--","app":"PHP","method":"--","url":"--","message":"str_repeat(): Second argument has to be greater than or equal to 0 at \/var\/www\/owncloud\/lib\/composer\/symfony\/console\/Helper\/ProgressBar.php#512"}
{"reqId":"WYf8m54CRrSKUovsob4V","level":3,"time":"2019-01-10T06:07:30+00:00","remoteAddr":"","user":"--","app":"PHP","method":"--","url":"--","message":"str_repeat(): Second argument has to be greater than or equal to 0 at \/var\/www\/owncloud\/lib\/composer\/symfony\/console\/Helper\/ProgressBar.php#512"}
{"reqId":"WYf8m54CRrSKUovsob4V","level":3,"time":"2019-01-10T06:07:30+00:00","remoteAddr":"","user":"--","app":"PHP","method":"--","url":"--","message":"str_repeat(): Second argument has to be greater than or equal to 0 at \/var\/www\/owncloud\/lib\/composer\/symfony\/console\/Helper\/ProgressBar.php#512"}
{"reqId":"WYf8m54CRrSKUovsob4V","level":3,"time":"2019-01-10T06:07:30+00:00","remoteAddr":"","user":"--","app":"PHP","method":"--","url":"--","message":"str_repeat(): Second argument has to be greater than or equal to 0 at \/var\/www\/owncloud\/lib\/composer\/symfony\/console\/Helper\/ProgressBar.php#512"}
{"reqId":"WYf8m54CRrSKUovsob4V","level":3,"time":"2019-01-10T06:07:30+00:00","remoteAddr":"","user":"--","app":"PHP","method":"--","url":"--","message":"str_repeat(): Second argument has to be greater than or equal to 0 at \/var\/www\/owncloud\/lib\/composer\/symfony\/console\/Helper\/ProgressBar.php#512"}
{"reqId":"WYf8m54CRrSKUovsob4V","level":3,"time":"2019-01-10T06:07:30+00:00","remoteAddr":"","user":"--","app":"PHP","method":"--","url":"--","message":"str_repeat(): Second argument has to be greater than or equal to 0 at \/var\/www\/owncloud\/lib\/composer\/symfony\/console\/Helper\/ProgressBar.php#512"}

This file has been truncated. show original

Browser log

Content Security Policy: The page’s settings blocked the loading of a resource at inline (“script-src”).
failed:1:1
JQMIGRATE: Migrate is installed, version 1.4.0 jquery-migrate.min.js:2:542
Deprecation warning: tipsy is deprecated. Use tooltip instead. js.js:2296:2

tom42 · January 10, 2019, 3:57pm

Hey,

from what i know the maintenance mode is kept as long as this is set to true in your config.php:

Maybe the occ command doesn’t have write access to the config.php and this is never set to false?

droid001 · January 10, 2019, 4:37pm

Good point but I’ve double checked that and the fact that the version in config.php is now set to 10.0.10.4 indicates that the occ has write access to the file.

tom42 · January 10, 2019, 5:07pm

This looks really strange to me. As an alternative you could also set the parameter manually to “false” within your config.php.

droid001 · January 10, 2019, 7:59pm

The maintenance value is set to false for sure so there must be an other parameter or more likely a failure which insures the maintenance page is displayed.

alfredb · January 10, 2019, 8:05pm

My best guess is, that it tries to update some apps, thus switching to maintenance mode again.

droid001 · January 10, 2019, 8:28pm

I switched on maintenance mode on again and turned off the webserver and went through the app list
sudo -u www-data php occ app:list
…and tried turning off the remaining enabled apps. Managed to disable federation but the rest couldn’t be disabled. Now maintenance mode is off and and server restarted. Same situation though.

tom42 · January 10, 2019, 8:42pm

Have you made sure that you’re actually looking at the correct ownCloud installation and don’t work in a different / other installation location which is served by your web server?

droid001 · January 10, 2019, 8:46pm

There is only one installation which is located at /var/www/owncloud. As I mentioned earlier the config.php was written to in the last update when the version value was set to 10.0.10.4.

tom42 · January 10, 2019, 8:47pm

e.g. i was able to access your ownCloud installation via the last IP configured in your trusted_domain settings but still getting the “you’re accessing from an untrusted domain” message which seems to me that the config/config.php you have posted isn’t the one used by your ownCloud installation.

droid001 · January 10, 2019, 8:49pm

I’ve changed trusted domains just recently, testing if it helps. I will update the original question with what I’ve got now.

droid001 · January 10, 2019, 9:02pm

FYI I’m getting this repeatedly from tail which I’m running on data/owncloud.log:

{"reqId":"WWcoolL84QVr3ClvUIWw","level":4,"time":"2019-01-10T20:59:38+00:00","remoteAddr":"80.216.185.28","user":"--","app":"caldav","method":"PROPFIND","url":"\/owncloud\/remote.php\/caldav","message":"Exception: HTTP\/1.1 503 System in maintenance mode.: {\"Exception\":\"Sabre\\\\DAV\\\\Exception\\\\ServiceUnavailable\",\"Message\":\"System in maintenance mode.\",\"Code\":0,\"Trace\":\"#0 [internal function]: OCA\\\\DAV\\\\Connector\\\\Sabre\\\\MaintenancePlugin->checkMaintenanceMode(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#1 \\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#2 \\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(466): Sabre\\\\Event\\\\EventEmitter->emit('beforeMethod', Array)\\n#3 \\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#4 \\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/apps\\\/dav\\\/appinfo\\\/v1\\\/caldav.php(93): Sabre\\\\DAV\\\\Server->exec()\\n#5 \\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/remote.php(165): require_once('\\\/var\\\/www\\\/pacolo...')\\n#6 {main}\",\"File\":\"\\\/var\\\/www\\\/pacolola.net\\\/public\\\/owncloud\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/MaintenancePlugin.php\",\"Line\":82}"}

droid001 · January 10, 2019, 10:17pm

I tried the manual upgrade procedure just recently but came up with the same result.

tom42 · January 11, 2019, 5:03pm

Hey,

the posted logfiles looks quite interesting and seems to me confirming my previous assumption:

If you compare this:

with:

(I have redacted your actual hostname)

you can see that you have two different installations side-by-side. I think it is getting even worse when reading this:

From what i know the package management of debian is always installing to /var/www/owncloud and when using a different installation location or moving the location afterwards you can’t keep your installation up to date with the package management.

IIRC the installation via the package management in conjunction with the web updater could make things even more worse:

droid001 · January 11, 2019, 5:03pm

@tom42: You’re completely correct. There was an ownCloud instance in the subfolder of the main site. What pain. Thanks for being the second set of eyeballs on the problem. I’ll be off to figuring out how to retain the package management version of ownCloud while making a subdomain to the main site now.
@tom42 @alfredb Thanks for the help.