net/http: Request not cancelled when body is not read

[sheerun]

What version of Go are you using (go version)?

go version go1.9.2 darwin/amd64

Does this issue reproduce with the latest release?

yes

What operating system and processor architecture are you using (go env)?

GOARCH="amd64"
GOBIN="/Users/sheerun/go/bin"
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/sheerun/go"
GORACE=""
GOROOT="/usr/local/Cellar/go/1.9.2/libexec"
GOTOOLDIR="/usr/local/Cellar/go/1.9.2/libexec/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/22/xz6_9gpx3jggts_8j68_25g80000gn/T/go-build547040878=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"

What did you do?

I wanted proper go-lang server that detects when request is cancelled:

package main

import (
	"fmt"
	"net/http"
	"time"
)

func Handler(w http.ResponseWriter, req *http.Request) {
	go func() {
		<-req.Context().Done()
		fmt.Println("done")
	}()

	time.Sleep(10 * time.Second)
}

func main() {
	http.ListenAndServe(":8080", http.HandlerFunc(Handler))
}

What did you expect to see?

Request is immediately cancelled for following calls:

curl http://localhost:8080/hello # then Ctrl+C
curl http://localhost:8080/hello -X POST -d 'asdfa' # then Ctrl+C
curl http://localhost:8080/hello -X PUT  -d 'foobar' # then Ctrl+C

What did you see instead?

Request is not cancelled for POST and PUT with body.

Side note: when POST of PUT is sent without body, the request is cancelled immediately as expected

curl http://localhost:8080/hello -X POST  # then Ctrl+C
curl http://localhost:8080/hello -X PUT # then Ctrl+C

[ianlancetaylor]

CC @bradfitz @tombergan

[sheerun]

I'll only mention it isn't issue with CURL as, following equivalent in node.js works without issues even for POST requests with body:

const express = require('express')
const app = express()

app.all('/', (req, res) => {
  req.connection.on('close', function (){
    console.log('done');
  });
  setTimeout(function () {
    res.send('Hello World!')
  }, 10000);
})

app.listen(3000, () => console.log('Example app listening on port 3000!'))

[sheerun]

Another note, when I use req.Body.Close() it behaves properly:

package main

import (
	"fmt"
	"net/http"
	"time"
)

func Handler(w http.ResponseWriter, req *http.Request) {
	req.Body.Close()

	go func() {
		<-req.Context().Done()
		fmt.Println("done")
	}()

	time.Sleep(10 * time.Second)
}

func main() {
	http.ListenAndServe(":8080", http.HandlerFunc(Handler))
}

But in my use case I don't want to close the body and still handle request cancellations (specifically: I want to stream request body after unknown time, but allow to cancel request from client side, a form of file p2p file transfering).

[sheerun]

Also, it seems because of this issue WriteTimeout setting of http.Server has no effect for POST/PUT queries with body (unless manually closing body, what misses the point of this flag).

[sheerun]

@bradfitz @tombergan I'm struggling to find workaround, any help?

[bradfitz]

The HTTP request context only expires once the Request.Body has been fully consumed.

Maybe we just need to document this.

If we could get TCP details out of the operating system portably and see when a connection got a RST before actually reading our way to it, that'd be nice, but I don't think /proc/net/tcp on Linux even contains that bit. Or maybe it's in "connection state". @tombergan, do you know?

[sheerun]

I strongly believe it is not something to document but to fix or at least provide alternative for.
This behaviour makes it impossible to implement http streaming with client-side cancelling in go.

[sheerun]

Plus it's certainly possible because as mentioned express in node.js has it

[bradfitz]

Okay, how? How does NodeJs do it?

[sheerun]

My quick research:

It starts here: https://github.com/nodejs/node/blob/48813dee2794e2f6993b72655a8dbd3011a908ab/lib/net.js#L552-L555
Which leads to: https://github.com/nodejs/node/blob/master/src/tcp_wrap.cc#L90
Which leads to: https://github.com/nodejs/node/blob/0a842633861cf20527ce93e6bf58b4ece1b168be/src/handle_wrap.cc#L63-L84

