nginx proxy_pass can't got full response data from outputstream

8/2/2021

The backend endpoint works using k8s-client to watch POD logs with the following code.

    @RequestMapping(value = "/{podName}/log", method = RequestMethod.GET)
    public void queryLog(HttpServletResponse response, @PathVariable(name = "podName", required = true) String podName,
                         @RequestParam(name = "container", required = true) String container,
                         @RequestParam(name = "tailLines", required = false) Integer tailLines,
                         @RequestParam(name = "timestamps", required = false) boolean timestamps,
                         @RequestParam(name = "follow", required = false) boolean follow) {
        try {
            PodLogs logs = new PodLogs();
            InputStream is = logs.streamNamespacedPodLog(namespace, podName, container, null, tailLines, timestamps, follow);
            copy(is, response.getOutputStream());

        } catch (Exception ex) {
            logger.error("exception", ex);
        }
    }

    public static void copy(InputStream in, OutputStream out) throws IOException {

        try {
            byte[] buffer = new byte[4096];
            int bytesRead;
            while ((bytesRead = in.read(buffer)) != -1) {
                String str = new String(buffer, 0, bytesRead);
                out.write(buffer, 0, bytesRead);
                out.flush();
            }
        } catch (IOException ex) {
            ex.printStackTrace();
        } finally {
            if (in != null) {
                in.close();
            }
            if (out != null) {
                out.close();
            }
        }

    }

The front:

<html>
	<head>
	    <title>Test</title>
	    <script type="text/javascript">
	    
	    var xhr = null;
	    
	     function setConnected(connected) {
	        	
	            document.getElementById('connect').disabled = connected;
	            document.getElementById('disconnect').disabled = !connected;
	            document.getElementById('response').innerHTML = '';
	        }
	      
	     function connect() {
	    
	      xhr = new XMLHttpRequest()

		  xhr.open('GET', `http://proxy.k8s.io/backend/api/pod-0/log?container=pod&tailLines=500&timestamps=true&follow=true`, true)

		  xhr.onreadystatechange = () => {
		    setConnected(true);
		    if (xhr.readyState >= 3 && xhr.status === 200) {
			   console.log("###")
		       console.log(xhr.responseText)
			   document.getElementById('response').innerHTML = document.getElementById('response').innerHTML + xhr.responseText;
		    }
		  }

		  xhr.send()
	    }
	     function disconnect() {
	        	
	            if(xhr != null) {
	                xhr.abort();
	            }
	            
	            setConnected(false);
	            console.log("Disconnected");
	        }
	    </script>
	    
	</head>
	
	<body  onload="disconnect()">
	 <div>
		<button id="connect" onclick="connect();">Connect</button>
		<button id="disconnect" disabled="disabled" onclick="disconnect();">Disconnect</button>
        </div>
	<div id="response"></div>
	</body>
</html>

I could get the full log and watched new generated log without nginx. However nginx with the following config can't get the full log from backend.

upstream backend {
        server backend:8080;
        keepalive_timeout 60s;
        keepalive 60;
        keepalive_requests 100;
}

server {
    listen       80;

    location / {
        root   /usr/share/nginx/html;
        index  index.html index.htm;
    }

    location /backend/api/ {
        proxy_pass http://backend/;
    }
}

The expected log sample:

2021-08-02T02:51:04.857054753Z 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
2021-08-02T02:51:04.857057468Z 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
2021-08-02T02:51:04.857060467Z 	at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93)
2021-08-02T02:51:04.857063232Z 	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)

The sample log I got:

2021-08-02T02:51:04.857054753Z 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
2021-08-02T02:51:04.857057468Z 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
2021-08-02T02:51:04.857060467Z 	at org.springframework.web.filter.HiddenHt

It looks like that the last chunked data was lost. When I accessed it with tailLines=200, some data still was lost. And when new logs were generated, no new data could display in the front page.

-- niaomingjian
java
kubernetes
nginx

2 Answers

8/2/2021

The issue is likely due to flushing to output in each iteration, and Nginx only forwarding the first chunk.

This is in the specs:

When buffering is disabled, the response is passed to a client synchronously, immediately as it is received. nginx will not try to read the whole response from the proxied server.

Try proxy_buffering on; in nginx, or the header X-Accel-Buffering: yes. Or buffer the whole response in Java.

See also https://stackoverflow.com/a/23171377/7362396

-- Tobias K.
Source: StackOverflow

8/2/2021

The root cause is the incorrect proxy_http_version. By default, the version 1.0 is used. Version 1.1 should be used for the keepalive connection.

Docs say:

Syntax: proxy_http_version 1.0 | 1.1;
Default: proxy_http_version 1.0;
Context: http, server, location
This directive appeared in version 1.1.4.

Sets the HTTP protocol version for proxying. By default, version 1.0 is used. Version 1.1 is recommended for use with keepalive connections and NTLM authentication.

How to fix:
Add proxy_http_version 1.1; under location block.

    location /backend/api/ {
        proxy_http_version    1.1;
        proxy_pass http://backend/;
    }
-- niaomingjian
Source: StackOverflow