NC AIO not accessible anymore through Caddy

hannes · April 1, 2023, 4:43pm

Hi,

I’m running NC AIO, currently on NC 26.0.0 and I’m not able to connect to it anymore.
I use Caddy on the host and that worked really well so far and I don’t get an error message from Caddy.

AIO is on latest and I manually updated Nextcloud with this guide.

Everything worked fine, but I lost access at some point. I can’t even say when or why. I can still access the AIO-dashboard and everything is up to date there v4.7.0. But when I look into the logs of AIO it throws a couple of errors:

AIO-logs

If your server has port 80 and 8443 open and you point a domain to your server, you can get a valid certificate automatically by opening the Nextcloud AIO Interface via:
https://your-domain-that-points-to-this-server.tld:8443e[0m
{"level":"info","ts":1680360352.749278,"msg":"using provided configuration","config_file":"/Caddyfile","config_adapter":""}
[01-Apr-2023 14:45:52] NOTICE: fpm is running, pid 119
[01-Apr-2023 14:45:52] NOTICE: ready to handle connections
NOTICE: PHP message: Not pulling the latest database image because the container was not correctly shut down.
NOTICE: PHP message: 404 Not Found
Type: Slim\Exception\HttpNotFoundException

4
Message: Not found.
File: /var/www/docker-aio/php/vendor/slim/slim/Slim/Middleware/RoutingMiddleware.php
Line: 76
Trace: #0 /var/www/docker-aio/php/vendor/slim/slim/Slim/Routing/RouteRunner.php(56): Slim\Middleware\RoutingMiddleware->performRouting(Object(GuzzleHttp\Psr7\ServerRequest))
#1 /var/www/docker-aio/php/vendor/slim/csrf/src/Guard.php(476): Slim\Routing\RouteRunner->handle(Object(GuzzleHttp\Psr7\ServerRequest))
#2 /var/www/docker-aio/php/vendor/slim/slim/Slim/MiddlewareDispatcher.php(168): Slim\Csrf\Guard->process(Object(GuzzleHttp\Psr7\ServerRequest), Object(Slim\Routing\RouteRunner))
#3 /var/www/docker-aio/php/vendor/slim/twig-view/src/TwigMiddleware.php(115): Psr\Http\Server\RequestHandlerInterface@anonymous->handle(Object(GuzzleHttp\Psr7\ServerRequest))
#4 /var/www/docker-aio/php/vendor/slim/slim/Slim/MiddlewareDispatcher.php(121): Slim\Views\TwigMiddleware->process(Object(GuzzleHttp\Psr7\ServerRequest), Object(Psr\Http\Server\RequestHandlerInterface@anonymous))
#5 /var/www/docker-aio/php/src/Middleware/AuthMiddleware.php(38): Psr\Http\Server\RequestHandlerInterface@anonymous->handle(Object(GuzzleHttp\Psr7\ServerRequest))
#6 /var/www/docker-aio/php/vendor/slim/slim/Slim/MiddlewareDispatcher.php(269): AIO\Middleware\AuthMiddleware->__invoke(Object(GuzzleHttp\Psr7\ServerRequest), Object(Psr\Http\Server\RequestHandlerInterface@anonymous))
#7 /var/www/docker-aio/php/vendor/slim/slim/Slim/Middleware/ErrorMiddleware.php(76): Psr\Http\Server\RequestHandlerInterface@anonymous->handle(Object(GuzzleHttp\Psr7\ServerRequest))
#8 /var/www/docker-aio/php/vendor/slim/slim/Slim/MiddlewareDispatcher.php(121): Slim\Middleware\ErrorMiddleware->process(Object(GuzzleHttp\Psr7\ServerRequest), Object(Psr\Http\Server\RequestHandlerInterface@anonymous))
#9 /var/www/docker-aio/php/vendor/slim/slim/Slim/MiddlewareDispatcher.php(65): Psr\Http\Server\RequestHandlerInterface@anonymous->handle(Object(GuzzleHttp\Psr7\ServerRequest))
#10 /var/www/docker-aio/php/vendor/slim/slim/Slim/App.php(199): Slim\MiddlewareDispatcher->handle(Object(GuzzleHttp\Psr7\ServerRequest))
#11 /var/www/docker-aio/php/vendor/slim/slim/Slim/App.php(183): Slim\App->handle(Object(GuzzleHttp\Psr7\ServerRequest))
#12 /var/www/docker-aio/php/public/index.php(170): Slim\App->run()
#13 {main}

