go: net/http: do not log error in http.Server for TCP probes

What version of Go are you using ?

1.10.x

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using?

N/A

What did you do?

Kubernetes apiserver is based on http.Server with a TLS config. If you put a Loadbalancer in front of it which implements basic TCP probing for the load balancing you end up being flooded by the following message:

I0810 08:34:34.483565 1 logs.go:49] http: TLS handshake error from 168.63.129.16:64551: EOF

Which originates from:

https://github.com/golang/go/blob/d3c3aaa61f7598f275f30fabd3749379fe0f2720/src/net/http/server.go#L1762-L1765

What did you expect to see?

I was hoping we could avoid logging an error for opened and closed tcp sockets.

About this issue

  • Original URL
  • State: closed
  • Created 6 years ago
  • Reactions: 12
  • Comments: 18 (8 by maintainers)

Commits related to this issue

Most upvoted comments

@kayrus I hope you are joking about effectiveness 😃

As per https://pkg.go.dev/log#Logger

Each logging operation makes a single call to the Writer’s Write method

the solution could look like:

type serverErrorLogWriter struct{}

func (*serverErrorLogWriter) Write(p []byte) (int, error) {
	m := string(p)
	// https://github.com/golang/go/issues/26918
	if strings.HasPrefix(m, "http: TLS handshake error") && strings.HasSuffix(m, ": EOF\n") {
		// handle EOF error
	} else {
		// handle other errors
	}
	return len(p), nil
}

func newServerErrorLog() *log.Logger {
	return log.New(&serverErrorLogWriter{}, "", 0)
}

I’m definitely not excited about running a regexp on every single log line.

I wouldn’t be either. Fortunately nobody mentioned a regexp here. 😃

I haven’t done a survey, but I think open/close a TCP port is not an unheard of way to monitor something.

IMO, a better way to monitor an HTTP server is to send an HTTP request.

Back in the day, the HTTP load balancer I wrote for LiveJournal got its most notable improvements when we started making load balancing decisions based on which backend could reply to an quick dummy OPTIONS * HTTP/1.1 HTTP request rather than just accept TCP. Because we wanted to see that we were talking to the real server in userspace and not just the kernel’s TCP accept backlog.

Ever since then when I want to see if an HTTP server is up I don’t trust that just its TCP port is replying. Who knows what that’ll be. Maybe that’s just systemd or something else listening for you and handing your (possibly failing to start) program a file descriptor.

In fact, Go’s HTTP server handles OPTIONS * requests by default:

// serverHandler delegates to either the server's Handler or                                                                            
// DefaultServeMux and also handles "OPTIONS *" requests.                                                                               
type serverHandler struct {
        srv *Server
}       
        
func (sh serverHandler) ServeHTTP(rw ResponseWriter, req *Request) {
        handler := sh.srv.Handler
        if handler == nil {
                handler = DefaultServeMux
        }
        if req.RequestURI == "*" && req.Method == "OPTIONS" {
                handler = globalOptionsHandler{}
        }
        handler.ServeHTTP(rw, req)
}       
$ telnet http2.golang.org 80
Trying 130.211.116.44...
Connected to http2.golang.org.
Escape character is '^]'.
OPTIONS * HTTP/1.1
Host: http2.golang.org
        
HTTP/1.1 200 OK
Content-Length: 0
Date: Tue, 21 Aug 2018 19:42:03 GMT
Content-Type: text/plain; charset=utf-8

^]
telnet> q

Or, if you want the server to close the connection for you and not have to require a Hostname, use HTTP/1.0 (with its implicit Connection: close):

$ telnet http2.golang.org 80
Trying 130.211.116.44...
Connected to http2.golang.org.
Escape character is '^]'.
OPTIONS * HTTP/1.0

HTTP/1.0 200 OK
Content-Length: 0
Date: Tue, 21 Aug 2018 19:47:46 GMT
Content-Type: text/plain; charset=utf-8

Connection closed by foreign host.

I can imagine setting up an optional channel for the http server to send non-fatal errors down instead of logging, that’s a lot of machinery but should satisfy all the use cases.

We’d use a func rather than a channel, but I really don’t want to add new API if we can help it.

And we already have a place we send non-fatal errors: the logger. Because we never call log.Fatal.

Or what sort of current error today do you consider fatal?