Skip to content

Commit 08fda79

Browse files
felixgefelixge
committed
fix: handler panics were not handled correctly
The net/http pkg automatically recovers from panics inside of handlers, and CaptureMetrics was unfortunately breaking this functionality by executing hnd in a new goroutine. This patch fixes the problem by using locks instead of channels. Rant: IMHO the automatic recover functionality of net/http is an absolute misfeature. It's basically "ON ERROR RESUME NEXT" from Visual Basic, except worse, because it's implicitly enforced upon you. The documentation excuses this behavior with the following comment: > If ServeHTTP panics, the server (the caller of ServeHTTP) assumes that > the effect of the panic was isolated to the active request. However, IMO that's an entirely unreasonable assumption. Most http handlers will have shared state, e.g. a *database/sql.DB. Anyway ... I'm afraid that ship has long sailed. Fixes felixge#2
1 parent a3dccdc commit 08fda79

2 files changed

Lines changed: 53 additions & 64 deletions

File tree

‎capture_metrics.go‎

Lines changed: 18 additions & 59 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ package httpsnoop
33
import (
44
"io"
55
"net/http"
6+
"sync"
67
"time"
78
)
89

@@ -25,91 +26,49 @@ type Metrics struct {
2526
// CaptureMetrics wraps the given hnd, executes it with the given w and r, and
2627
// returns the metrics it captured from it.
2728
func CaptureMetrics(hnd http.Handler, w http.ResponseWriter, r *http.Request) Metrics {
28-
// We use the updates channel and for loop below as an event loop that
29-
// guarantees non-overlapping execution of the closures sent through the
30-
// channel. This allows safe access to the m struct, even if hooks are being
31-
// called concurrently. The same could also be accomplished by a mutex, but
32-
// I've been waiting for an opportunity to try out the ideas from a few talks
33-
// on the topic [1][2] :).
34-
//
35-
// [1] https://www.youtube.com/watch?v=5buaPyJ0XeQ
36-
// [2] https://www.youtube.com/watch?v=yCbon_9yGVs
37-
3829
var (
3930
start = time.Now()
4031
m = Metrics{Code: http.StatusOK}
4132
headerWritten bool
42-
updates = make(chan func())
43-
done = make(chan struct{})
33+
lock sync.Mutex
4434
hooks = Hooks{
4535
WriteHeader: func(next WriteHeaderFunc) WriteHeaderFunc {
4636
return func(code int) {
47-
// Note: it's important to call next() here and not in the update
48-
// func below, otherwise hooked calls might end up being executed out
49-
// of order. This goes for all hooks.
5037
next(code)
51-
// We need to do this select in every hook, otherwise we would block
52-
// callers from go routines that exceed the call duration of the
53-
// hnd.ServeHTTP call below. One may argue that this would be
54-
// justifiable punishment for those misbehaved callers, but I'm
55-
// feeling charitable today ;).
56-
select {
57-
case updates <- func() {
58-
if !headerWritten {
59-
m.Code = code
60-
headerWritten = true
61-
}
62-
}:
63-
case <-done:
38+
lock.Lock()
39+
defer lock.Unlock()
40+
if !headerWritten {
41+
m.Code = code
42+
headerWritten = true
6443
}
6544
}
6645
},
6746

6847
Write: func(next WriteFunc) WriteFunc {
6948
return func(p []byte) (int, error) {
7049
n, err := next(p)
71-
select {
72-
case updates <- func() {
73-
m.Written += int64(n)
74-
headerWritten = true
75-
}:
76-
case <-done:
77-
}
50+
lock.Lock()
51+
defer lock.Unlock()
52+
m.Written += int64(n)
53+
headerWritten = true
7854
return n, err
7955
}
8056
},
8157

8258
ReadFrom: func(next ReadFromFunc) ReadFromFunc {
8359
return func(src io.Reader) (int64, error) {
8460
n, err := next(src)
85-
select {
86-
case updates <- func() {
87-
headerWritten = true
88-
m.Written += n
89-
}:
90-
case <-done:
91-
}
61+
lock.Lock()
62+
defer lock.Unlock()
63+
headerWritten = true
64+
m.Written += n
9265
return n, err
9366
}
9467
},
9568
}
9669
)
9770

98-
// Having to spawn an additional go routine here might be a bit unfortunate
99-
// from a performance perspective, but I'm not sure if it can be avoided.
100-
// --fg
101-
go func() {
102-
hnd.ServeHTTP(Wrap(w, hooks), r)
103-
close(done)
104-
}()
105-
106-
for {
107-
select {
108-
case update := <-updates:
109-
update()
110-
case <-done:
111-
m.Duration = time.Since(start)
112-
return m
113-
}
114-
}
71+
hnd.ServeHTTP(Wrap(w, hooks), r)
72+
m.Duration = time.Since(start)
73+
return m
11574
}

‎capture_metrics_test.go‎

Lines changed: 35 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -1,18 +1,29 @@
11
package httpsnoop
22

33
import (
4+
"io/ioutil"
5+
"log"
46
"net/http"
57
"net/http/httptest"
8+
"os"
9+
"strings"
610
"testing"
711
"time"
812
)
913

1014
func TestCaptureMetrics(t *testing.T) {
15+
// Some of the edge cases tested below cause the net/http pkg to log some
16+
// messages that add a lot of noise to the `go test -v` output, so we discard
17+
// the log here.
18+
log.SetOutput(ioutil.Discard)
19+
defer log.SetOutput(os.Stderr)
20+
1121
tests := []struct {
1222
Handler http.Handler
1323
WantDuration time.Duration
1424
WantWritten int64
1525
WantCode int
26+
WantErr string
1627
}{
1728
{
1829
Handler: http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {}),
@@ -37,9 +48,15 @@ func TestCaptureMetrics(t *testing.T) {
3748
}),
3849
WantCode: http.StatusOK,
3950
},
51+
{
52+
Handler: http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
53+
panic("oh no")
54+
}),
55+
WantErr: "EOF",
56+
},
4057
}
4158

42-
for _, test := range tests {
59+
for i, test := range tests {
4360
func() {
4461
ch := make(chan Metrics, 1)
4562
h := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
@@ -48,18 +65,31 @@ func TestCaptureMetrics(t *testing.T) {
4865
s := httptest.NewServer(h)
4966
defer s.Close()
5067
res, err := http.Get(s.URL)
68+
if !errContains(err, test.WantErr) {
69+
t.Errorf("test %d: got=%s want=%s", i, err, test.WantErr)
70+
}
5171
if err != nil {
52-
t.Fatal(err)
72+
return
5373
}
5474
defer res.Body.Close()
5575
m := <-ch
5676
if m.Code != test.WantCode {
57-
t.Errorf("got=%d want=%d", m.Code, test.WantCode)
77+
t.Errorf("test %d: got=%d want=%d", i, m.Code, test.WantCode)
5878
} else if m.Duration < test.WantDuration {
59-
t.Errorf("got=%s want=%s", m.Duration, test.WantDuration)
79+
t.Errorf("test %d: got=%s want=%s", i, m.Duration, test.WantDuration)
6080
} else if m.Written < test.WantWritten {
61-
t.Errorf("got=%d want=%d", m.Written, test.WantWritten)
81+
t.Errorf("test %d: got=%d want=%d", i, m.Written, test.WantWritten)
6282
}
6383
}()
6484
}
6585
}
86+
87+
func errContains(err error, s string) bool {
88+
var errS string
89+
if err == nil {
90+
errS = ""
91+
} else {
92+
errS = err.Error()
93+
}
94+
return strings.Contains(errS, s)
95+
}

0 commit comments

Comments
 (0)