[bug] Internal Server Error after installation of 29.0.5

walterzilla commented 1 month ago

Setting up brand new istance using stock composer file with latest nextcloud image results in Internal Server Error shortly after pressing Install button.

No errors in containers log but inside NC one I can found following:

Failed to open stream: No such file or directory at /var/www/html/lib/private/Config.php

Anyway said file is there...

Quick workaround would be installing and upgrading previous minor release (29.0.4) but in that case one's facing a Connection refused error which requires editing mariadb container's default hostname (from container's one to host's one) so maybe would be better installing and upgrading previous major release (28.0.9) instead.

joshtrichards commented 1 month ago

Reproduced.

Did not find a resolution unfortunately, but sharing my notes in case someone else picks it up before I'm able to look at it again (it's late here).

Highlights of weird things observed:

Nextcloud isn't logging a stack trace (below is once debug is on, pulled from the browser; it's not logged)
The below stack trace is likely a red herring; I believe it's merely because of the next item
There's an SQLite db in the datadirectory (i.e. owncloud.db) [this is a mysql stack + config.php is populated as expected for mysql]
We didn't actually change anything in the image itself other than bump the version of Nextcloud deployed in it. All changes were upstream (nextcloud, php, debian, possibly some extensions)
Clearly impacts installs, but not sure if it impacts updates broadly yet
Need to re-test our own rebuilds (versus the published builds)
Further notes below

An exception occurred while executing a query: SQLSTATE[42S02]: Base table or view not found: 1146 Table 'ncdb.oc_appconfig' doesn't exist /var/www/html/lib/private/DB/Exceptions/DbalException.php at 71
#0 /var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php(295): OC\DB\Exceptions\DbalException::wrap(Object(Doctrine\DBAL\Exception\TableNotFoundException))
#1 /var/www/html/lib/private/AppConfig.php(1246): OC\DB\QueryBuilder\QueryBuilder->executeQuery()
#2 /var/www/html/lib/private/AppConfig.php(264): OC\AppConfig->loadConfig(false)
#3 /var/www/html/lib/private/legacy/OC_App.php(736): OC\AppConfig->searchValues('installed_versi...')
#4 /var/www/html/lib/private/Server.php(694): OC_App::getAppVersions()
#5 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(175): OC\Server->OC\{closure}(Object(OC\Server))
#6 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(122): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(Pimple\Container))
#7 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(142): Pimple\Container->offsetGet('OC\\Memcache\\Fac...')
#8 /var/www/html/lib/private/ServerContainer.php(173): OC\AppFramework\Utility\SimpleContainer->query('OC\\Memcache\\Fac...', true)
#9 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(64): OC\ServerContainer->query('OC\\Memcache\\Fac...')
#10 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(197): OC\AppFramework\Utility\SimpleContainer->get('OC\\Memcache\\Fac...')
#11 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(175): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(OC\Server))
#12 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(Pimple\Container))
#13 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(142): Pimple\Container->offsetGet('OCP\\ICacheFacto...')
#14 /var/www/html/lib/private/ServerContainer.php(173): OC\AppFramework\Utility\SimpleContainer->query('OCP\\ICacheFacto...', true)
#15 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(96): OC\ServerContainer->query('OCP\\ICacheFacto...', true)
#16 [internal function]: OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(ReflectionParameter))
#17 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(83): array_map(Object(Closure), Array)
#18 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(128): OC\AppFramework\Utility\SimpleContainer->buildClass(Object(ReflectionClass))
#19 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(146): OC\AppFramework\Utility\SimpleContainer->resolve('OC\\User\\Manager')
#20 /var/www/html/lib/private/ServerContainer.php(173): OC\AppFramework\Utility\SimpleContainer->query('OC\\User\\Manager', true)
#21 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(64): OC\ServerContainer->query('OC\\User\\Manager')
#22 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(197): OC\AppFramework\Utility\SimpleContainer->get('OC\\User\\Manager')
#23 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(175): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(OC\Server))
#24 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(Pimple\Container))
#25 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(142): Pimple\Container->offsetGet('OCP\\IUserManage...')
#26 /var/www/html/lib/private/ServerContainer.php(173): OC\AppFramework\Utility\SimpleContainer->query('OCP\\IUserManage...', true)
#27 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(64): OC\ServerContainer->query('OCP\\IUserManage...')
#28 /var/www/html/lib/private/Server.php(534): OC\AppFramework\Utility\SimpleContainer->get('OCP\\IUserManage...')
#29 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(175): OC\Server->OC\{closure}(Object(OC\Server))
#30 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(122): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(Pimple\Container))
#31 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(142): Pimple\Container->offsetGet('OC\\User\\Session')
#32 /var/www/html/lib/private/ServerContainer.php(173): OC\AppFramework\Utility\SimpleContainer->query('OC\\User\\Session', true)
#33 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(64): OC\ServerContainer->query('OC\\User\\Session')
#34 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(197): OC\AppFramework\Utility\SimpleContainer->get('OC\\User\\Session')
#35 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(175): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(OC\Server))
#36 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(Pimple\Container))
#37 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(142): Pimple\Container->offsetGet('OCP\\IUserSessio...')
#38 /var/www/html/lib/private/ServerContainer.php(173): OC\AppFramework\Utility\SimpleContainer->query('OCP\\IUserSessio...', true)
#39 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(64): OC\ServerContainer->query('OCP\\IUserSessio...')
#40 /var/www/html/lib/private/Server.php(1361): OC\AppFramework\Utility\SimpleContainer->get('OCP\\IUserSessio...')
#41 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(175): OC\Server->OC\{closure}(Object(OC\Server))
#42 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(Pimple\Container))
#43 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(142): Pimple\Container->offsetGet('OCP\\ISession')
#44 /var/www/html/lib/private/ServerContainer.php(173): OC\AppFramework\Utility\SimpleContainer->query('OCP\\ISession', true)
#45 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(64): OC\ServerContainer->query('OCP\\ISession')
#46 /var/www/html/lib/private/Server.php(1252): OC\AppFramework\Utility\SimpleContainer->get('OCP\\ISession')
#47 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(175): OC\Server->OC\{closure}(Object(OC\Server))
#48 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(122): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(Pimple\Container))
#49 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(142): Pimple\Container->offsetGet('OC\\Security\\CSR...')
#50 /var/www/html/lib/private/ServerContainer.php(173): OC\AppFramework\Utility\SimpleContainer->query('OC\\Security\\CSR...', true)
#51 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(96): OC\ServerContainer->query('OC\\Security\\CSR...', true)
#52 [internal function]: OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(ReflectionParameter))
#53 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(83): array_map(Object(Closure), Array)
#54 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(128): OC\AppFramework\Utility\SimpleContainer->buildClass(Object(ReflectionClass))
#55 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(146): OC\AppFramework\Utility\SimpleContainer->resolve('OC\\Security\\CSR...')
#56 /var/www/html/lib/private/ServerContainer.php(173): OC\AppFramework\Utility\SimpleContainer->query('OC\\Security\\CSR...', true)
#57 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(64): OC\ServerContainer->query('OC\\Security\\CSR...')
#58 /var/www/html/lib/private/Server.php(1044): OC\AppFramework\Utility\SimpleContainer->get('OC\\Security\\CSR...')
#59 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(175): OC\Server->OC\{closure}(Object(OC\Server))
#60 /var/www/html/3rdparty/pimple/pimple/src/Pimple/Container.php(122): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(Pimple\Container))
#61 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(142): Pimple\Container->offsetGet('OCP\\IRequest')
#62 /var/www/html/lib/private/ServerContainer.php(173): OC\AppFramework\Utility\SimpleContainer->query('OCP\\IRequest', true)
#63 /var/www/html/lib/private/AppFramework/Utility/SimpleContainer.php(64): OC\ServerContainer->query('OCP\\IRequest')
#64 /var/www/html/lib/private/Server.php(1526): OC\AppFramework\Utility\SimpleContainer->get('OCP\\IRequest')
#65 /var/www/html/lib/private/legacy/OC_Template.php(309): OC\Server->getRequest()
#66 /var/www/html/index.php(114): OC_Template::printExceptionErrorPage(Object(OC\DB\Exceptions\DbalException), 500)
#67 {main}