I’m not sure where the problem could be, but maybe someone finds a clue in the logs?

Nextcloud Logs

[01-Apr-2023 15:10:39] NOTICE: fpm is running, pid 270
[01-Apr-2023 15:10:39] NOTICE: ready to handle connections
[2023-04-01 15:12:49.174160 +00:00] ERROR [notify_push] src/main.rs:77: Self test failed: Error while communicating with nextcloud instance

Database Logs


2023-04-01 15:10:02.900 UTC [12] LOG:  starting PostgreSQL 15.2 on aarch64-unknown-linux-musl, compiled by gcc (Alpine 12.2.1_git20220924-r4) 12.2.1 20220924, 64-bit
2023-04-01 15:10:02.901 UTC [12] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2023-04-01 15:10:02.901 UTC [12] LOG:  listening on IPv6 address "::", port 5432
2023-04-01 15:10:02.905 UTC [12] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2023-04-01 15:10:02.913 UTC [22] LOG:  database system was shut down at 2023-04-01 15:09:23 UTC
2023-04-01 15:10:02.921 UTC [12] LOG:  database system is ready to accept connections
2023-04-01 15:15:02.993 UTC [20] LOG:  checkpoint starting: time
2023-04-01 15:15:05.964 UTC [20] LOG:  checkpoint complete: wrote 32 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=2.912 s, sync=0.006 s, total=2.971 s; sync files=13, longest=0.003 s, average=0.001 s; distance=139 kB, estimate=139 kB
2023-04-01 15:20:03.021 UTC [20] LOG:  checkpoint starting: time
2023-04-01 15:20:06.047 UTC [20] LOG:  checkpoint complete: wrote 31 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.009 s, sync=0.007 s, total=3.026 s; sync files=12, longest=0.005 s, average=0.001 s; distance=167 kB, estimate=167 kB
2023-04-01 15:25:03.147 UTC [20] LOG:  checkpoint starting: time
2023-04-01 15:25:06.177 UTC [20] LOG:  checkpoint complete: wrote 31 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.012 s, sync=0.006 s, total=3.030 s; sync files=12, longest=0.003 s, average=0.001 s; distance=151 kB, estimate=165 kB
2023-04-01 15:30:03.273 UTC [20] LOG:  checkpoint starting: time
2023-04-01 15:30:06.401 UTC [20] LOG:  checkpoint complete: wrote 32 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.111 s, sync=0.006 s, total=3.128 s; sync files=13, longest=0.003 s, average=0.001 s; distance=169 kB, estimate=169 kB
2023-04-01 15:35:03.476 UTC [20] LOG:  checkpoint starting: time
2023-04-01 15:35:06.504 UTC [20] LOG:  checkpoint complete: wrote 32 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.013 s, sync=0.006 s, total=3.029 s; sync files=12, longest=0.003 s, average=0.001 s; distance=147 kB, estimate=167 kB
2023-04-01 15:40:03.605 UTC [20] LOG:  checkpoint starting: time
2023-04-01 15:40:06.759 UTC [20] LOG:  checkpoint complete: wrote 32 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.126 s, sync=0.007 s, total=3.155 s; sync files=13, longest=0.003 s, average=0.001 s; distance=173 kB, estimate=173 kB
2023-04-01 15:45:03.859 UTC [20] LOG:  checkpoint starting: time
2023-04-01 15:45:06.897 UTC [20] LOG:  checkpoint complete: wrote 31 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.015 s, sync=0.006 s, total=3.038 s; sync files=12, longest=0.003 s, average=0.001 s; distance=156 kB, estimate=171 kB
2023-04-01 15:50:03.993 UTC [20] LOG:  checkpoint starting: time
2023-04-01 15:50:07.130 UTC [20] LOG:  checkpoint complete: wrote 32 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.115 s, sync=0.006 s, total=3.137 s; sync files=13, longest=0.003 s, average=0.001 s; distance=171 kB, estimate=171 kB
2023-04-01 15:55:03.205 UTC [20] LOG:  checkpoint starting: time
2023-04-01 15:55:06.505 UTC [20] LOG:  checkpoint complete: wrote 33 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.268 s, sync=0.021 s, total=3.300 s; sync files=14, longest=0.017 s, average=0.002 s; distance=164 kB, estimate=171 kB
2023-04-01 16:00:03.605 UTC [20] LOG:  checkpoint starting: time
2023-04-01 16:00:06.734 UTC [20] LOG:  checkpoint complete: wrote 32 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.112 s, sync=0.006 s, total=3.130 s; sync files=13, longest=0.003 s, average=0.001 s; distance=182 kB, estimate=182 kB
2023-04-01 16:05:03.805 UTC [20] LOG:  checkpoint starting: time
2023-04-01 16:05:06.834 UTC [20] LOG:  checkpoint complete: wrote 31 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.012 s, sync=0.006 s, total=3.029 s; sync files=12, longest=0.003 s, average=0.001 s; distance=150 kB, estimate=179 kB
2023-04-01 16:10:03.929 UTC [20] LOG:  checkpoint starting: time
2023-04-01 16:10:06.858 UTC [20] LOG:  checkpoint complete: wrote 30 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=2.912 s, sync=0.005 s, total=2.929 s; sync files=11, longest=0.002 s, average=0.001 s; distance=161 kB, estimate=177 kB
2023-04-01 16:15:03.957 UTC [20] LOG:  checkpoint starting: time
2023-04-01 16:15:06.994 UTC [20] LOG:  checkpoint complete: wrote 31 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.018 s, sync=0.006 s, total=3.037 s; sync files=12, longest=0.002 s, average=0.001 s; distance=144 kB, estimate=174 kB
2023-04-01 16:20:04.049 UTC [20] LOG:  checkpoint starting: time
2023-04-01 16:20:07.085 UTC [20] LOG:  checkpoint complete: wrote 31 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.018 s, sync=0.006 s, total=3.036 s; sync files=12, longest=0.002 s, average=0.001 s; distance=164 kB, estimate=173 kB
2023-04-01 16:25:04.178 UTC [20] LOG:  checkpoint starting: time
2023-04-01 16:25:07.214 UTC [20] LOG:  checkpoint complete: wrote 31 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.017 s, sync=0.006 s, total=3.036 s; sync files=12, longest=0.003 s, average=0.001 s; distance=149 kB, estimate=171 kB
2023-04-01 16:30:04.313 UTC [20] LOG:  checkpoint starting: time
2023-04-01 16:30:07.353 UTC [20] LOG:  checkpoint complete: wrote 32 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.021 s, sync=0.006 s, total=3.040 s; sync files=12, longest=0.003 s, average=0.001 s; distance=166 kB, estimate=170 kB
2023-04-01 16:35:04.453 UTC [20] LOG:  checkpoint starting: time
2023-04-01 16:35:07.494 UTC [20] LOG:  checkpoint complete: wrote 31 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=3.018 s, sync=0.010 s, total=3.041 s; sync files=12, longest=0.006 s, average=0.001 s; distance=146 kB, estimate=168 kB

