403 Forbidden error when browing to wiki

[mitchplze]

Whether I go to http://URL:PORT directly, or through reverse proxy (Caddy in my case), I have started getting this now:

Forbidden: You don't have the permission to access the requested resource. It is either read-protected or not readable by the server.

I'm using Docker, with the following compose.yaml:

services:
  otterwiki:
    image: redimp/otterwiki:2
    restart: unless-stopped
    ports:
      - 8762:80
    volumes:
      - otterwiki:/app-data

volumes:
  otterwiki:
    driver: local
    driver_opts:
      type: nfs
      o: addr=10.13.5.5,nolock,soft,rw
      device: :/volume1/docker/otterwiki

This has worked fine for weeks, but now I can't get to the wiki at all. I have re-pulled latest image, and recreated the stack altogether. By not declaring a user:XXX in compose, the stack runs as root.

Console reveals nothing useful in my opinion:

2024-12-28 00:26:20,844 INFO Included extra file "/etc/supervisor/conf.d/supervisord.conf" during parsing
2024-12-28 00:26:20,845 INFO Set uid to user 0 succeeded
2024-12-28 00:26:20,852 INFO RPC interface 'supervisor' initialized
2024-12-28 00:26:20,853 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2024-12-28 00:26:20,853 INFO supervisord started with pid 1
2024-12-28 00:26:21,859 INFO spawned: 'quit_on_failure' with pid 9
2024-12-28 00:26:21,863 INFO spawned: 'nginx' with pid 10
2024-12-28 00:26:21,866 INFO spawned: 'uwsgi' with pid 11
[uwsgi] implicit plugin requested python3
[uWSGI] getting INI configuration from /app/uwsgi.ini
*** Starting uWSGI 2.0.21-debian (64bit) on [Sat Dec 28 00:26:21 2024] ***
compiled with version: 12.2.0 on 19 May 2023 13:59:29
os: Linux-6.1.0-26-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.112-1 (2024-09-30)
nodename: c4459de0bf5e
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 10
current working directory: /
writing pidfile to /tmp/uwsgi.pid
detected binary path: /usr/bin/uwsgi-core
chdir() to /app
your memory page size is 4096 bytes
detected max file descriptor number: 1048576
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uwsgi socket 0 bound to UNIX address /tmp/uwsgi.sock fd 3
setgid() to 33
setuid() to 33
Python version: 3.11.2 (main, Sep 14 2024, 03:00:30) [GCC 12.2.0]
PEP 405 virtualenv detected: /opt/venv
Set PythonHome to /opt/venv
Python main interpreter initialized at 0x7f232d5a4018
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 5 seconds
mapped 145840 bytes (142 KB) for 1 cores
*** Operational MODE: single process ***
2024-12-28 00:26:22,912 INFO success: quit_on_failure entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-12-28 00:26:22,912 INFO success: nginx entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-12-28 00:26:22,912 INFO success: uwsgi entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
WSGI app 0 (mountpoint='') ready in 2 seconds on interpreter 0x7f232d5a4018 pid: 11 (default app)
spawned uWSGI master process (pid: 11)
spawned uWSGI worker 1 (pid: 17, cores: 1)
running "unix_signal:15 gracefully_kill_them_all" (master-start)...
10.88.0.2 - - [28/Dec/2024:00:27:13 +0000] "GET / HTTP/1.1" 403 185 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:133.0) Gecko/20100101 Firefox/133.0"

Then when I try to navigate to pages and get the Forbidden:

10.88.0.2 - - [28/Dec/2024:00:27:13 +0000] "GET / HTTP/1.1" 403 185 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:133.0) Gecko/20100101 Firefox/133.0"

10.88.0.2 - - [28/Dec/2024:00:28:24 +0000] "GET / HTTP/1.1" 403 185 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:133.0) Gecko/20100101 Firefox/133.0"

10.88.0.2 - - [28/Dec/2024:00:29:21 +0000] "GET / HTTP/1.1" 403 185 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:133.0) Gecko/20100101 Firefox/133.0"

