'Permission error with Django logs in production

When trying to apply logging config to my Django project on the production server, the site returns a 502 gateway error and sudo journalctl -u gunicorn shows the following Permission denied: '/home/logs/MySite.log' error. The same config runs on the staging server and is working (using the same debug=false, gunicorn/nginx setup, not using any development settings like ./manage.py runserver or debug=true). The only difference I am aware of is that the staging server is served through http instead of https. Can anyone help fix the permissions error and to get logging running on production? Thanks in advance!

Error

-- Logs begin at Thu 2022-03-17 01:36:23 UTC, end at Sun 2022-03-20 22:41:48 UTC. --
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "<frozen importlib._bootstrap>", line 994, in _gcd_import
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "<frozen importlib._bootstrap>", line 971, in _find_and_load
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "<frozen importlib._bootstrap>", line 955, in _find_and_load_unlocked
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "<frozen importlib._bootstrap>", line 665, in _load_unlocked
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "<frozen importlib._bootstrap_external>", line 678, in exec_module
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/MySite/VicMySite/wsgi.py", line 15, in <module>
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     application = get_wsgi_application()
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/django/core/wsgi.py", line 12, in get_wsgi_applica>
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     django.setup(set_prefix=False)
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/django/__init__.py", line 19, in setup
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     configure_logging(settings.LOGGING_CONFIG, settings.LOGGING)
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/django/utils/log.py", line 75, in configure_logging
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     logging_config_func(logging_settings)
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/usr/lib64/python3.6/logging/config.py", line 802, in dictConfig
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     dictConfigClass(config).configure()
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/usr/lib64/python3.6/logging/config.py", line 573, in configure
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     '%r: %s' % (name, e))
Mar 20 22:40:00 mysite-prod gunicorn[419844]: ValueError: Unable to configure handler 'file': [Errno 13] Permission denied: '/home/logs/MySite.log'
Mar 20 22:40:00 mysite-prod gunicorn[419844]: [2022-03-20 15:40:00 -0700] [419851] [INFO] Worker exiting (pid: 419851)
Mar 20 22:40:00 mysite-prod gunicorn[419844]: [2022-03-20 15:40:00 -0700] [419852] [ERROR] Exception in worker process
Mar 20 22:40:00 mysite-prod gunicorn[419844]: Traceback (most recent call last):
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/usr/lib64/python3.6/logging/config.py", line 565, in configure
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     handler = self.configure_handler(handlers[name])
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/usr/lib64/python3.6/logging/config.py", line 738, in configure_handler
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     result = factory(**kwargs)
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/usr/lib64/python3.6/logging/__init__.py", line 1032, in __init__
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     StreamHandler.__init__(self, self._open())
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/usr/lib64/python3.6/logging/__init__.py", line 1061, in _open
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     return open(self.baseFilename, self.mode, encoding=self.encoding)
Mar 20 22:40:00 mysite-prod gunicorn[419844]: PermissionError: [Errno 13] Permission denied: '/home/logs/MySite.log'
Mar 20 22:40:00 mysite-prod gunicorn[419844]: During handling of the above exception, another exception occurred:
Mar 20 22:40:00 mysite-prod gunicorn[419844]: Traceback (most recent call last):
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/gunicorn/arbiter.py", line 589, in spawn_worker
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     worker.init_process()
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/gunicorn/workers/base.py", line 134, in init_proce>
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     self.load_wsgi()
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/gunicorn/workers/base.py", line 146, in load_wsgi
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     self.wsgi = self.app.wsgi()
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/gunicorn/app/base.py", line 67, in wsgi
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     self.callable = self.load()
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/gunicorn/app/wsgiapp.py", line 58, in load
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     return self.load_wsgiapp()
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/gunicorn/app/wsgiapp.py", line 48, in load_wsgiapp
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     return util.import_app(self.app_uri)
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/gunicorn/util.py", line 359, in import_app
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     mod = importlib.import_module(module)
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/usr/lib64/python3.6/importlib/__init__.py", line 126, in import_module
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     return _bootstrap._gcd_import(name[level:], package, level)
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "<frozen importlib._bootstrap>", line 994, in _gcd_import
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "<frozen importlib._bootstrap>", line 971, in _find_and_load
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "<frozen importlib._bootstrap>", line 955, in _find_and_load_unlocked
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "<frozen importlib._bootstrap>", line 665, in _load_unlocked
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "<frozen importlib._bootstrap_external>", line 678, in exec_module
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/MySite/VicMySite/wsgi.py", line 15, in <module>
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     application = get_wsgi_application()
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/django/core/wsgi.py", line 12, in get_wsgi_applica>
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     django.setup(set_prefix=False)
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/django/__init__.py", line 19, in setup
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     configure_logging(settings.LOGGING_CONFIG, settings.LOGGING)
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/home/my_username/.virtualenvs/mySitePython3/lib64/python3.6/site-packages/django/utils/log.py", line 75, in configure_logging
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     logging_config_func(logging_settings)
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/usr/lib64/python3.6/logging/config.py", line 802, in dictConfig
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     dictConfigClass(config).configure()
Mar 20 22:40:00 mysite-prod gunicorn[419844]:   File "/usr/lib64/python3.6/logging/config.py", line 573, in configure
Mar 20 22:40:00 mysite-prod gunicorn[419844]:     '%r: %s' % (name, e))
Mar 20 22:40:00 mysite-prod gunicorn[419844]: ValueError: Unable to configure handler 'file': [Errno 13] Permission denied: '/home/logs/MySite.log'
Mar 20 22:40:00 mysite-prod gunicorn[419844]: [2022-03-20 15:40:00 -0700] [419852] [INFO] Worker exiting (pid: 419852)
Mar 20 22:40:00 mysite-prod gunicorn[419844]: [2022-03-20 22:40:00 +0000] [419844] [WARNING] Worker with pid 419851 was terminated due to signal 15
Mar 20 22:40:00 mysite-prod gunicorn[419844]: [2022-03-20 22:40:00 +0000] [419844] [WARNING] Worker with pid 419852 was terminated due to signal 15
Mar 20 22:40:00 mysite-prod gunicorn[419844]: [2022-03-20 22:40:00 +0000] [419844] [INFO] Shutting down: Master
Mar 20 22:40:00 mysite-prod gunicorn[419844]: [2022-03-20 22:40:00 +0000] [419844] [INFO] Reason: Worker failed to boot.
Mar 20 22:40:00 mysite-prod systemd[1]: gunicorn.service: Main process exited, code=exited, status=3/NOTIMPLEMENTED
Mar 20 22:40:00 mysite-prod systemd[1]: gunicorn.service: Failed with result 'exit-code'.
Mar 20 22:40:00 mysite-prod systemd[1]: gunicorn.service: Start request repeated too quickly.
Mar 20 22:40:00 mysite-prod systemd[1]: gunicorn.service: Failed with result 'exit-code'.
Mar 20 22:40:00 mysite-prod systemd[1]: Failed to start Gunicorn daemon.

