kubernetes / ingress-nginx

Ingress NGINX Controller for Kubernetes
https://kubernetes.github.io/ingress-nginx/
Apache License 2.0
17.6k stars 8.27k forks source link

Logging response body #4824

Closed mozgoo closed 4 years ago

mozgoo commented 4 years ago

Is this a request for help? : yes


NGINX Ingress controller version: 0.26.1

Kubernetes version (use kubectl version): v1.14.3

Environment:

What happened: I want to log response body but no success

How to reproduce it (as minimally and precisely as possible): change nginx.tmpl: added some if in body_filter_by_lua_block

...
                body_filter_by_lua_block {
                    {{ if shouldConfigureLuaRestyWAF $all.Cfg.DisableLuaRestyWAF $location.LuaRestyWAF.Mode }}
                    local lua_resty_waf = require "resty.waf"
                    local waf = lua_resty_waf:new()
                    waf:exec()
                    {{ end }}

                    if ngx.var.log_response_body then
                       ngx.var.response_body = ngx.arg[1]
                       ngx.log(ngx.NOTICE, ngx.arg[1])
                    end
                }
...

and initialize variable also in nginx.tmpl:

...
            location {{ $path }} {
                {{ $ing := (getIngressInformation $location.Ingress $server.Hostname $location.Path) }}
                set $response_body  "";
                set $namespace      {{ $ing.Namespace | quote}};
                set $ingress_name   {{ $ing.Rule | quote }};
                set $service_name   {{ $ing.Service | quote }};
                set $service_port   {{ $ing.ServicePort | quote }};
                set $location_path  {{ $location.Path | escapeLiteralDollar | quote }};
...

configmap with settings:

apiVersion: v1
data:
  log-format-escape-json: "true"
  log-format-upstream: '{"scheme": "$scheme", "host": "$host", "local_time": "$time_local",
    "client": {"ip": "$remote_addr", "user": "$remote_user"}, "request": {"method":
    "$request_method", "uri": "$request_uri", "body": "$request_body", "id": "$req_id",
    "length": $request_length, "protocol": "$server_protocol", "time": $request_time,
    "query": "$query_string"}, "response": {"time": "$upstream_response_time", "status":
    $status, "body": "$response_body"}, "headers": {"referrer": "$http_referer", "user-agent":
    "$http_user_agent", "content-type": "$content_type", "content-length": "$content_length"},
    "upstream": {"name": "$proxy_upstream_name", "address": "$upstream_addr", "response_length":
    "$upstream_response_length", "status": "$upstream_status"}, "server": {"version":
    "$nginx_version", "pid": $pid}}'
kind: ConfigMap
metadata:
  creationTimestamp: "2019-12-10T09:22:48Z"
  labels:
    app: nginx-ingress
    chart: nginx-ingress-1.26.2
    component: controller
    heritage: Tiller
    release: ingress
  name: ingress-nginx-ingress-controller
  namespace: default

testing backend:

apiVersion: apps/v1
kind: Deployment
metadata:
  name: nginx
  labels:
    app: nginx
spec:
  replicas: 1
  selector:
    matchLabels:
      app: nginx
  template:
    metadata:
      labels:
        app: nginx
    spec:
      containers:
        - name: app
          image: nginx:latest
          ports:
            - containerPort: 80
---
apiVersion: v1
kind: Service
metadata:
  name: nginx-svc
  labels:
    app: nginx
spec:
  selector:
    app: nginx
  ports:
    - protocol: TCP
      port: 80
      targetPort: 80
---
apiVersion: extensions/v1beta1
kind: Ingress
metadata:
  name: nginx-ing
  labels:
    app: nginx
  annotations:
    kubernetes.io/ingress.class: nginx
    nginx.ingress.kubernetes.io/configuration-snippet: |
      set $log_response_body "on";
spec:
  rules:
  - host: test.internal
    http:
      paths:
      - path: /
        backend:
          serviceName: nginx-svc
          servicePort: 80

In nginx-controller logs I see no response.body value in my custom log_format

2019/12/11 08:40:56 [notice] 40#40: *1554 [lua] body_filter_by_lua:5:  while reading response header from upstream, client: 192.168.65.3, server: test.internal, request: "GET / HTTP/1.1", upstream: "http://10.1.0.20:80/", host: "test.internal"
2019/12/11 08:40:56 [notice] 40#40: *1554 [lua] body_filter_by_lua:5: <!DOCTYPE html>
<html>
<head>
<title>Welcome to nginx!</title>
<style>
    body {
        width: 35em;
        margin: 0 auto;
        font-family: Tahoma, Verdana, Arial, sans-serif;
    }
</style>
</head>
<body>
<h1>Welcome to nginx!</h1>
<p>If you see this page, the nginx web server is successfully installed and
working. Further configuration is required.</p>