And that leads to:

Windows implementation: https://github.com/libuv/libuv/blob/2b32e77bb6f41e2786168ec0f32d1f0fcc78071b/src/win/tcp.c#L1376-L1447

Unix implementation:
https://github.com/libuv/libuv/blob/2b32e77bb6f41e2786168ec0f32d1f0fcc78071b/src/unix/stream.c#L1637-L1688

[bradfitz]

None of that code looks relevant to this issue.

Instead, show me a Node JS program that accepts a POST request, doesn't read its body, and gets notified when the connection goes away.

[sheerun]

I've already posted it: #23262 (comment)

[bradfitz]

@sheerun, can you share a gist of the strace output of that node program running with a POST request with body being canceled?

Is express implicitly reading the request body for you? That's my guess.

Try it with larger bodies.

[sheerun]

This is more comprehensive example that shows that streaming and closing really occurs (because I'm generating request on the fly with counters, it's impossible for node's http to read whole request:

server:

var http = require('http')

var server = http.createServer((req, res) => {
  req.on('close', () => {
    console.log('close')
  });

  req.pipe(res);
});

server.listen(3000);

client:

var http = require('http');

const options = {
  hostname: 'localhost',
  port: 3000,
  method: 'POST'
};

const req = http.request(options, (res) => {
  res.on('data', (chunk) => {
    console.log(`DATA: ${chunk}`);
  });
});

var i = 0
setInterval(function () {
  req.write('Hello ' + i++);
}, 1000);

// We don't want to close request to simulate streaming
// req.end();

Here's the demo: https://asciinema.org/a/0YAqKgNLWlWlT5YUDyvLZFXlS

And here's strace for two messages and cancel: https://pastebin.com/XTQEBxb2

[bradfitz]

Yeah, Node or Express is reading your request body:

epoll_wait(5, [{EPOLLIN, {u32=12, u64=12}}], 1024, 118799) = 1
read(12, "7\r\nHello 1\r\n", 65536)     = 12
writev(12, [{"7", 1}, {"\r\n", 2}, {"Hello 1", 7}, {"\r\n", 2}], 4) = 12
epoll_ctl(5, EPOLL_CTL_MOD, 12, {EPOLLIN, {u32=12, u64=12}}) = 0
epoll_wait(5, [{EPOLLIN, {u32=12, u64=12}}], 1024, 117999) = 1
read(12, "", 65536)                     = 0

That's how it knows that RST or EOF occurred, because it read to there and got it.

Go doesn't read the Request.Body by default. Your Handler has to do that. Only once your Handler has reached the framed EOF (framed by Content-Length or chunking), then Go's server takes over and does the long background read waiting for the next request or the connection to die.

We don't do the automatic read by default, because that'd waste bandwidth (not applying any backpressure by filling up TCP buffers) if the request body is unwanted.

If you want to do the same behavior as node/express, do a io.Copy(ioutil.Discard, req.Body) in your handler.

[sheerun]

Thanks for your response. I managed to replicate Node.js behaviour in go with following:

func Handler(w http.ResponseWriter, req *http.Request) {
	go func() {
		<-req.Context().Done()
		fmt.Println("done")
	}()

	w.WriteHeader(200)
	buf := make([]byte, 1024)
	for {
		n, err := req.Body.Read(buf)
		if err != nil {
			fmt.Errorf(err.Error())
			return
		}
		w.Write(buf)
		w.(http.Flusher).Flush()
	}
}

Which unfortunately doesn't solve my use case, sorry for suggesting Node has solved this issue.

Even though Request.Body doesn't need to be fully consumed we still need to consume at least the part that already arrived in operating system to know whether client has dropped the connection.

So when client streams 2GB file and there's already 1MB of this file buffered on the receiving operating system, we need to read this 1MB to know whether client still needs this transfer (i.e. didn't drop it). If the transfer client did not drop connection, I need to store this 1MB in memory, and repeat...

