gopls/internal/jsonrpc2_v2/serve

1	// Copyright 2020 The Go Authors. All rights reserved.
2	// Use of this source code is governed by a BSD-style
3	// license that can be found in the LICENSE file.
4
5	package jsonrpc2_test
6
7	import (
8	"context"
9	"errors"
10	"fmt"
11	"runtime/debug"
12	"testing"
13	"time"
14
15	jsonrpc2 "golang.org/x/tools/internal/jsonrpc2_v2"
16	"golang.org/x/tools/internal/stack/stacktest"
17	)
18
19	func TestIdleTimeout(t *testing.T) {
20	stacktest.NoLeak(t)
21
22	// Use a panicking time.AfterFunc instead of context.WithTimeout so that we
23	// get a goroutine dump on failure. We expect the test to take on the order of
24	// a few tens of milliseconds at most, so 10s should be several orders of
25	// magnitude of headroom.
26	timer := time.AfterFunc(10*time.Second, func() {
27	debug.SetTraceback("all")
28	panic("TestIdleTimeout deadlocked")
29	})
30	defer timer.Stop()
31
32	ctx := context.Background()
33
34	try := func(d time.Duration) (longEnough bool) {
35	listener, err := jsonrpc2.NetListener(ctx, "tcp", "localhost:0", jsonrpc2.NetListenOptions{})
36	if err != nil {
37	t.Fatal(err)
38	}
39
40	idleStart := time.Now()
41	listener = jsonrpc2.NewIdleListener(d, listener)
42	defer listener.Close()
43
44	server := jsonrpc2.NewServer(ctx, listener, jsonrpc2.ConnectionOptions{})
45
46	// Exercise some connection/disconnection patterns, and then assert that when
47	// our timer fires, the server exits.
48	conn1, err := jsonrpc2.Dial(ctx, listener.Dialer(), jsonrpc2.ConnectionOptions{})
49	if err != nil {
50	if since := time.Since(idleStart); since < d {
51	t.Fatalf("conn1 failed to connect after %v: %v", since, err)
52	}
53	t.Log("jsonrpc2.Dial:", err)
54	return false // Took to long to dial, so the failure could have been due to the idle timeout.
55	}
56	// On the server side, Accept can race with the connection timing out.
57	// Send a call and wait for the response to ensure that the connection was
58	// actually fully accepted.
59	ac := conn1.Call(ctx, "ping", nil)
60	if err := ac.Await(ctx, nil); !errors.Is(err, jsonrpc2.ErrMethodNotFound) {
61	if since := time.Since(idleStart); since < d {
62	t.Fatalf("conn1 broken after %v: %v", since, err)
63	}
64	t.Log(`conn1.Call(ctx, "ping", nil):`, err)
65	conn1.Close()
66	return false
67	}
68
69	// Since conn1 was successfully accepted and remains open, the server is
70	// definitely non-idle. Dialing another simultaneous connection should
71	// succeed.
72	conn2, err := jsonrpc2.Dial(ctx, listener.Dialer(), jsonrpc2.ConnectionOptions{})
73	if err != nil {
74	conn1.Close()
75	t.Fatalf("conn2 failed to connect while non-idle after %v: %v", time.Since(idleStart), err)
76	return false
77	}
78	// Ensure that conn2 is also accepted on the server side before we close
79	// conn1. Otherwise, the connection can appear idle if the server processes
80	// the closure of conn1 and the idle timeout before it finally notices conn2
81	// in the accept queue.
82	// (That failure mode may explain the failure noted in
83	// https://go.dev/issue/49387#issuecomment-1303979877.)
84	ac = conn2.Call(ctx, "ping", nil)
85	if err := ac.Await(ctx, nil); !errors.Is(err, jsonrpc2.ErrMethodNotFound) {
86	t.Fatalf("conn2 broken while non-idle after %v: %v", time.Since(idleStart), err)
87	}
88
89	if err := conn1.Close(); err != nil {
90	t.Fatalf("conn1.Close failed with error: %v", err)
91	}
92	idleStart = time.Now()
93	if err := conn2.Close(); err != nil {
94	t.Fatalf("conn2.Close failed with error: %v", err)
95	}
96
97	conn3, err := jsonrpc2.Dial(ctx, listener.Dialer(), jsonrpc2.ConnectionOptions{})
98	if err != nil {
99	if since := time.Since(idleStart); since < d {
100	t.Fatalf("conn3 failed to connect after %v: %v", since, err)
101	}
102	t.Log("jsonrpc2.Dial:", err)
103	return false // Took to long to dial, so the failure could have been due to the idle timeout.
104	}
105
106	ac = conn3.Call(ctx, "ping", nil)
107	if err := ac.Await(ctx, nil); !errors.Is(err, jsonrpc2.ErrMethodNotFound) {
108	if since := time.Since(idleStart); since < d {
109	t.Fatalf("conn3 broken after %v: %v", since, err)
110	}
111	t.Log(`conn3.Call(ctx, "ping", nil):`, err)
112	conn3.Close()
113	return false
114	}
115
116	idleStart = time.Now()
117	if err := conn3.Close(); err != nil {
118	t.Fatalf("conn3.Close failed with error: %v", err)
119	}
120
121	serverError := server.Wait()
122
123	if !errors.Is(serverError, jsonrpc2.ErrIdleTimeout) {
124	t.Errorf("run() returned error %v, want %v", serverError, jsonrpc2.ErrIdleTimeout)
125	}
126	if since := time.Since(idleStart); since < d {
127	t.Errorf("server shut down after %v idle; want at least %v", since, d)
128	}
129	return true
130	}
131
132	d := 1 * time.Millisecond
133	for {
134	t.Logf("testing with idle timout %v", d)
135	if !try(d) {
136	d *= 2
137	continue
138	}
139	break
140	}
141	}
142
143	type msg struct {
144	Msg string
145	}
146
147	type fakeHandler struct{}
148
149	func (fakeHandler) Handle(ctx context.Context, req *jsonrpc2.Request) (interface{}, error) {
150	switch req.Method {
151	case "ping":
152	return &msg{"pong"}, nil
153	default:
154	return nil, jsonrpc2.ErrNotHandled
155	}
156	}
157
158	func TestServe(t *testing.T) {
159	stacktest.NoLeak(t)
160	ctx := context.Background()
161
162	tests := []struct {
163	name string
164	factory func(context.Context) (jsonrpc2.Listener, error)
165	}{
166	{"tcp", func(ctx context.Context) (jsonrpc2.Listener, error) {
167	return jsonrpc2.NetListener(ctx, "tcp", "localhost:0", jsonrpc2.NetListenOptions{})
168	}},
169	{"pipe", func(ctx context.Context) (jsonrpc2.Listener, error) {
170	return jsonrpc2.NetPipeListener(ctx)
171	}},
172	}
173
174	for _, test := range tests {
175	t.Run(test.name, func(t *testing.T) {
176	fake, err := test.factory(ctx)
177	if err != nil {
178	t.Fatal(err)
179	}
180	conn, shutdown, err := newFake(t, ctx, fake)
181	if err != nil {
182	t.Fatal(err)
183	}
184	defer shutdown()
185	var got msg
186	if err := conn.Call(ctx, "ping", &msg{"ting"}).Await(ctx, &got); err != nil {
187	t.Fatal(err)
188	}
189	if want := "pong"; got.Msg != want {
190	t.Errorf("conn.Call(...): returned %q, want %q", got, want)
191	}
192	})
193	}
194	}
195
196	func newFake(t testing.T, ctx context.Context, l jsonrpc2.Listener) (jsonrpc2.Connection, func(), error) {
197	server := jsonrpc2.NewServer(ctx, l, jsonrpc2.ConnectionOptions{
198	Handler: fakeHandler{},
199	})
200
201	client, err := jsonrpc2.Dial(ctx,
202	l.Dialer(),
203	jsonrpc2.ConnectionOptions{
204	Handler: fakeHandler{},
205	})
206	if err != nil {
207	return nil, nil, err
208	}
209	return client, func() {
210	if err := l.Close(); err != nil {
211	t.Fatal(err)
212	}
213	if err := client.Close(); err != nil {
214	t.Fatal(err)
215	}
216	server.Wait()
217	}, nil
218	}
219
220	// TestIdleListenerAcceptCloseRace checks for the Accept/Close race fixed in CL 388597.
221	//
222	// (A bug in the idleListener implementation caused a successful Accept to block
223	// on sending to a background goroutine that could have already exited.)
224	func TestIdleListenerAcceptCloseRace(t *testing.T) {
225	ctx := context.Background()
226
227	n := 10
228
229	// Each iteration of the loop appears to take around a millisecond, so to
230	// avoid spurious failures we'll set the watchdog for three orders of
231	// magnitude longer. When the bug was present, this reproduced the deadlock
232	// reliably on a Linux workstation when run with -count=100, which should be
233	// frequent enough to show up on the Go build dashboard if it regresses.
234	watchdog := time.Duration(n) * 1000 * time.Millisecond
235	timer := time.AfterFunc(watchdog, func() {
236	debug.SetTraceback("all")
237	panic(fmt.Sprintf("%s deadlocked after %v", t.Name(), watchdog))
238	})
239	defer timer.Stop()
240
241	for ; n > 0; n-- {
242	listener, err := jsonrpc2.NetPipeListener(ctx)
243	if err != nil {
244	t.Fatal(err)
245	}
246	listener = jsonrpc2.NewIdleListener(24*time.Hour, listener)
247
248	done := make(chan struct{})
249	go func() {
250	conn, err := jsonrpc2.Dial(ctx, listener.Dialer(), jsonrpc2.ConnectionOptions{})
251	listener.Close()
252	if err == nil {
253	conn.Close()
254	}
255	close(done)
256	}()
257
258	// Accept may return a non-nil error if Close closes the underlying network
259	// connection before the wrapped Accept call unblocks. However, it must not
260	// deadlock!
261	c, err := listener.Accept(ctx)
262	if err == nil {
263	c.Close()
264	}
265	<-done
266	}
267	}
268
269	// TestCloseCallRace checks for a race resulting in a deadlock when a Call on
270	// one side of the connection races with a Close (or otherwise broken
271	// connection) initiated from the other side.
272	//
273	// (The Call method was waiting for a result from the Read goroutine to
274	// determine which error value to return, but the Read goroutine was waiting for
275	// in-flight calls to complete before reporting that result.)
276	func TestCloseCallRace(t *testing.T) {
277	ctx := context.Background()
278	n := 10
279
280	watchdog := time.Duration(n) * 1000 * time.Millisecond
281	timer := time.AfterFunc(watchdog, func() {
282	debug.SetTraceback("all")
283	panic(fmt.Sprintf("%s deadlocked after %v", t.Name(), watchdog))
284	})
285	defer timer.Stop()
286
287	for ; n > 0; n-- {
288	listener, err := jsonrpc2.NetPipeListener(ctx)
289	if err != nil {
290	t.Fatal(err)
291	}
292
293	pokec := make(chan *jsonrpc2.AsyncCall, 1)
294
295	s := jsonrpc2.NewServer(ctx, listener, jsonrpc2.BinderFunc(func(_ context.Context, srvConn *jsonrpc2.Connection) jsonrpc2.ConnectionOptions {
296	h := jsonrpc2.HandlerFunc(func(ctx context.Context, _ *jsonrpc2.Request) (interface{}, error) {
297	// Start a concurrent call from the server to the client.
298	// The point of this test is to ensure this doesn't deadlock
299	// if the client shuts down the connection concurrently.
300	//
301	// The racing Call may or may not receive a response: it should get a
302	// response if it is sent before the client closes the connection, and
303	// it should fail with some kind of "connection closed" error otherwise.
304	go func() {
305	pokec <- srvConn.Call(ctx, "poke", nil)
306	}()
307
308	return &msg{"pong"}, nil
309	})
310	return jsonrpc2.ConnectionOptions{Handler: h}
311	}))
312
313	dialConn, err := jsonrpc2.Dial(ctx, listener.Dialer(), jsonrpc2.ConnectionOptions{})
314	if err != nil {
315	listener.Close()
316	s.Wait()
317	t.Fatal(err)
318	}
319
320	// Calling any method on the server should provoke it to asynchronously call
321	// us back. While it is starting that call, we will close the connection.
322	if err := dialConn.Call(ctx, "ping", nil).Await(ctx, nil); err != nil {
323	t.Error(err)
324	}
325	if err := dialConn.Close(); err != nil {
326	t.Error(err)
327	}
328
329	// Ensure that the Call on the server side did not block forever when the
330	// connection closed.
331	pokeCall := <-pokec
332	if err := pokeCall.Await(ctx, nil); err == nil {
333	t.Errorf("unexpected nil error from server-initited call")
334	} else if errors.Is(err, jsonrpc2.ErrMethodNotFound) {
335	// The call completed before the Close reached the handler.
336	} else {
337	// The error was something else.
338	t.Logf("server-initiated call completed with expected error: %v", err)
339	}
340
341	listener.Close()
342	s.Wait()
343	}
344	}
345