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