"Internal Server Error The server was unable to complete your request" After upgrading docker image

maeries · July 14, 2021, 4:20pm

When I try to login I get

Internal Server Error
The server was unable to complete your request.
If this happens again, please send the technical details below to the server administrator.
More details can be found in the server log

Technical Information
Remote Address: 172.19.0.4
xeTisVxTOQWzudx0rw8T

Nextcloud version: 22.0.0.11 as per the config.php
Operating system and version: Ubuntu 20.04 NC running via Docker
Additional Information: running behind caddy2 reverse proxy

Steps to replicate it:

I guess upgrade to the latest version. I have ouroboros and I guess it updated nextcloud
Go to the login page
Login

The output of your config.php file:

<?php
$CONFIG = array (
  'htaccess.RewriteBase' => '/',
  'memcache.local' => '\\OC\\Memcache\\APCu',
  'apps_paths' => 
  array (
    0 => 
    array (
      'path' => '/var/www/html/apps',
      'url' => '/apps',
      'writable' => false,
    ),
    1 => 
    array (
      'path' => '/var/www/html/custom_apps',
      'url' => '/custom_apps',
      'writable' => true,
    ),
  ),
  'instanceid' => 'aadfljk3g1k34',
  'passwordsalt' => 'afagvasASDGafg423rfAS',
  'secret' => 'asdf24adfav342SDA',
  'trusted_domains' => 
  array (
    0 => '192.168.11.3:8080',
    1 => 'sub.domain.tld',
  ),
  'datadirectory' => '/var/www/html/data',
  'dbtype' => 'mysql',
  'version' => '22.0.0.11',
  'overwrite.cli.url' => 'http://192.168.11.51:8080',
  'dbname' => 'nextcloud',
  'dbhost' => 'db',
  'dbport' => '',
  'dbtableprefix' => 'oc_',
  'mysql.utf8mb4' => true,
  'dbuser' => 'nextcloud',
  'dbpassword' => 'password',
  'installed' => true,
  'overwriteprotocol' => 'https',
  'maintenance' => false,
  'app_install_overwrite' => 
  array (
    0 => 'files_external_gdrive',
  ),
  'loglevel' => 0,
  'app.mail.verify-tls-peer' => false,
  'theme' => '',
  'memcache.distributed' => '\\OC\\Memcache\\Redis',
  'memcache.locking' => '\\OC\\Memcache\\Redis',
  'redis' => 
  array (
    'host' => 'redis',
    'password' => false,
    'port' => 6379,
  ),
);

The output of your Apache/nginx/system log in /var/log/____:

app_1    | Configuring Redis as session handler
db_1     | 2021-07-14 15:58:23+00:00 [Note] [Entrypoint]: Entrypoint script for MariaDB Server 1:10.6.3+maria~focal started.
db_1     | 2021-07-14 15:58:24+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
db_1     | 2021-07-14 15:58:24+00:00 [Note] [Entrypoint]: Entrypoint script for MariaDB Server 1:10.6.3+maria~focal started.
db_1     | 2021-07-14 15:58:24 0 [Note] mysqld (mysqld 10.6.3-MariaDB-1:10.6.3+maria~focal) starting as process 1 ...
db_1     | 2021-07-14 15:58:24 0 [Warning] You need to use --log-bin to make --binlog-format work.
db_1     | 2021-07-14 15:58:24 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
db_1     | 2021-07-14 15:58:24 0 [Note] InnoDB: Number of pools: 1
db_1     | 2021-07-14 15:58:24 0 [Note] InnoDB: Using generic crc32 instructions
db_1     | 2021-07-14 15:58:24 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
db_1     | 2021-07-14 15:58:24 0 [Note] InnoDB: Using Linux native AIO
db_1     | 2021-07-14 15:58:24 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
db_1     | 2021-07-14 15:58:24 0 [Note] InnoDB: Completed initialization of buffer pool
db_1     | 2021-07-14 15:58:24 0 [Note] InnoDB: 128 rollback segments are active.
db_1     | 2021-07-14 15:58:24 0 [Note] InnoDB: Creating shared tablespace for temporary tables
db_1     | 2021-07-14 15:58:24 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
redis_1  | 1:C 14 Jul 15:58:23.582 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
redis_1  | 1:C 14 Jul 15:58:23.582 # Redis version=4.0.14, bits=64, commit=00000000, modified=0, pid=1, just started
redis_1  | 1:C 14 Jul 15:58:23.582 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
redis_1  | 1:M 14 Jul 15:58:23.585 * Running mode=standalone, port=6379.
redis_1  | 1:M 14 Jul 15:58:23.585 # Server initialized
redis_1  | 1:M 14 Jul 15:58:23.585 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
db_1     | 2021-07-14 15:58:24 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
redis_1  | 1:M 14 Jul 15:58:23.585 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo never > /sys/kernel/mm/transparent_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled.
db_1     | 2021-07-14 15:58:24 0 [Note] InnoDB: 10.6.3 started; log sequence number 82217021177; transaction id 51163484
db_1     | 2021-07-14 15:58:24 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
db_1     | 2021-07-14 15:58:24 0 [Note] Plugin 'FEEDBACK' is disabled.
db_1     | 2021-07-14 15:58:24 0 [Warning] You need to use --log-bin to make --expire-logs-days or --binlog-expire-logs-seconds work.
db_1     | 2021-07-14 15:58:24 0 [Note] Server socket created on IP: '0.0.0.0'.
db_1     | 2021-07-14 15:58:24 0 [Note] Server socket created on IP: '::'.
db_1     | 2021-07-14 15:58:24 0 [Warning] 'proxies_priv' entry '@% root@2404a78c672b' ignored in --skip-name-resolve mode.
redis_1  | 1:M 14 Jul 15:58:23.653 * DB loaded from disk: 0.069 seconds
redis_1  | 1:M 14 Jul 15:58:23.653 * Ready to accept connections
db_1     | 2021-07-14 15:58:24 0 [ERROR] Incorrect definition of table mysql.event: expected column 'definer' at position 3 to have type varchar(, found type char(141).
db_1     | 2021-07-14 15:58:24 0 [ERROR] mysqld: Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler.
db_1     | 2021-07-14 15:58:24 0 [Note] mysqld: ready for connections.
db_1     | Version: '10.6.3-MariaDB-1:10.6.3+maria~focal'  socket: '/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
db_1     | 2021-07-14 15:58:25 0 [Note] InnoDB: Buffer pool(s) load completed at 210714 15:58:25
app_1    | AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.30.0.4. Set the 'ServerName' directive globally to suppress this message
app_1    | AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.30.0.4. Set the 'ServerName' directive globally to suppress this message
app_1    | [Wed Jul 14 15:58:26.010754 2021] [mpm_prefork:notice] [pid 1] AH00163: Apache/2.4.38 (Debian) PHP/7.4.21 configured -- resuming normal operations
app_1    | [Wed Jul 14 15:58:26.010882 2021] [core:notice] [pid 1] AH00094: Command line: 'apache2 -D FOREGROUND'
app_1    | 172.19.0.4 - Marius [14/Jul/2021:15:58:33 +0000] "GET /status.php HTTP/1.1" 200 1101 "-" "Mozilla/5.0 (Linux) mirall/3.2.2git (Nextcloud, manjaro-5.10.42-1-MANJARO ClientArchitecture: x86_64 OsArchitecture: x86_64)"
app_1    | 172.19.0.4 - Marius [14/Jul/2021:15:58:33 +0000] "PROPFIND /remote.php/webdav/ HTTP/1.1" 503 1080 "-" "Mozilla/5.0 (Linux) mirall/3.2.2git (Nextcloud, manjaro-5.10.42-1-MANJARO ClientArchitecture: x86_64 OsArchitecture: x86_64)"
app_1    | 172.19.0.4 - Marius [14/Jul/2021:15:58:35 +0000] "GET /status.php HTTP/1.1" 200 1101 "-" "Mozilla/5.0 (Linux) mirall/3.2.2git (Nextcloud, manjaro-5.10.42-1-MANJARO ClientArchitecture: x86_64 OsArchitecture: x86_64)"
app_1    | 172.19.0.4 - Marius [14/Jul/2021:15:58:35 +0000] "PROPFIND /remote.php/webdav/ HTTP/1.1" 503 1080 "-" "Mozilla/5.0 (Linux) mirall/3.2.2git (Nextcloud, manjaro-5.10.42-1-MANJARO ClientArchitecture: x86_64 OsArchitecture: x86_64)"
app_1    | 172.19.0.4 - - [14/Jul/2021:15:58:43 +0000] "GET / HTTP/1.1" 302 892 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:89.0) Gecko/20100101 Firefox/89.0"
app_1    | 172.19.0.4 - - [14/Jul/2021:15:58:43 +0000] "GET /login HTTP/1.1" 200 7000 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:89.0) Gecko/20100101 Firefox/89.0"
app_1    | 172.19.0.4 - - [14/Jul/2021:15:58:44 +0000] "GET /core/img/loading-dark.gif HTTP/1.1" 200 5161 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:89.0) Gecko/20100101 Firefox/89.0"
app_1    | 172.19.0.4 - - [14/Jul/2021:15:58:44 +0000] "GET /apps/photos/service-worker.js HTTP/1.1" 401 779 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:89.0) Gecko/20100101 Firefox/89.0"
app_1    | 172.19.0.4 - - [14/Jul/2021:15:58:47 +0000] "POST /login HTTP/1.1" 500 5027 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:89.0) Gecko/20100101 Firefox/89.0"
app_1    | 172.19.0.4 - - [14/Jul/2021:15:58:48 +0000] "GET /apps/photos/service-worker.js HTTP/1.1" 401 878 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:89.0) Gecko/20100101 Firefox/89.0"
app_1    | 172.19.0.4 - - [14/Jul/2021:15:58:49 +0000] "GET /apps/photos/service-worker.js HTTP/1.1" 401 779 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:89.0) Gecko/20100101 Firefox/89.0"