10.88.0.2 - - [28/Dec/2024:00:29:21 +0000] "GET / HTTP/1.1" 403 185 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:133.0) Gecko/20100101 Firefox/133.0"

10.88.0.2 - - [28/Dec/2024:00:29:21 +0000] "GET / HTTP/1.1" 403 185 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:133.0) Gecko/20100101 Firefox/133.0"

10.88.0.2 - - [28/Dec/2024:00:29:22 +0000] "GET / HTTP/1.1" 403 185 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:133.0) Gecko/20100101 Firefox/133.0"

10.88.0.2 - - [28/Dec/2024:00:29:22 +0000] "GET / HTTP/1.1" 403 185 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:133.0) Gecko/20100101 Firefox/133.0"

10.88.0.2 - - [28/Dec/2024:00:29:22 +0000] "GET / HTTP/1.1" 403 185 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:133.0) Gecko/20100101 Firefox/133.0"

On the backend storage:

The "repository" directory contains all my pages as expected. No idea what's wrong here.

I will most likely be forced to backup the repo folder, and then rebuild the installation from scratch.

[mitchplze]

Rebuilding the environment and importing old repository folder seemed to workaround the issue.

Still, I would love to know why this occurred and how to prevent it. I have a backup for troubleshooting.

[redimp]

Hey @mitchplze, thanks for reporting this and for the update that you got it working.

Unfortunately I have no idea what went wrong. An Otter Wiki does nothing fancy with the file permissions, it always runs as user with the uid 33 and reads and writes files (and runs git) with this uid. It never does any modification of permissions except for the startup in the entrypoint.sh, where it runs as root (uid 0) and changes the permissions of the /app-data to www-data (uid 33).

Can you check which permissions are set in the nfs volume in /volume1/docker/otterwiki and what permissions are in the docker container via

docker compose exec otterwiki ls -ln /app-data

[mitchplze]

This seems to have happened again, on a fresh build!

I am starting to suspect it has to do with the NFS mount and possibly the way Otterwiki handles permissions thru Docker.

I note that on the below ls's, the time stamp of the files seem to be frozen in time. While it's true that I have not looked at the wiki since Dec 27/28 (timezone difference between machines), the containers have been up all along.

Today is Jan 19, and it looks like there has been no writes back to the sqlite or settings since I last went through the rebuild. Not sure what would be causing this, or if that's expected, if there has been 0 activity at all.

I have not noticed any behaviours whatsoever like this for other apps, running in an identical config. I tried adding user: root to my compose.yml, and that didn't seem to fix the 403.

As requested:

# Storage host
mitch@blt:/volume1/docker$ ls -lhn otterwiki
total 48K
-rw-r--r-- 1 33 33  28K Dec 27 16:39 db.sqlite
drwxr-xr-x 1 33 33 2.2K Dec 27 16:41 repository
-rw-r--r-- 1 33 33  156 Dec 27 16:37 settings.cfg
mitch@blt:/volume1/docker$ 

and

# Container host
root@vcd3:~/jan19# docker compose exec otterwiki ls -ln /app-data
total 48
-rw-r--r-- 1 33 33 28672 Dec 28 00:39 db.sqlite
drwxr-xr-x 1 33 33  2184 Dec 28 00:41 repository
-rw-r--r-- 1 33 33   156 Dec 28 00:37 settings.cfg

As before, container logs don't seem like they're much help.