Redis Logs

Memory overcommit is disabled but necessary for safe operation
See https://github.com/nextcloud/all-in-one/discussions/1731 how to enable overcommit
1:C 01 Apr 2023 15:10:04.493 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
1:C 01 Apr 2023 15:10:04.493 # Redis version=7.0.10, bits=64, commit=00000000, modified=0, pid=1, just started
1:C 01 Apr 2023 15:10:04.493 # Configuration loaded
1:M 01 Apr 2023 15:10:04.494 * monotonic clock: POSIX clock_gettime
1:M 01 Apr 2023 15:10:04.495 * Running mode=standalone, port=6379.
1:M 01 Apr 2023 15:10:04.495 # Server initialized
1:M 01 Apr 2023 15:10:04.495 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can can also cause failures without low memory condition, see https://github.com/jemalloc/jemalloc/issues/1328. 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.
1:M 01 Apr 2023 15:10:04.498 * Loading RDB produced by version 7.0.10
1:M 01 Apr 2023 15:10:04.498 * RDB age 41 seconds
1:M 01 Apr 2023 15:10:04.498 * RDB memory usage when created 1.49 Mb
1:M 01 Apr 2023 15:10:04.500 * Done loading RDB, keys loaded: 1362, keys expired: 0.
1:M 01 Apr 2023 15:10:04.500 * DB loaded from disk: 0.003 seconds
1:M 01 Apr 2023 15:10:04.500 * Ready to accept connections
1:M 01 Apr 2023 15:55:42.219 * 100 changes in 300 seconds. Saving...
1:M 01 Apr 2023 15:55:42.223 * Background saving started by pid 658
658:C 01 Apr 2023 15:55:42.512 * DB saved on disk
658:C 01 Apr 2023 15:55:42.513 * Fork CoW for RDB: current 1 MB, peak 1 MB, average 0 MB
1:M 01 Apr 2023 15:55:42.525 * Background saving terminated with success