Weird. Looks like it should be something simple, but I don't know what's going on. (I believe the above error is a red herring; it's likely simply because of the SQLite <--> MySQL db mix-up... which is closer to the real underlying issue).

Fails right after creating initial admin account
Only entry in nextcloud.log doesn't match reality (at least in the moments later when checked).
- the config.php exists, is readable (by www-data), etc.
There is a SQLite db (owncloud.db) in the datadirectory
- This is weird (set to mysql at the time)
- The config.php is correct db-wise (e.g. mysql, etc.)
Nextcloud log never gets anything else in it
- i.e. The barebones Internal Server Error browser-side, but successive accesses (HTTP transactions) don't generate log entries,
- This is weird.
- With debug on the browser sees a stack trace
No specifics in the Apache error log (via docker log)
- Even removed /var/log/apache2/error.log symlink to /dev/stderr to verify directly
Appears to be a 500 generated solely by Nextcloud, but:
- Nextcloud isn't logging anything beyond the (presumed) first time
- This is weird.
Replacing index.php behaves as expected (i.e. works)

Here in the docker image repository, we didn't change anything in our Dockerfile other than the version bump.

Most likely culprits:

Something that we did here in docker image that I'm overlooking :thinking:
Something upstream in server that is showing up in our image for an unknown reason :thinking:
Something in PHP (since the version changed and there were a number of fixes in it)

Test ideas:

[x] Turn up the logging level and see if we get lucky
[x] Turn on debugging and see if we get lucky
[ ] Is our 28.0.9 image broken too?
[ ] Is a self-built image broken too?
[ ] Is a self-built 29.0.5 against prior php base image too?
[ ] Are "only" new installers impacted or updaters too?
[ ] Is anyone not impacted by this?
[ ] Trace process

TODO:

[ ] Tests (above)
[ ] Withdraw image? / push update when we have a fix (Cc: @J0WI)

Main obvious changes in our upstreams:

nextcloud bumped 29.0.4->29.0.5
- obviously lots of changes here
php base image bumped from PHP 8.2.21->8.2.22
- no changes image itself: just a version bump
- loads of changes in PHP: https://www.php.net/ChangeLog-8.php
some relevant bookworm changes possibly, but not in apache
possibly some changes in our extensions (bookworm packages + pecl)
dockerized debian base image
Docker Engine
Underlying hosts themselves (OS updates, etc.)

walterzilla commented 1 month ago

Is our 28.0.9 image broken too?

As mentioned before, installing and upgrading 28.0.9 and 29.0.4 images works fine (except for that minor issue with the latter).

Thanks for your prompt and careful remarks.

joshtrichards commented 1 month ago

Possible workaround: Specify NEXTCLOUD_ADMIN_USER and NEXTCLOUD_ADMIN_PASSWORD (skips the web installer)

h4b4n3r0 commented 1 month ago

Oh man. :P Yesterday everything was working with my test setup and today ... it drove me crazy. Thanks for giving the hint with the additional env variables. It worked for me!

joshtrichards commented 1 month ago

Underlying issue (as deep as I've gotten so far) seems to be that regardless of db parameters specified, the web installer is starting out with an SQLite based install, but it finishes with the correct db type written to the config. So the wrong db is getting initialized. This obviously breaks things.

It's also notable that doing an intentional sqlite install breaks too because the default sqlite db name (owncloud.db) is what the web install starts out with, but it finishes with the correct (specified) db. Breaking in the same way. SQlite however will work through if you specify/use the default sqlite db name (presumably because even though the installer is misbehaving in sqlite mode too, the db names at least match before/after so it works out anyhow).

The difference when using workaround noted above (specifying NEXTCLOUD_ADMIN_USER and NEXTCLOUD_ADMIN_PASSWORD) is that the Docker image entrypoint runs the occ maintenance:install with all the necessary parameters directly rather than using the web installer.

I suspect this is related to upstream (server) nextcloud/server#46931 or thereabouts. This is the main db change in 29.0.5 (and a more significant one than would normally occur in a maintenance release, but necessary to fix a bigger issue).

The new replica stuff has created problems elsewhere when it comes to db option merging/management (e.g. with the occ db:convert-type, which currently remains unfixed).

The installer's db handling is a little weird already. And there are additional differences between the web installer mode and the occ mode. So I guess in that sense I'm not entirely surprised there was collateral damage (if my hypothesis is right anyhow).

Actual root cause still to be determined.

I actually would really like to see what happens when someone does a bare metal install of v29.0.5 and configures via the web installer. I would expect the same problems, but there's a chance it won't come up if autoconfig.php also isn't in the mix (which we use in the image, but is probably somewhat less common for bare metal users).

walterzilla commented 1 month ago

Possible workaround: Specify NEXTCLOUD_ADMIN_USER and NEXTCLOUD_ADMIN_PASSWORD (skips the web installer)

Interesting idea...but I have to point out that in my case doing so results in at least two collateral inconveniences:

trusted_domains config var being set to localhost
security warning Your data directory and files are probably accessible from the internet (etc etc...) appearing

Both of them (especially first one) can be fixed in no time if one knows where to put its hands, still I guess meanwhile better stick to a more straightforward workaround like upgrading from previous release...

joshtrichards commented 1 month ago

You can set NEXTCLOUD_TRUSTED_DOMAINS too.

walterzilla commented 1 month ago

You can set NEXTCLOUD_TRUSTED_DOMAINS too.

Sure, that's the reason I wrote expecially first one...still it takes some more effort to solve second one so I reckon it's going to be only a waste of time for a docker typical user wishing to keep things simple.

joshtrichards commented 3 weeks ago

Confirmed to be upstream (server) as suspected.

Fixed in nextcloud/server#47521

joshtrichards commented 3 weeks ago

Keeping open until:

[x] Upstream backport is merged into stable29: nextcloud/server#47549
[x] Upstream publishes a new release (29.0.6): tracker TBD
- [x] RC1 published: https://github.com/nextcloud/server/releases/tag/v29.0.6rc1
- [x] Final: https://github.com/nextcloud-releases/updater_server/pull/1113
[x] We publish a new image after the above are completed

joshtrichards commented 2 weeks ago

Upstream 29.0.6 published formally: nextcloud-releases/updater_server#1113

joshtrichards commented 2 weeks ago

https://github.com/nextcloud/docker/releases/tag/v2024.8.2

nextcloud / docker

[bug] Internal Server Error after installation of 29.0.5 #2283