Logging config, debug set to false

DEBUG = False

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'verbose': {
            'format' : "[%(asctime)s] %(levelname)s [%(name)s:%(lineno)s] %(message)s",
            'datefmt' : "%d/%b/%Y %H:%M:%S"
        },
        'simple': {
            'format': '%(levelname)s %(message)s'
        },
    },
    'handlers': {
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'simple'
        },
        'file': {
            'level': 'WARNING',
            'class': 'logging.FileHandler',
            'filename': '/home/logs/MySite.log',
            'formatter': 'verbose'
        },
    },
    'loggers': {
        'django': {
            'handlers': ['file'],
            'level': 'WARNING',
        },
        'mapApp': {
            'handlers': ['file'],
            'level': 'DEBUG'
        }
    },
}

Gunicorn Service file:

[Unit] Description=Gunicorn daemon Requires=gunicorn.socket After=network.target

[Service] User=my_username Group=my_username WorkingDirectory=/home/MySite

ExecStart=/home/my_username/.virtualenvs/mySitePython3/bin/gunicorn --access-logfile - --workers 3 --bind unix:gunicorn.sock VicMySite.wsgi

[Install] WantedBy=multi-user.target

Gunicorn Socket file

[Install] WantedBy=sockets.target

[Unit] Description=Gunicorn WSGI socket