2025-01-20 02:31:22,416 INFO Included extra file "/etc/supervisor/conf.d/supervisord.conf" during parsing
2025-01-20 02:31:22,417 INFO Set uid to user 0 succeeded
2025-01-20 02:31:22,436 INFO RPC interface 'supervisor' initialized
2025-01-20 02:31:22,437 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2025-01-20 02:31:22,438 INFO supervisord started with pid 1
2025-01-20 02:31:23,442 INFO spawned: 'quit_on_failure' with pid 9
2025-01-20 02:31:23,453 INFO spawned: 'nginx' with pid 10
2025-01-20 02:31:23,470 INFO spawned: 'uwsgi' with pid 11
[uwsgi] implicit plugin requested python3
[uWSGI] getting INI configuration from /app/uwsgi.ini
*** Starting uWSGI 2.0.21-debian (64bit) on [Mon Jan 20 02:31:23 2025] ***
compiled with version: 12.2.0 on 19 May 2023 13:59:29
os: Linux-6.1.0-26-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.112-1 (2024-09-30)
nodename: 74dcbbc5b524
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 3
current working directory: /
writing pidfile to /tmp/uwsgi.pid
detected binary path: /usr/bin/uwsgi-core
chdir() to /app
your memory page size is 4096 bytes
detected max file descriptor number: 1048576
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uwsgi socket 0 bound to UNIX address /tmp/uwsgi.sock fd 3
setgid() to 33
setuid() to 33
Python version: 3.11.2 (main, Sep 14 2024, 03:00:30) [GCC 12.2.0]
PEP 405 virtualenv detected: /opt/venv
Set PythonHome to /opt/venv
Python main interpreter initialized at 0x7f643620a018
python threads support enabled
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 5 seconds
mapped 145840 bytes (142 KB) for 1 cores
*** Operational MODE: single process ***
2025-01-20 02:31:24,582 INFO success: quit_on_failure entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-01-20 02:31:24,583 INFO success: nginx entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-01-20 02:31:24,583 INFO success: uwsgi entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
WSGI app 0 (mountpoint='') ready in 3 seconds on interpreter 0x7f643620a018 pid: 11 (default app)
spawned uWSGI master process (pid: 11)
spawned uWSGI worker 1 (pid: 17, cores: 1)
running "unix_signal:15 gracefully_kill_them_all" (master-start)...
10.88.0.2 - - [20/Jan/2025:02:31:26 +0000] "GET / HTTP/1.1" 403 185 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.1.1 Safari/605.1.15"

Thanks for looking into this.

[redimp]

On both the storage host and in the container the files have the expected owner and permissions.

To be sure can you check the permissions for the diorectories as well:

ls -lan /app-data

and the repository, too:

ls -lan /app-data/repository | head

I might have to add a writeable test to the healthcheck.

[mitchplze]

To be sure can you check the permissions for the diorectories as well:

ls -lan /app-data

Here you go:

root@vcd3:~/jan19# docker compose exec otterwiki ls -lan /app-data
total 52
drwxr-xr-x 1 33 33   504 Dec 28 00:41 .
drwxr-xr-x 1  0  0  4096 Jan 20 17:29 ..
-rw-r--r-- 1 33 33 28672 Dec 28 00:39 db.sqlite
drwxr-xr-x 1 33 33  2184 Dec 28 00:41 repository
-rw-r--r-- 1 33 33   156 Dec 28 00:37 settings.cfg

and the repository, too:

ls -lan /app-data/repository | head

Here you are:

root@vcd3:~/jan19# docker compose exec otterwiki ls -lan /app-data/repository | head
total 24
drwxr-xr-x 1 33 33 2184 Dec 28 00:41 .
drwxr-xr-x 1 33 33  504 Dec 28 00:41 ..
drwxr-xr-x 1 33 33 2352 Jan 20 17:30 .git
drwxr-xr-x 1 33 33  208 Dec 28 00:41 home
-rw-r--r-- 1 33 33  101 Dec 28 00:41 redacted.md
drwxr-xr-x 1 33 33  168 Dec 28 00:41 redacted
drwxr-xr-x 1 33 33  336 Dec 28 00:41 redacted
drwxr-xr-x 1 33 33  168 Dec 28 00:41 redacted
drwxr-xr-x 1 33 33  168 Dec 28 00:41 redacted

Hope this helps. Let me know if there's anything else I can try before I rebuild again.

[redimp]

Unfortunately the permissions are all correct.

Can we check who throws the 403 error? Please run

curl -s -L -v https://hostname/ -o /dev/null 2>&1 | grep -e "^[<>]"

[mitchplze]

Here you go.

One from the Caddy reverse proxy, and one from the bare HTTP port.

The 403 exists on both, so I'm not convinced its a Caddy issue.

