"access_log off" has not effect in NGINX

11/22/2018

So I use ingress-nginx extensively in a Kubernetes environment to load balance and as a proxy however I'm having some difficulty disabling the access_log for a specific site.

Using ingress-nginx 0.20.0 which is built on top of NGINX 1.15.5 I have the following ingress object.

apiVersion: extensions/v1beta1
kind: Ingress
metadata:
  name: kb-kibana
  annotations:
    kubernetes.io/ingress.class: nginx
    kubernetes.io/tls-acme: "true"
    nginx.ingress.kubernetes.io/auth-signin: https://oauth2.test.test.com/oauth2/start
    nginx.ingress.kubernetes.io/auth-url: http://op-oauth2-proxy.control.svc.cluster.local:4180/oauth2/auth
    nginx.ingress.kubernetes.io/enable-access-log: "false"
    nginx.ingress.kubernetes.io/force-ssl-redirect: "true"
    nginx.ingress.kubernetes.io/secure-backends: "false"
    nginx.ingress.kubernetes.io/ssl-passthrough: "false"
    nginx.ingress.kubernetes.io/ssl-redirect: "true"
spec:
  rules:
  - host: kibana.test.com
    http:
      paths:
      - backend:
          serviceName: kb-kibana
          servicePort: 5601
        path: /
  tls:
  - hosts:
    - kibana.test.com
    secretName: kb-kibana-tls

This produces the following nginx.conf,

server {
        server_name kibana.test.com ;

        listen 80;

        listen [::]:80;

        set $proxy_upstream_name "-";

        listen 443  ssl http2;

        listen [::]:443  ssl http2;

        # PEM sha: 402874b12f87115abb8b52a53f8faeabc3a2b647
        ssl_certificate                         /etc/ingress-controller/ssl/monitoring-kb-kibana-tls.pem;
        ssl_certificate_key                     /etc/ingress-controller/ssl/monitoring-kb-kibana-tls.pem;

        ssl_trusted_certificate                 /etc/ingress-controller/ssl/monitoring-kb-kibana-tls-full-chain.pem;
        ssl_stapling                            on;
        ssl_stapling_verify                     on;

        location = /_external-auth-Lw {
                internal;

                # ngx_auth_request module overrides variables in the parent request,
                # therefore we have to explicitly set this variable again so that when the parent request
                # resumes it has the correct value set for this variable so that Lua can pick backend correctly
                set $proxy_upstream_name "monitoring-kb-kibana-5601";

                proxy_pass_request_body     off;
                proxy_set_header            Content-Length "";

                proxy_set_header            Host                    op-oauth2-proxy.control.svc.cluster.local;
                proxy_set_header            X-Original-URL          $scheme://$http_host$request_uri;
                proxy_set_header            X-Original-Method       $request_method;
                proxy_set_header            X-Sent-From             "nginx-ingress-controller";
                proxy_set_header            X-Real-IP               $the_real_ip;

                proxy_set_header            X-Forwarded-For        $the_real_ip;

                proxy_set_header            X-Auth-Request-Redirect $request_uri;

                proxy_buffering                         off;
                proxy_buffer_size                       4k;
                proxy_buffers                           4 4k;
                proxy_request_buffering                 on;

                proxy_http_version          1.1;
                proxy_ssl_server_name       on;
                proxy_pass_request_headers  on;
                client_max_body_size        10m;

                # Pass the extracted client certificate to the auth provider

                set $target http://op-oauth2-proxy.control.svc.cluster.local:4180/oauth2/auth;
                proxy_pass $target;
        }

        location / {

                set $namespace      "monitoring";
                set $ingress_name   "kb-kibana";
                set $service_name   "kb-kibana";
                set $service_port   "5601";
                set $location_path  "/";

                rewrite_by_lua_block {

                        balancer.rewrite()

                }

                log_by_lua_block {

                        balancer.log()

                        monitor.call()
                }

                if ($scheme = https) {
                        more_set_headers                        "Strict-Transport-Security: max-age=15724800; includeSubDomains";
                }

                access_log off;

                .....
        }
}

However, despite of access_log off; above it still logs the following in the access log,