Apache Logs

Waiting for Nextcloud to start...
{"level":"info","ts":1680361846.2585971,"msg":"using provided configuration","config_file":"/Caddyfile","config_adapter":""}
[Sat Apr 01 15:10:46.269872 2023] [mpm_event:notice] [pid 45:tid 281473435037784] AH00489: Apache/2.4.56 (Unix) configured -- resuming normal operations
[Sat Apr 01 15:10:46.269953 2023] [core:notice] [pid 45:tid 281473435037784] AH00094: Command line: '/usr/local/apache2/bin/httpd -D FOREGROUND'

Caddy Logs

Apr 01 15:19:50 server02 caddy[304401]: {"level":"info","ts":1680362390.7804918,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0x40000d7ea0"}
Apr 01 15:19:50 server02 caddy[304401]: {"level":"info","ts":1680362390.7814825,"logger":"tls","msg":"cleaning storage unit","description":"FileStorage:/var/lib/caddy/.local/share/caddy"}
Apr 01 15:19:50 server02 caddy[304401]: {"level":"info","ts":1680362390.7815425,"logger":"http","msg":"enabling HTTP/3 listener","addr":":443"}
Apr 01 15:19:50 server02 caddy[304401]: {"level":"info","ts":1680362390.7817957,"logger":"http.log","msg":"server running","name":"srv0","protocols":["h1","h2","h3"]}
Apr 01 15:19:50 server02 caddy[304401]: {"level":"info","ts":1680362390.7819433,"logger":"http.log","msg":"server running","name":"remaining_auto_https_redirects","protocols":["h1","h2",">
Apr 01 15:19:50 server02 caddy[304401]: {"level":"info","ts":1680362390.7819657,"logger":"http","msg":"enabling automatic TLS certificate management","domains":["DOMAIN"]}
Apr 01 15:19:50 server02 caddy[304401]: {"level":"info","ts":1680362390.7846658,"msg":"autosaved config (load with --resume flag)","file":"/var/lib/caddy/.config/caddy/autosave.json"}
Apr 01 15:19:50 server02 caddy[304401]: {"level":"info","ts":1680362390.784816,"msg":"serving initial configuration"}
Apr 01 15:19:50 server02 systemd[1]: Started Caddy.
Apr 01 15:19:50 server02 caddy[304401]: {"level":"info","ts":1680362390.7867298,"logger":"tls","msg":"finished cleaning storage units"}

Any help is appreciated! I already checked that the domain points to my IP address, that’s correct. I hope it’s no DB issue…

szaimen · April 1, 2023, 4:46pm

If this happened after the manual upgrade to 26, does restoring a backup make things work again?

hannes · April 1, 2023, 4:48pm

No it didn’t happen after the update, it worked quite well in 26. To be honest, it feels like it happened just over night…

szaimen · April 1, 2023, 4:48pm

Okay and restoring a backup from yesterday is no option?

hannes · April 1, 2023, 4:52pm

Hehe, as you already guess, there is no backup from yesterday. Due to some storage issues I’m living backup free (at least from the configs) since end of february…

hannes · April 1, 2023, 4:53pm

You don’t see an obvious issue in the logs right?

szaimen · April 1, 2023, 4:53pm

I fear in this case I cannot help further.

hannes · April 1, 2023, 4:56pm

Ok, understand that. Thanks for the fast reply!

Too bad, don’t wanna ditch this NC again… Maybe someone else can have a look at the logs.

I noticed for example this message, which seems to come all the time (in the AIO-logs)

Message: Not found.
File: /var/www/docker-aio/php/vendor/slim/slim/Slim/Middleware/RoutingMiddleware.php
Line: 76

szaimen · April 1, 2023, 5:00pm

Just to note: this log entry is unrelated to the issue you are having.

hannes · April 1, 2023, 5:03pm

Thank you I’ll research further!

hannes · April 1, 2023, 5:24pm

Solved it, sorry for the thread! It was a hardware problems related to the router… The server was always fine.

Thanks again for your help. Will work with the backups tonight