> curl -s -L -v https://wiki.domain.com -o /dev/null 2>&1 | grep -e "^[<>]"
> GET / HTTP/2
> Host: wiki.domain.com
> User-Agent: curl/8.7.1
> Accept: */*
> 
< HTTP/2 403 
< alt-svc: h3=":443"; ma=2592000
< content-type: text/html; charset=utf-8
< date: Mon, 20 Jan 2025 19:59:38 GMT
< server: Caddy
< server: nginx/1.22.1
< vary: Cookie
< 
> curl -s -L -v http://hostname:8762 -o /dev/null 2>&1 | grep -e "^[<>]"
> GET / HTTP/1.1
> Host: hostname:8762
> User-Agent: curl/8.7.1
> Accept: */*
> 
< HTTP/1.1 403 FORBIDDEN
< Server: nginx/1.22.1
< Date: Mon, 20 Jan 2025 20:00:20 GMT
< Content-Type: text/html; charset=utf-8
< Content-Length: 213
< Connection: keep-alive
< Vary: Cookie
< 

[redimp]

Thank you! You are right, the caddy is for sure not the issue.

Last question: Which Otterwiki version is this?

[mitchplze]

Great question! Since the UI is not currently usable, best I can do is the image:

redimp/otterwiki:2@sha256:8bbfae69803ab2e551737cbb2164fcb177b1fccbf14afe3c2e3c139e315f3339

I think I pulled that yesterday or the day before. The original wiki was built on/around Dec 27 with a fresh docker image at that time.

You'd know better than me, but I think its also in the container log

[redimp]

You'd know better than me, but I think its also in the container log

Unfortunately not. Will add printing versions for nginx, supervisord and An Otter Wiki.

Can you try to run the image redimp/otterwiki:2.8.0-slim, since all the permissions are correct, it should be able to run with the same configuration. Documentation about this image can be found here and since you are running this behind a Caddy anyway it should fit.

[mitchplze]

Thanks. Changed to that image and port 8080 on the destination.

403 still persists.

Container log:

[uWSGI] getting INI configuration from /app/uwsgi.ini
[uwsgi-static] added mapping for /static => /app/otterwiki/static/
*** Starting uWSGI 2.0.25.1 (64bit) on [Mon Jan 20 23:24:34 2025] ***
compiled with version: 13.2.1 20240309 on 17 May 2024 06:11:37
os: Linux-6.1.0-26-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.112-1 (2024-09-30)
nodename: 3422d0103b48
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 3
current working directory: /
writing pidfile to /tmp/uwsgi.pid
detected binary path: /usr/sbin/uwsgi
uWSGI running as root, you can use --uid/--gid/--chroot options
*** WARNING: you are running uWSGI as root !!! (use the --uid flag) *** 
chdir() to /app
your memory page size is 4096 bytes
detected max file descriptor number: 1048576
building mime-types dictionary from file /etc/mime.types...1390 entry found
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uwsgi socket 0 bound to TCP address :8080 fd 3
uWSGI running as root, you can use --uid/--gid/--chroot options
*** WARNING: you are running uWSGI as root !!! (use the --uid flag) *** 
Python version: 3.12.7 (main, Oct  7 2024, 11:30:19) [GCC 13.2.1 20240309]
PEP 405 virtualenv detected: /opt/venv
Set PythonHome to /opt/venv
Python main interpreter initialized at 0x7f37b0415950
uWSGI running as root, you can use --uid/--gid/--chroot options
*** WARNING: you are running uWSGI as root !!! (use the --uid flag) *** 
python threads support enabled
your server socket listen backlog is limited to 1024 connections
your mercy for graceful operations on workers is 5 seconds
mapped 145840 bytes (142 KB) for 1 cores
*** Operational MODE: single process ***
WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x7f37b0415950 pid: 1 (default app)
uWSGI running as root, you can use --uid/--gid/--chroot options
*** WARNING: you are running uWSGI as root !!! (use the --uid flag) *** 
spawned uWSGI master process (pid: 1)
spawned uWSGI worker 1 (pid: 11, cores: 1)
running "unix_signal:15 gracefully_kill_them_all" (master-start)...