Login error 500 after docker-compose update

[TheSelox]

I pulled a new image and started the container. I tried to log in but it failed.

Then I remembered that there was more to do and saw in the docs that I also needed to execute sh docker/update.sh after updating. Ran without an issue but still the login doesn't work.

I don't get any hints in the frontend and can only see the error in the container logs (see below).

The last entry in laravel.log is from 3 days ago, so I'm not sure if it's relevant.

[08-Jun-2023 08:04:11] NOTICE: fpm is running, pid 17
[08-Jun-2023 08:04:11] NOTICE: ready to handle connections
Migrate database...
Database migration completed.
2023-06-08 08:04:10,851 CRIT Supervisor is running as root.  Privileges were not dropped because no user is specified in the config file.  If you intend to run as root, you can set user=root in the config file to avoid this message.
2023-06-08 08:04:10,853 INFO supervisord started with pid 14
2023-06-08 08:04:11,856 INFO spawned: 'cron' with pid 15
2023-06-08 08:04:11,860 INFO spawned: 'nginx' with pid 16
2023-06-08 08:04:11,861 INFO spawned: 'php-fpm' with pid 17
2023-06-08 08:04:12,905 INFO success: cron entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2023-06-08 08:04:12,905 INFO success: nginx entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2023-06-08 08:04:12,905 INFO success: php-fpm entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
127.0.0.1 -  08/Jun/2023:08:04:29 +0000 "POST /index.php" 500
192.168.2.10 - - [08/Jun/2023:08:04:29 +0000] "POST /api/auth/login HTTP/1.1" 500 6628 "https://benotes.example.com/login" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/113.0" "192.168.5.27"

I'm using a dedicated postgres db which worked before. As far as I can see in the db the users and data are still there.

[fr0tt]

Which version did you update from ?

[TheSelox]

Not really sure. I was on the latest tag for the app container image

[fr0tt]

Ok that's actually rather useful.

I can try to look into it this evening but if you want to have an answer before that you can just, for a brief moment, change in you .env file two variables to:

APP_DEBUG=true
APP_ENV=local

and then try to login again, check your laravel.log again and see if anything comes up.

[TheSelox]

laravel.log doesn't get written to disk and I get these container logs. I guess it's a permission issue

2023/06/08 13:40:59 [crit] 19#19: *1 open() "/var/lib/nginx/tmp/fastcgi/1/00/0000000001" failed (13: Permission denied) while reading upstream, client: 192.168.2.10, server: localhost, request: "POST /api/auth/login HTTP/1.1", upstream: "fastcgi://127.0.0.1:9000", host: "benotes.example.com", referrer: "https://benotes.example.com/login"
127.0.0.1 -  08/Jun/2023:13:40:59 +0000 "POST /index.php" 500
192.168.2.10 - - [08/Jun/2023:13:40:59 +0000] "POST /api/auth/login HTTP/1.1" 500 141224 "https://benotes.example.com/login" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/113.0" "192.168.5.27"

Inside the container it looks like this and is it normal that the storage directory has a different group ID than the other ones?

-rw-r--r--    1 1000     102         1.0K May 20  2022 LICENSE
-rw-r--r--    1 1000     102          119 May 20  2022 Procfile
-rw-r--r--    1 1000     102        14.6K May 30 08:42 api.md
drwxr-xr-x    1 1000     102          138 May  3 12:57 app
-rw-r--r--    1 1000     102          805 May 20  2022 app.json
-rw-r--r--    1 1000     102         1.6K Jan 14 21:29 artisan
drwxr-xr-x    1 1000     102           24 Apr 15 22:56 bootstrap
-rw-r--r--    1 1000     102         2.0K May 14 10:46 composer.json
-rw-r--r--    1 1000     102       327.7K May  3 12:57 composer.lock
drwxr-xr-x    1 1000     102          348 May 30 18:19 config
drwxr-xr-x    1 1000     102           72 Apr 15 22:56 database
drwxr-xr-x    1 1000     102          202 Jun  3 20:16 docker
drwxrwxrwt    1 1000     102            0 May 11 20:11 html
drwxr-xr-x    1 1000     102           12 Jun  3 20:17 localhost
-rw-r--r--    1 1000     102          206 May 20  2022 nginx.conf
-rw-r--r--    1 1000     102       932.9K Mar 10 10:28 package-lock.json
-rw-r--r--    1 1000     102         2.3K Mar 10 10:28 package.json
-rw-r--r--    1 1000     102         1.2K Jan 14 21:29 phpunit.xml
-rw-r--r--    1 1000     102         3.3K Jan 14 21:29 playwright.config.js
drwxr-xr-x    1 1000     102          236 Jun  3 20:19 public
drwxr-xr-x    1 1000     102           44 Apr 15 22:56 resources
drwxr-xr-x    1 1000     102           74 Apr 15 22:56 routes
-rw-r--r--    1 1000     102          569 Jan 14 21:29 server.php
drwxr-xr-x    8 1000     82            88 May 14 07:28 storage
-rw-r--r--    1 1000     102         1.6K Mar  3 10:47 tailwind.config.js
drwxr-xr-x    1 1000     102           90 Apr 15 22:56 tests
drwxr-xr-x    1 1000     102          788 Jun  3 20:19 vendor
-rw-r--r--    1 1000     102         1.5K Jan 14 21:29 webpack.mix.js

[fr0tt]

That's normal, but I'm going to change that 102 to 1000 which is what I actually expected to happen.

Your issue is probably caused by your storage bind mount. I updated the documentation, maybe the information there can already help you enough.

[TheSelox]

Thx! The issue seemed to have been the wrong user in the storage dir permissions. I execute chown -R www-data:www-data storage within the container, and it immediately worked again.