Skip to content

Commit abbb61e

Browse files
fix/conn: prevent re-entrant logger deadlock
Protocol errors invoke the configured logger while the connection is shutting down. Calling user code under the connection mutex meant a logger that sends over the same connection could never observe closure and instead deadlocked. Complete teardown before logging so re-entrant calls return ErrClosed. Amp-Thread-ID: https://ampcode.com/threads/T-019fb774-aef7-75df-8eb3-8888d6835754 Co-authored-by: Amp <amp@ampcode.com>
1 parent 2807055 commit abbb61e

2 files changed

Lines changed: 43 additions & 6 deletions

File tree

conn.go

Lines changed: 11 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -180,24 +180,29 @@ func (c *Conn) SendResponse(ctx context.Context, resp *Response) error {
180180

181181
func (c *Conn) close(cause error) error {
182182
c.mu.Lock()
183-
defer c.mu.Unlock()
184-
185183
if c.closed {
184+
c.mu.Unlock()
186185
return ErrClosed
187186
}
187+
c.closed = true
188188

189189
for _, call := range c.pending {
190190
close(call.done)
191191
}
192192

193+
close(c.disconnect)
194+
c.mu.Unlock()
195+
196+
c.cancelCtx()
197+
err := c.stream.Close()
198+
199+
// The logger may call back into c, so invoke it only after shutdown is
200+
// complete and c.mu is unlocked.
193201
if cause != nil && cause != io.EOF && cause != io.ErrUnexpectedEOF {
194202
c.logger.Printf("jsonrpc2: protocol error: %v\n", cause)
195203
}
196204

197-
close(c.disconnect)
198-
c.cancelCtx()
199-
c.closed = true
200-
return c.stream.Close()
205+
return err
201206
}
202207

203208
func (c *Conn) readMessages(ctx context.Context) {

conn_test.go

Lines changed: 32 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -167,6 +167,38 @@ func TestConn_DisconnectNotify(t *testing.T) {
167167
connA.Write([]byte("invalid json"))
168168
assertDisconnect(t, c, connB)
169169
})
170+
171+
t.Run("protocol error logger uses connection", func(t *testing.T) {
172+
connA, connB := net.Pipe()
173+
logResult := make(chan error, 1)
174+
var c *jsonrpc2.Conn
175+
c = jsonrpc2.NewConn(
176+
context.Background(),
177+
jsonrpc2.NewPlainObjectStream(connB),
178+
noopHandler{},
179+
jsonrpc2.SetLogger(connNotifyLogger{conn: &c, result: logResult}),
180+
)
181+
connA.Write([]byte("invalid json"))
182+
assertDisconnect(t, c, connB)
183+
184+
select {
185+
case err := <-logResult:
186+
if err != jsonrpc2.ErrClosed {
187+
t.Errorf("logger Notify: got %v, want %v", err, jsonrpc2.ErrClosed)
188+
}
189+
case <-time.After(200 * time.Millisecond):
190+
t.Error("logger blocked using connection")
191+
}
192+
})
193+
}
194+
195+
type connNotifyLogger struct {
196+
conn **jsonrpc2.Conn
197+
result chan<- error
198+
}
199+
200+
func (l connNotifyLogger) Printf(string, ...interface{}) {
201+
l.result <- (*l.conn).Notify(context.Background(), "log", nil)
170202
}
171203

172204
func TestConn_Close(t *testing.T) {

0 commit comments

Comments
 (0)