{"proxy_protocol_addr": "","remote_addr": "xxx.xxx.xxx.xx", "proxy_add_x_forwarded_for": "xxx.xxx.xxx.xx, xxx.xxx.xxx.xx", "remote_user": "", "time_local": "21/Nov/2018:09:53:39 +0000", "request" : "GET / HTTP/1.1", "status": "202", "body_bytes_sent": "0", "http_referer":  "", "http_user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36", "request_length" : "0", "request_time": "0.004", "proxy_upstream_name": "monitoring-kb-kibana-5601", "upstream_addr": "xxx.xxx.xxx.xx:4180",  "upstream_response_length": "0", "upstream_response_time": "0.003", "upstream_status": "202", "request_body": "", "http_authorization": ""}
{"proxy_protocol_addr": "","remote_addr": "xxx.xxx.xxx.xx", "proxy_add_x_forwarded_for": "xxx.xxx.xxx.xx, xxx.xxx.xxx.xx", "remote_user": "", "time_local": "21/Nov/2018:09:53:40 +0000", "request" : "GET /app/kibana HTTP/1.1", "status": "202", "body_bytes_sent": "0", "http_referer":  "https://kibana.test.com/", "http_user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36", "request_length" : "0", "request_time": "0.001", "proxy_upstream_name": "monitoring-kb-kibana-5601", "upstream_addr": "xxx.xxx.xxx.xx:4180",  "upstream_response_length": "0", "upstream_response_time": "0.001", "upstream_status": "202", "request_body": "", "http_authorization": ""}
{"proxy_protocol_addr": "","remote_addr": "xxx.xxx.xxx.xx", "proxy_add_x_forwarded_for": "xxx.xxx.xxx.xx, xxx.xxx.xxx.xx", "remote_user": "", "time_local": "21/Nov/2018:09:53:42 +0000", "request" : "GET /api/console/api_server?sense_version=%40%40SENSE_VERSION&apis=es_6_0 HTTP/1.1", "status": "202", "body_bytes_sent": "0", "http_referer":  "https://kibana.test.com/app/kibana", "http_user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36", "request_length" : "0", "request_time": "0.002", "proxy_upstream_name": "monitoring-kb-kibana-5601", "upstream_addr": "xxx.xxx.xxx.xx:4180",  "upstream_response_length": "0", "upstream_response_time": "0.001", "upstream_status": "202", "request_body": "", "http_authorization": ""}
{"proxy_protocol_addr": "","remote_addr": "xxx.xxx.xxx.xx", "proxy_add_x_forwarded_for": "xxx.xxx.xxx.xx, xxx.xxx.xxx.xx", "remote_user": "", "time_local": "21/Nov/2018:09:53:43 +0000", "request" : "GET /plugins/kibana/assets/discover.svg HTTP/1.1", "status": "202", "body_bytes_sent": "0", "http_referer":  "https://kibana.test.com/app/kibana", "http_user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36", "request_length" : "0", "request_time": "0.001", "proxy_upstream_name": "monitoring-kb-kibana-5601", "upstream_addr": "xxx.xxx.xxx.xx:4180",  "upstream_response_length": "0", "upstream_response_time": "0.001", "upstream_status": "202", "request_body": "", "http_authorization": ""}
{"proxy_protocol_addr": "","remote_addr": "xxx.xxx.xxx.xx", "proxy_add_x_forwarded_for": "xxx.xxx.xxx.xx, xxx.xxx.xxx.xx", "remote_user": "", "time_local": "21/Nov/2018:09:53:43 +0000", "request" : "GET /plugins/timelion/icon.svg HTTP/1.1", "status": "202", "body_bytes_sent": "0", "http_referer":  "https://kibana.test.com/app/kibana", "http_user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36", "request_length" : "0", "request_time": "0.001", "proxy_upstream_name": "monitoring-kb-kibana-5601", "upstream_addr": "xxx.xxx.xxx.xx:4180",  "upstream_response_length": "0", "upstream_response_time": "0.000", "upstream_status": "202", "request_body": "", "http_authorization": ""}
{"proxy_protocol_addr": "","remote_addr": "xxx.xxx.xxx.xx", "proxy_add_x_forwarded_for": "xxx.xxx.xxx.xx, xxx.xxx.xxx.xx", "remote_user": "", "time_local": "21/Nov/2018:09:53:43 +0000", "request" : "GET /plugins/kibana/assets/settings.svg HTTP/1.1", "status": "202", "body_bytes_sent": "0", "http_referer":  "https://kibana.test.com/app/kibana", "http_user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36", "request_length" : "0", "request_time": "0.029", "proxy_upstream_name": "monitoring-kb-kibana-5601", "upstream_addr": "xxx.xxx.xxx.xx:4180",  "upstream_response_length": "0", "upstream_response_time": "0.030", "upstream_status": "202", "request_body": "", "http_authorization": ""}
{"proxy_protocol_addr": "","remote_addr": "xxx.xxx.xxx.xx", "proxy_add_x_forwarded_for": "xxx.xxx.xxx.xx, xxx.xxx.xxx.xx", "remote_user": "", "time_local": "21/Nov/2018:09:53:43 +0000", "request" : "GET /plugins/kibana/assets/dashboard.svg HTTP/1.1", "status": "202", "body_bytes_sent": "0", "http_referer":  "https://kibana.test.com/app/kibana", "http_user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36", "request_length" : "0", "request_time": "0.029", "proxy_upstream_name": "monitoring-kb-kibana-5601", "upstream_addr": "xxx.xxx.xxx.xx:4180",  "upstream_response_length": "0", "upstream_response_time": "0.030", "upstream_status": "202", "request_body": "", "http_authorization": ""}
{"proxy_protocol_addr": "","remote_addr": "xxx.xxx.xxx.xx", "proxy_add_x_forwarded_for": "xxx.xxx.xxx.xx, xxx.xxx.xxx.xx", "remote_user": "", "time_local": "21/Nov/2018:09:53:43 +0000", "request" : "GET /ui/favicons/favicon-32x32.png HTTP/1.1", "status": "202", "body_bytes_sent": "0", "http_referer":  "https://kibana.test.com/app/kibana", "http_user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36", "request_length" : "0", "request_time": "0.001", "proxy_upstream_name": "monitoring-kb-kibana-5601", "upstream_addr": "xxx.xxx.xxx.xx:4180",  "upstream_response_length": "0", "upstream_response_time": "0.001", "upstream_status": "202", "request_body": "", "http_authorization": ""}
{"proxy_protocol_addr": "","remote_addr": "xxx.xxx.xxx.xx", "proxy_add_x_forwarded_for": "xxx.xxx.xxx.xx, xxx.xxx.xxx.xx", "remote_user": "", "time_local": "21/Nov/2018:09:53:44 +0000", "request" : "GET /plugins/kibana/assets/wrench.svg HTTP/1.1", "status": "202", "body_bytes_sent": "0", "http_referer":  "https://kibana.test.com/app/kibana", "http_user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36", "request_length" : "0", "request_time": "0.003", "proxy_upstream_name": "monitoring-kb-kibana-5601", "upstream_addr": "xxx.xxx.xxx.xx:4180",  "upstream_response_length": "0", "upstream_response_time": "0.003", "upstream_status": "202", "request_body": "", "http_authorization": ""}
{"proxy_protocol_addr": "","remote_addr": "xxx.xxx.xxx.xx", "proxy_add_x_forwarded_for": "xxx.xxx.xxx.xx, xxx.xxx.xxx.xx", "remote_user": "", "time_local": "21/Nov/2018:09:53:45 +0000", "request" : "GET /ui/fonts/open_sans/open_sans_v15_latin_600.woff2 HTTP/1.1", "status": "202", "body_bytes_sent": "0", "http_referer":  "https://kibana.test.com/app/kibana", "http_user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36", "request_length" : "0", "request_time": "0.002", "proxy_upstream_name": "monitoring-kb-kibana-5601", "upstream_addr": "xxx.xxx.xxx.xx:4180",  "upstream_response_length": "0", "upstream_response_time": "0.002", "upstream_status": "202", "request_body": "", "http_authorization": ""}

This appears to be a NGINX specific issue as I cant see anything wrong with the nginx.conf configuration at this point. Any help is appreciated.

-- nixgadget
kubernetes
nginx
nginx-ingress

1 Answer

11/22/2018

Log requests are logged in the context of a location where processing ends. Module ngx_http_log_module

So you have missing access_log off; in location = /_external-auth-Lw

Looking at the upstream port - 4180 - on the logged requests, I believe those are requests from the _external-auth-Lw location.

-- Gal S
Source: StackOverflow