j-ed · July 14, 2021, 6:10pm

As ususal, check the Nextcloud log file for any related issues which might point you to the root cause of the problem.

maeries · July 14, 2021, 7:10pm

Where can I find it? It’s not in /var/www/html/data/nextcloud.log

matevzm · July 14, 2021, 7:32pm

Same issue here. In the logs it says:
InnoDB refuses to write tables with ROW_FORMAT=COMPRESSED or KEY_BLOCK_SIZE.
Looks like MariaDB default change:
##### MariaDB starting with 10.6

From MariaDB 10.6.0, tables that are of the COMPRESSED row format are read-only by default. This is the first step towards removing write support and deprecating the feature.

Set the innodb_read_only_compressed variable to OFF to make the tables writable.

To fix it right now you can edit docker compose yml and add --skip-innodb-read-only-compressed to the commands for db. If you have yml from Docker Hub, the commands would be
command: --transaction-isolation=READ-COMMITTED --binlog-format=ROW --skip-innodb-read-only-compressed

Wytoo · July 15, 2021, 6:49am

I’ve got a Nextcloud/MariaDB Docker Container running on a Synology. How do I implement that fix? The Console from the WebUI of the Docker Image won’t open, but I’ve got SSH to the Synology Server of course.

Reiner_Nippes · July 15, 2021, 9:26am

link to that on docker hub? did build the image on your own? do you have the dockerfile?

Wytoo · July 15, 2021, 9:53am

I used those two images.

https://registry.hub.docker.com/_/mariadb/

https://registry.hub.docker.com/r/linuxserver/nextcloud/

Reiner_Nippes · July 15, 2021, 10:00am

