Score:2

Nginx writes error log entries to access.log

cn flag

I'm trying to configure fail2ban for 403 errors from Nginx. But for some reason my error.log file is empty and all 403 (and all 4XX, 5XX) errors are going to access.log. However, I checked my config and it looks fine.

server {
    listen 80;
    server_name example.com;

    return 301 https://$host$request_uri;
}

server {
    listen 443;
    server_name example.com;

    access_log  /var/log/nginx/example.com/access.log;
    error_log   /var/log/nginx/example.com/error.log;

    ssl on;
    include /etc/nginx/conf.d/letsencrypt;
    include /etc/nginx/conf.d/verify-client;

    location / {
        include /etc/nginx/conf.d/403-if-not-verified;

        proxy_pass http://...;
        proxy_http_version 1.1;
        proxy_set_header Upgrade $http_upgrade;
        proxy_set_header Connection "upgrade";
        proxy_set_header Host $http_host;

        proxy_set_header X-Real-IP $remote_addr;
        proxy_set_header X-Forward-For $proxy_add_x_forwarded_for;
        proxy_set_header X-Forward-Proto http;
        proxy_set_header X-Nginx-Proxy true;

        proxy_redirect off;
    }

    location ^~ /.well-known {
        root /usr/share/nginx/html/;
        allow all;
    }
}

Result:

root@raspberrypi:/var/log/nginx/example.com# ls -la
total 12
drwxr-xr-x  2 www-data adm 4096 Aug 28 09:55 .
drwxr-xr-x 12 www-data adm 4096 Aug 28 08:53 ..
-rw-r--r--  1 www-data adm 1417 Aug 28 09:55 access.log
-rw-r--r--  1 www-data adm    0 Aug 28 09:55 error.log

access.log:

192.168.1.1 - - [28/Aug/2021:09:46:29 +0300] "GET / HTTP/1.1" 403 135 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0"
192.168.1.1 - - [28/Aug/2021:09:49:53 +0300] "GET / HTTP/1.1" 403 135 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0"
192.168.1.1 - - [28/Aug/2021:09:50:53 +0300] "GET / HTTP/1.1" 403 135 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0"
192.168.1.1 - - [28/Aug/2021:09:52:02 +0300] "GET / HTTP/1.1" 403 135 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0"
192.168.1.1 - - [28/Aug/2021:09:52:30 +0300] "GET / HTTP/1.1" 403 135 "-" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0"

All the include configs contain just certificate-related stuff, nothing to do with logging.

upd. Also, I tried to put error_log directive inside of / location, but nothing has changed.

upd2. Tried changing log level to debug, got this:

2021/08/28 11:07:32 [debug] 10257#10257: *134281 SSL ALPN supported by client: h2
2021/08/28 11:07:32 [debug] 10257#10257: *134281 SSL ALPN supported by client: http/1.1
2021/08/28 11:07:32 [debug] 10257#10257: *134281 SSL ALPN selected: http/1.1
2021/08/28 11:07:32 [debug] 10257#10257: *134281 SSL_do_handshake: -1
2021/08/28 11:07:32 [debug] 10257#10257: *134281 SSL_get_error: 2
2021/08/28 11:07:32 [debug] 10257#10257: *134281 reusable connection: 0
2021/08/28 11:07:32 [debug] 10257#10257: *134281 SSL handshake handler: 0
2021/08/28 11:07:32 [debug] 10257#10257: *134281 ssl new session: 95794EF3:32:165
2021/08/28 11:07:32 [debug] 10257#10257: *134281 ssl new session: 05E7BF5A:32:166
2021/08/28 11:07:32 [debug] 10257#10257: *134281 SSL_do_handshake: 1
2021/08/28 11:07:32 [debug] 10257#10257: *134281 SSL: TLSv1.3, cipher: "TLS_AES_128_GCM_SHA256 TLSv1.3 Kx=any Au=any Enc=AESGCM(128) Mac=AEAD"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 reusable connection: 1
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http wait request handler
2021/08/28 11:07:32 [debug] 10257#10257: *134281 posix_memalign: 01341900:256 @16
2021/08/28 11:07:32 [debug] 10257#10257: *134281 malloc: 012C1660:1024
2021/08/28 11:07:32 [debug] 10257#10257: *134281 SSL_read: 464
2021/08/28 11:07:32 [debug] 10257#10257: *134281 SSL_read: -1
2021/08/28 11:07:32 [debug] 10257#10257: *134281 SSL_get_error: 2
2021/08/28 11:07:32 [debug] 10257#10257: *134281 reusable connection: 0
2021/08/28 11:07:32 [debug] 10257#10257: *134281 posix_memalign: 013043B0:4096 @16
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http process request line
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http request line: "GET / HTTP/1.1"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http uri: "/"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http args: ""
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http exten: ""
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http process request header line
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header: "Host: example.com"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header: "User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header: "Accept-Language: en-US,en;q=0.5"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header: "Accept-Encoding: gzip, deflate, br"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header: "Connection: keep-alive"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header: "Upgrade-Insecure-Requests: 1"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header: "Sec-Fetch-Dest: document"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header: "Sec-Fetch-Mode: navigate"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header: "Sec-Fetch-Site: none"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header: "Sec-Fetch-User: ?1"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header: "Cache-Control: max-age=0"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 http header done
2021/08/28 11:07:32 [debug] 10257#10257: *134281 event timer del: 3: 215143200
2021/08/28 11:07:32 [debug] 10257#10257: *134281 generic phase: 0
2021/08/28 11:07:32 [debug] 10257#10257: *134281 rewrite phase: 1
2021/08/28 11:07:32 [debug] 10257#10257: *134281 test location: "/"
2021/08/28 11:07:32 [debug] 10257#10257: *134281 using configuration "/"

upd3. Permissions for both log files are the same, so means ok.

ihorc avatar
cn flag
Okay, looks like such errors as 4XX and 5XX should not go to error.log as it is only for configuration/software errors?
Score:3
us flag

error.log contains detailed information about errors that happen on the server side, that is, HTTP error codes 5xx and other startup / internal errors.

It is not meant for logging all HTTP error status codes.

If you want to only log specific HTTP errors, you can create a second access_log entry with filtering. The example below is from nginx documentation with slight modification:

map $status $loggable {
    default 0;
    ~^4 1;
}

access_log /path/to/log combined if=$loggable;

The map is used to check status code and set $loggable variable accordingly. Default action is to not log, and if the HTTP status code starts with 4, then the request is logged.

mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.