ingress-nginx: Invalid handling of chunked requests: Transfer-encoding "chunked" changed automatically to content-length
Is this a BUG REPORT or FEATURE REQUEST? (choose one): BUG REPORT
NGINX Ingress controller version: Release: 0.26.1 Build: git-2de5a893a Repository: https://github.com/kubernetes/ingress-nginx nginx version: openresty/1.15.8.2
Kubernetes version (use kubectl version
):
Server Version: version.Info{Major:“1”, Minor:“13”, GitVersion:“v1.13.0”, GitCommit:“ddf47ac13c1a9483ea035a79cd7c10005ff21a6d”, GitTreeState:“clean”, BuildDate:“2018-12-03T20:56:12Z”, GoVersion:“go1.11.2”, Compiler:“gc”, Platform:“linux/amd64”}
Environment:
- Cloud provider or hardware configuration: On-prem and Minikube
- OS (e.g. from /etc/os-release):
- Kernel (e.g.
uname -a
): - Install tools:
- Others:
What happened:
I have a java client that sends chunked HTTP POST requests, and it works fine when it is connected directly to my service using the node IP and service port. The problem is when the client sends requests through the Ingress. Requests with chunked data lower than 2m are failling and one or two passing and it feels that is random. After checking the logs, I found out that that the nginx ingress controller is changing the header “Transfer-Encoding: chunked” to “Content-Length”.
What you expected to happen:
Ingress controller should not buffer the incoming requests if proxy_request_buffering is off.
How to reproduce it (as minimally and precisely as possible):
- Start Minikube with 1.13.
- Enable Ingress
- Configure ingress and turn off proxy_buffering and proxy_request_buffering. Here is the config:
apiVersion: extensions/v1beta1
kind: Ingress
metadata:
name: spectrum-replicator-http-api-com
annotations:
kubernetes.io/ingress.class: nginx
nginx.ingress.kubernetes.io/backend-protocol: "HTTP"
nginx.ingress.kubernetes.io/proxy-buffering: "off"
nginx.ingress.kubernetes.io/proxy-body-size: "0"
nginx.ingress.kubernetes.io/proxy-request-buffering: "off"
nginx.ingress.kubernetes.io/proxy-max-temp-file-size: "0"
spec:
rules:
- host: spectrum-replicator-http-api.com
http:
paths:
- path: /
backend:
serviceName: spectrum-replicator
servicePort: 10010
-
Set Ingress controller in debug mode
-
Send POST HTTP request with chunked data. In my case, the java client sends the same request with different payload sizes 3k, 33k, 500k, 1m, 2m, 3m, 5m, 7m …
-
Here is one of the failing requests. The ingress controller response with 200 OK and zero content. The Nginx ingress controller gets the chunk data from the client and changes the request to use Content-Length: 38. (including an example with logs from the same request with the correct headers)
http request line: "POST /api/1/space/spectrum-aa-1/objects/test-1576243368918%2Fload-test-2/payload HTTP/1.1"
lua rewrite handler, uri:"/api/1/space/spectrum-aa-1/objects/test-1576243368918/load-test-2/payload" c:1
2019/12/13 13:22:50 [debug] 47#47: *310 looking up Lua code cache with key '=rewrite_by_lua(nginx.conf:450)nhli_810dc96928b7314c9cd60e7b526c7375'
2019/12/13 13:22:50 [debug] 47#47: *310 lua creating new thread
2019/12/13 13:22:50 [debug] 47#47: *310 lua reset ctx
2019/12/13 13:22:50 [debug] 47#47: *310 http cleanup add: 00005600766C5A38
2019/12/13 13:22:50 [debug] 47#47: *310 lua run thread, top:0 c:1
2019/12/13 13:22:50 [debug] 47#47: *310 add cleanup: 00005600766C5A90
2019/12/13 13:22:50 [debug] 47#47: *310 lua resume returned 0
2019/12/13 13:22:50 [debug] 47#47: *310 lua light thread ended normally
2019/12/13 13:22:50 [debug] 47#47: *310 lua deleting light thread
2019/12/13 13:22:50 [debug] 47#47: *310 post rewrite phase: 7
2019/12/13 13:22:50 [debug] 47#47: *310 generic phase: 8
2019/12/13 13:22:50 [debug] 47#47: *310 generic phase: 9
2019/12/13 13:22:50 [debug] 47#47: *310 generic phase: 10
2019/12/13 13:22:50 [debug] 47#47: *310 access phase: 11
2019/12/13 13:22:50 [debug] 47#47: *310 access phase: 12
2019/12/13 13:22:50 [debug] 47#47: *310 access phase: 13
2019/12/13 13:22:50 [debug] 47#47: *310 access phase: 14
2019/12/13 13:22:50 [debug] 47#47: *310 post access phase: 15
2019/12/13 13:22:50 [debug] 47#47: *310 generic phase: 16
2019/12/13 13:22:50 [debug] 47#47: *310 generic phase: 17
2019/12/13 13:22:50 [debug] 47#47: *310 posix_memalign: 0000560076664310:4096 @16
2019/12/13 13:22:50 [debug] 47#47: *310 http client request body preread 59
2019/12/13 13:22:50 [debug] 47#47: *310 http request body chunked filter
2019/12/13 13:22:50 [debug] 47#47: *310 http body chunked buf t:1 f:0 00005600766612E0, pos 0000560076661912, size: 59 file: 0, size: 0
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 63 s:0
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0D s:1
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0A s:3
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 54 s:4
2019/12/13 13:22:50 [debug] 47#47: *310 http body chunked buf t:1 f:0 00005600766612E0, pos 0000560076661921, size: 44 file: 0, size: 0
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0D s:5
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0A s:6
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 31 s:0
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 34 s:1
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0D s:1
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0A s:3
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 36 s:4
2019/12/13 13:22:50 [debug] 47#47: *310 http body chunked buf t:1 f:0 00005600766612E0, pos 000056007666193B, size: 18 file: 0, size: 0
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0D s:5
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0A s:6
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 36 s:0
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0D s:1
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0A s:3
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 52 s:4
2019/12/13 13:22:50 [debug] 47#47: *310 http body chunked buf t:1 f:0 00005600766612E0, pos 0000560076661946, size: 7 file: 0, size: 0
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0D s:5
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0A s:6
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 30 s:0
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0D s:1
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0A s:8
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0D s:9
2019/12/13 13:22:50 [debug] 47#47: *310 http chunked byte: 0A s:10
2019/12/13 13:22:50 [debug] 47#47: *310 http body new buf t:1 f:0 0000560076661915, pos 0000560076661915, size: 12 file: 0, size: 0
2019/12/13 13:22:50 [debug] 47#47: *310 http body new buf t:1 f:0 0000560076661927, pos 0000560076661927, size: 20 file: 0, size: 0
2019/12/13 13:22:50 [debug] 47#47: *310 http body new buf t:1 f:0 0000560076661940, pos 0000560076661940, size: 6 file: 0, size: 0
2019/12/13 13:22:50 [debug] 47#47: *310 http body new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2019/12/13 13:22:50 [debug] 47#47: *310 http init upstream, client timer: 0
2019/12/13 13:22:50 [debug] 47#47: *310 http map started
2019/12/13 13:22:50 [debug] 47#47: *310 http map: "" ""
2019/12/13 13:22:50 [debug] 47#47: *310 http map started
2019/12/13 13:22:50 [debug] 47#47: *310 http script var: "7ec5a68f74b7e62717c59e19d8653836"
2019/12/13 13:22:50 [debug] 47#47: *310 http map: "" "7ec5a68f74b7e62717c59e19d8653836"
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: "Host"
2019/12/13 13:22:50 [debug] 47#47: *310 http script var: "spectrum-replicator-http-api.com:80"
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: ""
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: ""
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: "X-Request-ID"
2019/12/13 13:22:50 [debug] 47#47: *310 http script var: "7ec5a68f74b7e62717c59e19d8653836"
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: "X-Real-IP"
2019/12/13 13:22:50 [debug] 47#47: *310 http script var: "192.168.64.1"
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: "X-Forwarded-For"
2019/12/13 13:22:50 [debug] 47#47: *310 http script var: "192.168.64.1"
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: "X-Forwarded-Host"
2019/12/13 13:22:50 [debug] 47#47: *310 http script var: "spectrum-replicator-http-api.com:80"
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: "X-Forwarded-Port"
2019/12/13 13:22:50 [debug] 47#47: *310 http script var: "80"
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: "X-Forwarded-Proto"
2019/12/13 13:22:50 [debug] 47#47: *310 http script var: "http"
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: "X-Scheme"
2019/12/13 13:22:50 [debug] 47#47: *310 http script var: "http"
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: ""
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: "Content-Length"
2019/12/13 13:22:50 [debug] 47#47: *310 http script var: "38"
2019/12/13 13:22:50 [debug] 47#47: *310 http script copy: ""
"POST /api/1/space/spectrum-aa-1/objects/test-1576243368918%2Fload-test-2/payload HTTP/1.1
Host: spectrum-replicator-http-api.com:80
X-Request-ID: 7ec5a68f74b7e62717c59e19d8653836
X-Real-IP: 192.168.64.1
X-Forwarded-For: 192.168.64.1
X-Forwarded-Host: spectrum-replicator-http-api.com:80
X-Forwarded-Port: 80
X-Forwarded-Proto: http
X-Scheme: http
Content-Length: 38
Content-Type: application/octet-stream
Anything else we need to know: In this particular test, the tcpdumps show that the client is sending 5 segments of data to the nginx and the ingress controller resend the chunked data in 2 segments. Here are the logs of the same request but the ingress controller does nothing to the buffers or headers.
http request line: "POST /api/1/space/spectrum-aa-1/objects/test-1576243368918%2Fload-test-1/payload HTTP/1.1"
2019/12/13 13:22:49 [debug] 47#47: *310 http client request body preread 17
2019/12/13 13:22:49 [debug] 47#47: *310 http request body chunked filter
2019/12/13 13:22:49 [debug] 47#47: *310 http body chunked buf t:1 f:0 00005600766C4090, pos 00005600766C46C2, size: 17 file: 0, size: 0
2019/12/13 13:22:49 [debug] 47#47: *310 http chunked byte: 63 s:0
2019/12/13 13:22:49 [debug] 47#47: *310 http chunked byte: 0D s:1
2019/12/13 13:22:49 [debug] 47#47: *310 http chunked byte: 0A s:3
2019/12/13 13:22:49 [debug] 47#47: *310 http chunked byte: 54 s:4
2019/12/13 13:22:49 [debug] 47#47: *310 http body chunked buf t:1 f:0 00005600766C4090, pos 00005600766C46D1, size: 2 file: 0, size: 0
2019/12/13 13:22:49 [debug] 47#47: *310 http chunked byte: 0D s:5
2019/12/13 13:22:49 [debug] 47#47: *310 http chunked byte: 0A s:6
2019/12/13 13:22:49 [debug] 47#47: *310 http body new buf t:1 f:0 00005600766C46C5, pos 00005600766C46C5, size: 12 file: 0, size: 0
2019/12/13 13:22:49 [debug] 47#47: *310 malloc: 0000560076663300:8192
2019/12/13 13:22:49 [debug] 47#47: *310 http read client request body
2019/12/13 13:22:49 [debug] 47#47: *310 recv: eof:0, avail:0
2019/12/13 13:22:49 [debug] 47#47: *310 http client request body recv -2
2019/12/13 13:22:49 [debug] 47#47: *310 http client request body rest 3
2019/12/13 13:22:49 [debug] 47#47: *310 event timer add: 3: 60000:22794549
2019/12/13 13:22:49 [debug] 47#47: *310 http init upstream, client timer: 1
2019/12/13 13:22:49 [debug] 47#47: *310 event timer del: 3: 22794549
2019/12/13 13:22:49 [debug] 47#47: *310 http map started
2019/12/13 13:22:49 [debug] 47#47: *310 http map: "" ""
2019/12/13 13:22:49 [debug] 47#47: *310 http map started
2019/12/13 13:22:49 [debug] 47#47: *310 http script var: "a9991ec03b9caa426e510b8ae40f2a13"
2019/12/13 13:22:49 [debug] 47#47: *310 http map: "" "a9991ec03b9caa426e510b8ae40f2a13"
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: "Host"
2019/12/13 13:22:49 [debug] 47#47: *310 http script var: "spectrum-replicator-http-api.com:80"
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: ""
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: ""
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: "X-Request-ID"
2019/12/13 13:22:49 [debug] 47#47: *310 http script var: "a9991ec03b9caa426e510b8ae40f2a13"
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: "X-Real-IP"
2019/12/13 13:22:49 [debug] 47#47: *310 http script var: "192.168.64.1"
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: "X-Forwarded-For"
2019/12/13 13:22:49 [debug] 47#47: *310 http script var: "192.168.64.1"
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: "X-Forwarded-Host"
2019/12/13 13:22:49 [debug] 47#47: *310 http script var: "spectrum-replicator-http-api.com:80"
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: "X-Forwarded-Port"
2019/12/13 13:22:49 [debug] 47#47: *310 http script var: "80"
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: "X-Forwarded-Proto"
2019/12/13 13:22:49 [debug] 47#47: *310 http script var: "http"
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: "X-Scheme"
2019/12/13 13:22:49 [debug] 47#47: *310 http script var: "http"
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: ""
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: ""
2019/12/13 13:22:49 [debug] 47#47: *310 http script copy: "Transfer-Encoding"
2019/12/13 13:22:49 [debug] 47#47: *310 http script var: "chunked"
"POST /api/1/space/spectrum-aa-1/objects/test-1576243368918%2Fload-test-1/payload HTTP/1.1
Host: spectrum-replicator-http-api.com:80
X-Request-ID: a9991ec03b9caa426e510b8ae40f2a13
X-Real-IP: 192.168.64.1
X-Forwarded-For: 192.168.64.1
X-Forwarded-Host: spectrum-replicator-http-api.com:80
X-Forwarded-Port: 80
X-Forwarded-Proto: http
X-Scheme: http
Transfer-Encoding: chunked
Content-Type: application/octet-stream
Here is the nginx config:
## start server spectrum-replicator-http-api.com
server {
server_name spectrum-replicator-http-api.com ;
listen 80 ;
listen 443 ssl http2 ;
set $proxy_upstream_name "-";
ssl_certificate_by_lua_block {
certificate.call()
}
location / {
set $namespace "oneira-sandbox";
set $ingress_name "spectrum-replicator-http-api-com";
set $service_name "spectrum-replicator";
set $service_port "10010";
set $location_path "/";
rewrite_by_lua_block {
lua_ingress.rewrite({
force_ssl_redirect = false,
ssl_redirect = true,
force_no_ssl_redirect = false,
use_port_in_redirects = false,
})
balancer.rewrite()
plugins.run()
}
header_filter_by_lua_block {
plugins.run()
}
body_filter_by_lua_block {
}
log_by_lua_block {
balancer.log()
monitor.call()
plugins.run()
}
port_in_redirect off;
set $balancer_ewma_score -1;
set $proxy_upstream_name "oneira-sandbox-spectrum-replicator-10010";
set $proxy_host $proxy_upstream_name;
set $pass_access_scheme $scheme;
set $pass_server_port $server_port;
set $best_http_host $http_host;
set $pass_port $pass_server_port;
set $proxy_alternative_upstream_name "";
client_max_body_size 0;
proxy_set_header Host $best_http_host;
# Pass the extracted client certificate to the backend
# Allow websocket connections
proxy_set_header Upgrade $http_upgrade;
proxy_set_header Connection $connection_upgrade;
proxy_set_header X-Request-ID $req_id;
proxy_set_header X-Real-IP $remote_addr;
proxy_set_header X-Forwarded-For $remote_addr;
proxy_set_header X-Forwarded-Host $best_http_host;
proxy_set_header X-Forwarded-Port $pass_port;
proxy_set_header X-Forwarded-Proto $pass_access_scheme;
proxy_set_header X-Scheme $pass_access_scheme;
# Pass the original X-Forwarded-For
proxy_set_header X-Original-Forwarded-For $http_x_forwarded_for;
# mitigate HTTPoxy Vulnerability
# https://www.nginx.com/blog/mitigating-the-httpoxy-vulnerability-with-nginx/
proxy_set_header Proxy "";
# Custom headers to proxied server
proxy_connect_timeout 5s;
proxy_send_timeout 60s;
proxy_read_timeout 60s;
proxy_buffering off;
proxy_buffer_size 128k;
proxy_buffers 4 128k;
proxy_max_temp_file_size 0;
proxy_request_buffering off;
proxy_http_version 1.1;
proxy_cookie_domain off;
proxy_cookie_path off;
# In case of errors try the next upstream server before returning an error
proxy_next_upstream error timeout;
proxy_next_upstream_timeout 0;
proxy_next_upstream_tries 3;
proxy_pass http://upstream_balancer;
proxy_redirect off;
}
}
## end server spectrum-replicator-http-api.com
About this issue
- Original URL
- State: closed
- Created 5 years ago
- Reactions: 1
- Comments: 55 (21 by maintainers)
@aledbf any luck?
No, still same issue.
Reading the log I see
Please set
enable-underscores-in-headers: "true"
in the configuration configmap https://kubernetes.github.io/ingress-nginx/user-guide/nginx-configuration/configmap/#enable-underscores-in-headersAlso, please update to 0.30.0. After that, please post the log again with these two changes.
@OscarNeira please don’t take this in the wrong way but I can’t keep doing all these tests. Please update when you can reproduce the issue reliably.
@OscarNeira same
Today I will try to reproduce this issue. Thank you for the procedure to reproduce the issue.
@OscarNeira please update to 0.28.0 and test again.