Ingress-nginx: Nginx [notice] logs are not JSON formated

[geek876]

BUG REPORT :

NGINX Ingress controller version:
0.10.2 also tried it with 0.11.0

Kubernetes version (use kubectl version):
Client Version: version.Info{Major:"1", Minor:"8", GitVersion:"v1.8.4", GitCommit:"9befc2b8928a9426501d3bf62f72849d5cbcd5a3", GitTreeState:"clean", BuildDate:"2017-11-20T05:28:34Z", GoVersion:"go1.8.3", Compiler:"gc", Platform:"darwin/amd64"} Server Version: version.Info{Major:"1", Minor:"8+", GitVersion:"v1.8.4+coreos.0", GitCommit:"4292f9682595afddbb4f8b1483673449c74f9619", GitTreeState:"clean", BuildDate:"2017-11-21T17:22:25Z", GoVersion:"go1.8.3", Compiler:"gc", Platform:"linux/amd64"}

Environment:

• Cloud provider or hardware configuration: Azure
• OS (e.g. from /etc/os-release): Container Linux by CoreOS 1662.1.0 (Ladybug) 4.14.15-coreos docker://17.12.0-ce
• Kernel (e.g. uname -a):
• Install tools:
• Others:

What happened:
Nginx [notice] logs ends up non-json formatted even though the configmap sets
log-format-escape-json: "true"
log-format-upstream: '{ "time": "$time_iso8601", "remote_addr": "$proxy_protocol_addr", "x-forward-for": "$proxy_add_x_forwarded_for", "request_id": "$request_id", "remote_user": "$remote_user", "bytes_sent": $bytes_sent, "request_time": $request_time, "status": $status, "vhost": "$host", "request_proto": "$server_protocol", "path": "$uri", "request_query": "$args", "request_length": $request_length, "duration": $request_time, "method": "$request_method", "http_referrer": "$http_referer", "http_user_agent": "$http_user_agent" }'
warn and error logs do get JSON formatted
The error-log level is 'notice' by default.
https://github.com/kubernetes/ingress-nginx/blob/master/docs/user-guide/configmap.md#error-log-level.

What you expected to happen:
[notice] logs should also get JSON formatted

How to reproduce it (as minimally and precisely as possible):
Set log-format-escape-json and log-format-upstream as above within ConfigMap, then trigger a [notice] event within Nginx.

Anything else we need to know:

[aledbf]

@geek876 please post an example of the logs without the format

[geek876]

@aledbf

NON JSON

2018/03/19 12:53:21 [notice] 37619#37619: *60751257 rewritten data: "/health", args: "", client: 10.55.3.0, server: x.x.x.com, request: "GET /health/ml HTTP/1.1", host: "x.x.x.com"
2018/03/19 12:57:51 [notice] 37619#37619: *60755636 "/health(.*)" matches "/health/ml", client: 10.55.11.0, server: x.x.x.com, request: "GET /health/ml HTTP/1.1", host: "x.x.x.com"
2018/03/19 12:57:51 [notice] 37619#37619: *60755636 rewritten data: "/health", args: "", client: 10.55.11.0, server: x.x.x.com, request: "GET /health/ml HTTP/1.1", host: "x.x.x.com"
2018/03/19 12:58:21 [notice] 37619#37619: *60756229 "/health(.*)" matches "/health/ml", client: 10.55.12.0, server: x.x.x.com, request: "GET /health/ml HTTP/1.1", host: "x.x.x.com"
2018/03/19 12:58:21 [notice] 37619#37619: *60756229 rewritten data: "/health", args: "", client: 10.55.12.0, server: x.x.x.com, request: "GET /health/ml HTTP/1.1", host: "x.x.x.com"

JSON

{ "time": "2018-03-19T12:22:41+00:00", "remote_addr": "", "x-forward-for": "10.55.9.0", "request_id": "aaa31d227e2be356864c6c48a26dcf8b", "remote_user": "", "bytes_sent": 54008, "request_time": 0.046, "status": 200, "vhost": "x.x.com", "request_proto": "HTTP/2.0", "path": "/a9bdd30425d018022b089472e3268fc2.eot", "request_query": "__uncache=3%2F13%2F2018%2C%201%3A44%3A10%20PM", "request_length": 74, "duration": 0.046, "method": "GET", "http_referrer": "https://x.x.com/sw.js", "http_user_agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/65.0.3325.162 Safari/537.36" }

[aledbf]

Closing. This is working as expected. The real issue here is that nginx doesn't support custom formats for error_log