ah. ok. i though you used one image that contains both nextcloud and mariadb.

you have to configure your synology in that way that you use the image “mariadb:10.5”. i guess you didn’t specify the imge version. so you got an automatic update to 10.6.

you know where to look at? i don’t have my synology at hand right now.

jt196 · July 15, 2021, 10:20am

Can confirm this is the case on upgrade to MariaDB 10.6. My Watchtower log at 02:58 this morning:

Found new mariadb:latest image (f55fb7cb2f36)
Stopping /nextcloud-mariadb (4d3afb524d95) with SIGTERM
Creating /nextcloud-mariadb
Removing image 24439278c770

Added @matevzm’s suggested lines to the Docker Compose file:

services:

    db:
        image: mariadb
        container_name: nextcloud-mariadb
        command: --transaction-isolation=READ-COMMITTED --binlog-format=ROW --skip-innodb-read-only-compressed
        networks:
        - nextcloud_network
***etc***

Ran the usual sudo docker-compose up -d command on the container and it’s back up and running.

Not to self: if you don’t want interruptions like this, turn the auto-update off!

Reiner_Nippes · July 15, 2021, 10:43am

nope.

use:

in this case you pin the correct db version, but you’ll participate from the security patches of that image.

Wytoo · July 15, 2021, 11:53am

Exactly,thanks WatchTower To be honest I’d have to look into it. Don’t know how to change that exactly. But about appending the mentioned command, where would I do that? Don’t actually know if or where there’s that docker compose file. Changing the Enviroment MariaDB_Major Variable from 10.6 to 10.5 didn’t work. But there’s also a field called MariaDB_Version which has a much more different notation, 1:10.6.3+maria~focal. Wouldn’t know to what to change that to.

Wytoo · July 17, 2021, 9:11am

Ok, I tried a new image with an older version, tried to change the currents image version to an older one. Tried a new Image with an old image with the command --skip-innodb-read-only-compressed Nothing worked

Has anyone else an idea on what to do next?

I see the same error in the logs, but have a synology Docker setup.

techc0de · July 17, 2021, 2:07pm

hello,

Try add this command:

'--innodb_read_only_compressed=OFF'

dmp1ce · July 18, 2021, 8:30pm

This worked for my setup. What is the long term solution? Is this an issue on Github?

Wytoo · July 19, 2021, 8:36am

Thanks! At first I was getting an error but those ’ seem to be necessary. Cause after I’ve entered them alongside the command then the Synology Docker accepted the command.

rubo77 · July 19, 2021, 5:04pm

thanks, I solved it by adding the combinatin of your suggestions and added this line in my docker-compose.yaml:

services:
  db:
     image: mariadb
     command: --transaction-isolation=READ-COMMITTED --binlog-format=ROW --skip-innodb-read-only-compressed --innodb_read_only_compressed=OFF

Then I successfully updated from NC 20 to 21 with

docker-compose pull && docker-compose up

And after turning off the maintenance mode with

docker exec --user www-data ${DOCKERNAME} php occ maintenance:mode --off

I updated all apps with the website-updater.

And everything works fine!

I tried to debug this a bit further:

After the update, I tried to remove the command line again, but then still NC doesn’t start so i added the command line again.

Strange is: I still have that same error in the log, but it seems to cause no harm any more:

[ERROR] Incorrect definition of table mysql.event: expected column 'definer' at position 3 to have type varchar(, found type char(141).  
[ERROR] mysqld: Event Scheduler: An error occurred when initializing system tables. Disabling the Event Scheduler.

By the way: after removing this part, NC also starts fine:

 --innodb_read_only_compressed=OFF

So maybe that part wasn’t important, or just for the update and afterwards it isn’t needed any more.

ogghi · July 26, 2021, 1:23pm

Hi, just found this to solve my issue as well, wanted to say thanks!

tdse · July 26, 2021, 4:58pm

Could you please explain where you added this information in the docker app in DSM. I run docker either with the docker app or via Portainer. Thank you.