serve_test.go

Documentation: golang.org/x/tools/internal/jsonrpc2_v2

     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  }
   348
View as plain text