Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

net/http: check that http2 logs no more than http1 #13925

Closed
karmeye opened this issue Jan 12, 2016 · 7 comments
Closed

net/http: check that http2 logs no more than http1 #13925

karmeye opened this issue Jan 12, 2016 · 7 comments
Milestone

Comments

@karmeye
Copy link

karmeye commented Jan 12, 2016

Why are these logged by default?

...
2016/01/12 18:47:58 http2: server closing client connection; error reading frame from client 54.213.93.184:35476: read tcp 172.31.25.225:8000->54.213.93.184:35476: i/o timeout
2016/01/12 18:47:58 http2: server closing client connection; error reading frame from client 54.213.93.184:35477: read tcp 172.31.25.225:8000->54.213.93.184:35477: i/o timeout
2016/01/12 18:47:58 http2: server closing client connection; error reading frame from client 54.213.93.184:35478: read tcp 172.31.25.225:8000->54.213.93.184:35478: i/o timeout
2016/01/12 18:47:58 http2: server closing client connection; error reading frame from client 54.213.93.184:35480: read tcp 172.31.25.225:8000->54.213.93.184:35480: i/o timeout
2016/01/12 18:47:58 http2: server closing client connection; error reading frame from client 54.213.93.184:35481: read tcp 172.31.25.225:8000->54.213.93.184:35481: i/o timeout
...

If I understand it correctly, it's not an error; it's just that the client wants to keep a connection open for a longer time than the server (the ReadDeadline times out).

@bradfitz
Copy link
Contributor

How are you starting your http server? Do you have explicit configuration, or the default?

@karmeye
Copy link
Author

karmeye commented Jan 12, 2016

Explicit. I am setting the timeouts.

func NewServer(addr string, handler http.Handler) *Server {
    s := &Server{
        Server: http.Server{
            Addr: addr,
            Handler: &serverHandler{
                Handler: handler,
            },
            MaxHeaderBytes: 4096,

            // Maximum duration before timing out read of the request
            ReadTimeout: 3 * 60 * time.Second, //60e9,

            // Maximum duration before timing out write of the response
            WriteTimeout: 3 * 60 * time.Second, //60e9,
        },
    }
    s.ConnState = func(conn net.Conn, state http.ConnState) {
        switch state {

        // StateNew represents a new connection that is expected to
        // send a request immediately. Connections begin at this
        // state and then transition to either StateActive or
        // StateClosed
        case http.StateNew:

            // StateActive represents a connection that has read 1 or more
            // bytes of a request. The Server.ConnState hook for
            // StateActive fires before the request has entered a handler
            // and doesn't fire again until the request has been
            // handled. After the request is handled, the state
            // transitions to StateClosed, StateHijacked, or StateIdle.
        case http.StateActive:

            conn.SetReadDeadline(time.Now().Add(s.ReadTimeout))
            conn.SetWriteDeadline(time.Now().Add(s.WriteTimeout))

            // StateIdle represents a connection that has finished
            // handling a request and is in the keep-alive state, waiting
            // for a new request. Connections transition from StateIdle
            // to either StateActive or StateClosed.
        case http.StateIdle:

            // StateHijacked represents a hijacked connection.
            // This is a terminal state. It does not transition to StateClosed.
            // 
            // StateClosed represents a closed connection.
            // This is a terminal state. Hijacked connections do not
            // transition to StateClosed.
        case http.StateHijacked, http.StateClosed:

        }
    }
    return s
}

@bradfitz
Copy link
Contributor

I've clarified the docs for ConnState StateActive in https://go-review.googlesource.com/18575:

        // For HTTP/2, StateActive fires on the transition from zero
        // to one active request, and only transitions away once all
        // active requests are complete. That means that ConnState
        // can not be used to do per-request work; ConnState only notes
        // the overall state of the connection.
        StateActive

ConnState is mostly used for graceful shutdowns of servers. If you want to adjust read and write deadlines per-request, you'll also need to install a http.Handler wrapper which does that (cooperating with the ConnState hook to map between the net.Conn and the http.Request.RemoteAddr)

@gopherbot
Copy link

CL https://golang.org/cl/18575 mentions this issue.

gopherbot pushed a commit that referenced this issue Jan 13, 2016
Update #13925

Change-Id: I7cd0625fad841eb0e3f364629f9bc225aa2fdce9
Reviewed-on: https://go-review.googlesource.com/18575
Reviewed-by: Andrew Gerrand <adg@golang.org>
@bradfitz bradfitz added this to the Go1.6 milestone Jan 21, 2016
@bradfitz bradfitz self-assigned this Jan 21, 2016
@bradfitz
Copy link
Contributor

I'll audit the http2 logging paths and make sure they're not any more verbose than http1 for Go 1.6.

@rsc rsc changed the title net/http: log "http2: server closing client connection" net/http: check that http2 logs no more than http1 Jan 26, 2016
@gopherbot
Copy link

CL https://golang.org/cl/18932 mentions this issue.

gopherbot pushed a commit to golang/net that referenced this issue Jan 26, 2016
Recognize connection aborted errors on Windows and don't log them by
default, like the Unix case.

Log frame reading errors only at verbose level, to match
net/http.Server.

Updates golang/go#13925
Updates golang/go#14061

Change-Id: I87998a924b11d4dad5512e010b29d2da6b4bf867
Reviewed-on: https://go-review.googlesource.com/18932
Reviewed-by: Ian Lance Taylor <iant@golang.org>
@gopherbot
Copy link

CL https://golang.org/cl/18934 mentions this issue.

@golang golang locked and limited conversation to collaborators Feb 3, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

3 participants