[Socket] ListenStream=/run/gunicorn.sock

[Install] WantedBy=sockets.target

Nginx config

user nginx; worker_processes auto; error_log /var/log/nginx/error.log; pid /run/nginx.pid;

include /usr/share/nginx/modules/*.conf;

events { worker_connections 1024; }

http { log_format  main  '$remote_addr - $remote_user [$time_local] "$request" ' '$status $body_bytes_sent "$http_referer" ' '"$http_user_agent" "$http_x_forwarded_for"';

access_log  /var/log/nginx/access.log  main;

sendfile            on;
tcp_nopush          on;
tcp_nodelay         on;
keepalive_timeout   65;
types_hash_max_size 2048;

include             /etc/nginx/mime.types;
default_type        application/octet-stream;

# Load modular configuration files from the /etc/nginx/conf.d directory.
# See http://nginx.org/en/docs/ngx_core_module.html#include
# for more information.
include /etc/nginx/conf.d/*.conf;

server { listen 80; server_name mysite.org; return 301 https://$host$request_uri; }

# Ignore requests for incorrect hosts instead of forwarding to Django
# https://docs.djangoproject.com/en/3.0/howto/deployment/checklist/#debug

server { listen 80 default_server; return 444; }

# Settings for a TLS enabled server.
server {
    listen       443 ssl http2 default_server;
    listen       [::]:443 ssl http2 default_server;
    server_name  mysite.org;

    ssl_certificate "/home/my_username/ssl/mysite_org_chain.crt";
    ssl_certificate_key "/home/my_username/ssl/mysite.key";

    location = /favicon.ico { access_log off; log_not_found off; }
    location /static/ {
      root /home/MySite;
    }
location /media/ {
      root /home/MySite;
    }
    location / {
        proxy_set_header Host $http_host;
        proxy_set_header X-Real-IP $remote_addr;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_set_header X-Forwarded-Proto $scheme;
        proxy_pass http://unix:/run/gunicorn.sock;
      }
  }
}

Restarting the server after making changes:

. /home/my_username/.virtualenvs/mySitePython3/bin/activate
./manage.py migrate --settings=VicMySite.settings.prod
./manage.py collectstatic --settings=VicMySite.settings.prod
./manage.py clearcache --settings=VicMySite.settings.prod
sudo systemctl restart gunicorn

Things I have tried so far:

  • confirming gunicorn is running as the my_username user (1. it is in the socket file, 2. when I let Django create the log file the owner and group are both my_username, 3. ps aux | grep gunicorn shows the process running as my_username)

  • confirming the 'logs' directory and 'MySite.log' file the have my_username user as both the owner and group. setting both to chmod 777 temporarily to see if it helped with the permissions error (it did not)

  • temporarily turning off selinux with sudo setenforce 0

djangonginxlogginggunicornproduction-environment


Sources

This article follows the attribution requirements of Stack Overflow and is licensed under CC BY-SA 3.0.

Source: Stack Overflow

Solution Source

Related Questions

How to configure log4j in a Spring Mvc application configured with Java Annotations and using a log4j.properties file

Android: How to open Call Log (missed-outgoing-incoming call view)?

log4j writing to console but not to file (Liferay + Tomcat)

Using python Logging with AWS Lambda

How to log a variable's name and value?

Force log rollover in tomcat log4j2 even if no traffic

Python Selenium - Disable Chromedriver log message in cmd

Gradle stack trace on terminal

Logging to Amazon S3

PyTorch Lightning training console output is weird

Disable signalr console logging

How to stop selenium from printing WebDriver manager startup logs?

In Gradle, how to print out a message in the console / Event Log?

.Net Core 3.1 - Set ForContext for Serilog with Microsoft Ilogger interface

Configure Node.js to log to a file instead of the console