On my OSX this buffer size on receiving side seems to be for some around 0.5MB, no matter how big streamed request is on writer side, it means if I want to check connection state every 10 seconds, I need to use 0.5mb of memory or disk very 10 seconds, effectively reading body of request anyway.

I'm no longer convinced this is fixable, but it would be nice if it was. I'll do further research and post if find something interesting, but for sure someone else is more experienced to answer this.

[sheerun]

I've encountered this stack overflow which suggest that the solution might be using MSG_PEEK to peek into the connection and asking for more than system's buffer (e.g. 1mb). This effectively will maintain the buffer full at operating system side, and inform whether client has dropped the connection.

I'm not saying go-lang should do it by default as peeking 0.5mb every few seconds is resource consuming, but some application could use this feature. Is there anything in go-lang's http package that sets MSG_PEEK when reading tcp connection?

[sheerun]

From my side I deem this issue unresolvable. I tried using MSG_PEEK, but the output doesn't change when the connection is dropped. I could probably do some hacks, like reading part of the buffer and checking with MSG_PEEK if buffer is re-filling, but it's probably not worth it.

Most likely this feature requires client co-operation with Expect: 100-continue header.

Here's the code I used for testing MSG_PEEK:

package main

import (
	"fmt"
	"log"
	"net"
	"syscall"
	"time"
)

func main() {
	l, err := net.Listen("tcp", ":3000")
	if err != nil {
		log.Panicln(err)
	}
	log.Println("Listening to connections")
	defer l.Close()

	for {
		conn, err := l.Accept()
		if err != nil {
			log.Panicln(err)
		}

		go handleRequest(conn)
	}
}

func IsClosed(conn net.Conn) bool {
	tcpConn := conn.(*net.TCPConn)
	file, err := tcpConn.File()
	if err != nil {
		return true
	}

	x := make([]byte, 1000000)
	y := make([]byte, 0)
	a, b, c, d, e := syscall.Recvmsg(int(file.Fd()), x, y, syscall.MSG_PEEK|syscall.MSG_DONTWAIT)
	fmt.Printf("%v %v %v %v %v\n", a, b, c, d, e)
	fmt.Println(len(x))

	return false
}

func handleRequest(conn net.Conn) {
	log.Println("Accepted new connection.")
	defer conn.Close()
	defer log.Println("Closed connection.")

	go func() {
		for {
			if IsClosed(conn) {
				fmt.Println("closed")
				return
			}
			time.Sleep(1 * time.Second)
		}
	}()

	for {
		// buf := make([]byte, 1)
		// size, err := conn.Read(buf)
		// if err != nil {
		// 	return
		// }
		// data := buf[:size]
		// fmt.Println(string(data))
		time.Sleep(1 * time.Second)
	}
}

[dedo1911]

@sheerun The following code is deprecated but still works for me, give it a shot:

notify := w.(http.CloseNotifier).CloseNotify()
go func() {
    <-notify
    // connection close, do cleanup, etc.
}()

The replacement for this deprecation should be to use Request.Context as your example does,
but is not giving the same expected result because of this issue.

I'm still using CloseNotifier in my code as it's the only way I found to detect client closed connection.

[bokunodev]

sorry I interrupting the conversation.
I just wanted to say, there's a reason it's called CloseNotifier
You don't have to consume Request.Body but you have to Close() it.
its true, for POST or GET request. with or without body.
Request.Body.Close() will block, until the client go away.
when the client is go away AND Request.Body is Close()-ed, the Done() signal is sent.

defer func(){
    _ = r.Body.Close()
    wg.Wait()
}()

I agree that the documentation should be updated.

[AlexanderYastrebov]

The HTTP request context only expires once the Request.Body has been fully consumed.

reading Request.Body partially didn't work for me.

See also details #37145 (comment)

[andodeki]

@dedo1911 does this delay the request body reading a bit, so that if the client has already gone away then i doesn't bother to read the request body anymore ??
Thanks