<p>For online documentation and support please refer to
<a href="http://nginx.org/">nginx.org</a>.<br/>
Commercial support is available at
<a href="http://nginx.com/">nginx.com</a>.</p>

<p><em>Thank you for using nginx.</em></p>
</body>
</html>
 while reading upstream, client: 192.168.65.3, server: test.internal, request: "GET / HTTP/1.1", upstream: "http://10.1.0.20:80/", host: "test.internal"
2019/12/11 08:40:56 [notice] 40#40: *1554 [lua] body_filter_by_lua:5:  while sending to client, client: 192.168.65.3, server: test.internal, request: "GET / HTTP/1.1", upstream: "http://10.1.0.20:80/", host: "test.internal"
{"scheme": "http", "host": "test.internal", "local_time": "11/Dec/2019:08:40:56 +0000", "client": {"ip": "192.168.65.3", "user": ""}, "request": {"method": "GET", "uri": "/", "body": "", "id": "b574cde167af344af0b3fbe373be76af", "length": 77, "protocol": "HTTP/1.1", "time": 0.002, "query": ""}, "response": {"time": "0.000", "status": 200, "body": ""}, "headers": {"referrer": "", "user-agent": "curl/7.64.1", "content-type": "", "content-length": ""}, "upstream": {"name": "default-nginx-svc-80", "address": "10.1.0.20:80", "response_length": "612", "status": "200"}, "server": {"version": "1.15.8", "pid": 40}}

I've tried to log response on openresty/openresty:alpine docker image w/o k8s and it works

conf.d/default.conf:

server {
    listen       80;
    server_name  _;

    set $response_body "";

    body_filter_by_lua_block {
        if ngx.var.log_response then
            ngx.var.response_body = ngx.arg[1]
        end
    }

    location / {
        access_log logs/access.log custom_access;
            root   /usr/local/openresty/nginx/html;
            index  index.html index.htm;
        set $log_response "1";
    }
}
nginx_1  | {"scheme": "http", "host": "127.0.0.1", "local_time": "11/Dec/2019:09:43:59 +0000", "client": {"ip": "172.18.0.1", "user": "-"}, "request": {"method": "GET", "uri": "/", "body": "-", "length": 78, "protocol": "HTTP/1.1", "time": 0.000, "query": "-"}, "response": {"time": "-", "status": 200, "body": "<!DOCTYPE html>\x0A<html>\x0A<head>\x0A<title>Welcome to OpenResty!</title>\x0A<style>\x0A    body {\x0A        width: 35em;\x0A        margin: 0 auto;\x0A        font-family: Tahoma, Verdana, Arial, sans-serif;\x0A    }\x0A</style>\x0A</head>\x0A<body>\x0A<h1>Welcome to OpenResty!</h1>\x0A<p>If you see this page, the OpenResty web platform is successfully installed and\x0Aworking. Further configuration is required.</p>\x0A\x0A<p>For online documentation and support please refer to\x0A<a href=\x22https://openresty.org/\x22>openresty.org</a>.<br/>\x0ACommercial support is available at\x0A<a href=\x22https://openresty.com/\x22>openresty.com</a>.</p>\x0A\x0A<p><em>Thank you for flying OpenResty.</em></p>\x0A</body>\x0A</html>\x0A"}, "headers": {"referrer": "-", "user-agent": "curl/7.64.1", "content-type": "-", "content-length": "-"}, "server": {"version": "1.15.8", "pid": 7}}

Please help whats wrong in my configuration Thanks

mozgoo commented 4 years ago

I forgot that nginx is a proxy and tried to log the response with the proxy_pass and this also does not work, probably the issue can be closed

server {
    listen       80;
    server_name  _;

    set $response_body "-";

    body_filter_by_lua_block {
        if ngx.var.log_response then
            ngx.var.response_body = ngx.arg[1]
        end
    }

    location / {
        access_log logs/access.log custom_access;
        proxy_pass http://nginx-behind:80/;
        set $log_response "1";
    }
}
nginx-behind_1  | 172.18.0.2 - - [11/Dec/2019:10:48:37 +0000] "GET / HTTP/1.0" 200 612 "-" "curl/7.64.1" "-"
nginx_1         | {"scheme": "http", "host": "127.0.0.1", "local_time": "11/Dec/2019:10:48:37 +0000", "client": {"ip": "172.18.0.1", "user": "-"}, "request": {"method": "GET", "uri": "/", "body": "-", "length": 78, "protocol": "HTTP/1.1", "time": 0.000, "query": "-"}, "response": {"time": "0.010", "status": 200, "body": ""}, "headers": {"referrer": "-", "user-agent": "curl/7.64.1", "content-type": "-", "content-length": "-"}, "server": {"version": "1.15.8", "pid": 6}}