gitee.com/ks-custle/core-gm@v0.0.0-20230922171213-b83bdd97b62c/grpc/test/retry_test.go (about)

     1  /*
     2   *
     3   * Copyright 2018 gRPC authors.
     4   *
     5   * Licensed under the Apache License, Version 2.0 (the "License");
     6   * you may not use this file except in compliance with the License.
     7   * You may obtain a copy of the License at
     8   *
     9   *     http://www.apache.org/licenses/LICENSE-2.0
    10   *
    11   * Unless required by applicable law or agreed to in writing, software
    12   * distributed under the License is distributed on an "AS IS" BASIS,
    13   * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    14   * See the License for the specific language governing permissions and
    15   * limitations under the License.
    16   *
    17   */
    18  
    19  package test
    20  
    21  import (
    22  	"context"
    23  	"fmt"
    24  	"io"
    25  	"net"
    26  	"reflect"
    27  	"strconv"
    28  	"strings"
    29  	"sync"
    30  	"testing"
    31  	"time"
    32  
    33  	grpc "gitee.com/ks-custle/core-gm/grpc"
    34  	"gitee.com/ks-custle/core-gm/grpc/codes"
    35  	"gitee.com/ks-custle/core-gm/grpc/internal/stubserver"
    36  	"gitee.com/ks-custle/core-gm/grpc/metadata"
    37  	"gitee.com/ks-custle/core-gm/grpc/stats"
    38  	"gitee.com/ks-custle/core-gm/grpc/status"
    39  	testpb "gitee.com/ks-custle/core-gm/grpc/test/grpc_testing"
    40  	"github.com/golang/protobuf/proto"
    41  )
    42  
    43  func (s) TestRetryUnary(t *testing.T) {
    44  	i := -1
    45  	ss := &stubserver.StubServer{
    46  		EmptyCallF: func(context.Context, *testpb.Empty) (*testpb.Empty, error) {
    47  			i++
    48  			switch i {
    49  			case 0, 2, 5:
    50  				return &testpb.Empty{}, nil
    51  			case 6, 8, 11:
    52  				return nil, status.New(codes.Internal, "non-retryable error").Err()
    53  			}
    54  			return nil, status.New(codes.AlreadyExists, "retryable error").Err()
    55  		},
    56  	}
    57  	if err := ss.Start([]grpc.ServerOption{}); err != nil {
    58  		t.Fatalf("Error starting endpoint server: %v", err)
    59  	}
    60  	defer ss.Stop()
    61  	ss.NewServiceConfig(`{
    62      "methodConfig": [{
    63        "name": [{"service": "grpc.testing.TestService"}],
    64        "waitForReady": true,
    65        "retryPolicy": {
    66          "MaxAttempts": 4,
    67          "InitialBackoff": ".01s",
    68          "MaxBackoff": ".01s",
    69          "BackoffMultiplier": 1.0,
    70          "RetryableStatusCodes": [ "ALREADY_EXISTS" ]
    71        }
    72      }]}`)
    73  	ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second)
    74  	for {
    75  		if ctx.Err() != nil {
    76  			t.Fatalf("Timed out waiting for service config update")
    77  		}
    78  		if ss.CC.GetMethodConfig("/grpc.testing.TestService/EmptyCall").WaitForReady != nil {
    79  			break
    80  		}
    81  		time.Sleep(time.Millisecond)
    82  	}
    83  	cancel()
    84  
    85  	testCases := []struct {
    86  		code  codes.Code
    87  		count int
    88  	}{
    89  		{codes.OK, 0},
    90  		{codes.OK, 2},
    91  		{codes.OK, 5},
    92  		{codes.Internal, 6},
    93  		{codes.Internal, 8},
    94  		{codes.Internal, 11},
    95  		{codes.AlreadyExists, 15},
    96  	}
    97  	for _, tc := range testCases {
    98  		ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
    99  		_, err := ss.Client.EmptyCall(ctx, &testpb.Empty{})
   100  		cancel()
   101  		if status.Code(err) != tc.code {
   102  			t.Fatalf("EmptyCall(_, _) = _, %v; want _, <Code() = %v>", err, tc.code)
   103  		}
   104  		if i != tc.count {
   105  			t.Fatalf("i = %v; want %v", i, tc.count)
   106  		}
   107  	}
   108  }
   109  
   110  func (s) TestRetryThrottling(t *testing.T) {
   111  	i := -1
   112  	ss := &stubserver.StubServer{
   113  		EmptyCallF: func(context.Context, *testpb.Empty) (*testpb.Empty, error) {
   114  			i++
   115  			switch i {
   116  			case 0, 3, 6, 10, 11, 12, 13, 14, 16, 18:
   117  				return &testpb.Empty{}, nil
   118  			}
   119  			return nil, status.New(codes.Unavailable, "retryable error").Err()
   120  		},
   121  	}
   122  	if err := ss.Start([]grpc.ServerOption{}); err != nil {
   123  		t.Fatalf("Error starting endpoint server: %v", err)
   124  	}
   125  	defer ss.Stop()
   126  	ss.NewServiceConfig(`{
   127      "methodConfig": [{
   128        "name": [{"service": "grpc.testing.TestService"}],
   129        "waitForReady": true,
   130        "retryPolicy": {
   131          "MaxAttempts": 4,
   132          "InitialBackoff": ".01s",
   133          "MaxBackoff": ".01s",
   134          "BackoffMultiplier": 1.0,
   135          "RetryableStatusCodes": [ "UNAVAILABLE" ]
   136        }
   137      }],
   138      "retryThrottling": {
   139        "maxTokens": 10,
   140        "tokenRatio": 0.5
   141      }
   142    }`)
   143  	ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second)
   144  	for {
   145  		if ctx.Err() != nil {
   146  			t.Fatalf("Timed out waiting for service config update")
   147  		}
   148  		if ss.CC.GetMethodConfig("/grpc.testing.TestService/EmptyCall").WaitForReady != nil {
   149  			break
   150  		}
   151  		time.Sleep(time.Millisecond)
   152  	}
   153  	cancel()
   154  
   155  	testCases := []struct {
   156  		code  codes.Code
   157  		count int
   158  	}{
   159  		{codes.OK, 0},           // tokens = 10
   160  		{codes.OK, 3},           // tokens = 8.5 (10 - 2 failures + 0.5 success)
   161  		{codes.OK, 6},           // tokens = 6
   162  		{codes.Unavailable, 8},  // tokens = 5 -- first attempt is retried; second aborted.
   163  		{codes.Unavailable, 9},  // tokens = 4
   164  		{codes.OK, 10},          // tokens = 4.5
   165  		{codes.OK, 11},          // tokens = 5
   166  		{codes.OK, 12},          // tokens = 5.5
   167  		{codes.OK, 13},          // tokens = 6
   168  		{codes.OK, 14},          // tokens = 6.5
   169  		{codes.OK, 16},          // tokens = 5.5
   170  		{codes.Unavailable, 17}, // tokens = 4.5
   171  	}
   172  	for _, tc := range testCases {
   173  		ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
   174  		_, err := ss.Client.EmptyCall(ctx, &testpb.Empty{})
   175  		cancel()
   176  		if status.Code(err) != tc.code {
   177  			t.Errorf("EmptyCall(_, _) = _, %v; want _, <Code() = %v>", err, tc.code)
   178  		}
   179  		if i != tc.count {
   180  			t.Errorf("i = %v; want %v", i, tc.count)
   181  		}
   182  	}
   183  }
   184  
   185  func (s) TestRetryStreaming(t *testing.T) {
   186  	req := func(b byte) *testpb.StreamingOutputCallRequest {
   187  		return &testpb.StreamingOutputCallRequest{Payload: &testpb.Payload{Body: []byte{b}}}
   188  	}
   189  	res := func(b byte) *testpb.StreamingOutputCallResponse {
   190  		return &testpb.StreamingOutputCallResponse{Payload: &testpb.Payload{Body: []byte{b}}}
   191  	}
   192  
   193  	largePayload, _ := newPayload(testpb.PayloadType_COMPRESSABLE, 500)
   194  
   195  	type serverOp func(stream testpb.TestService_FullDuplexCallServer) error
   196  	type clientOp func(stream testpb.TestService_FullDuplexCallClient) error
   197  
   198  	// Server Operations
   199  	sAttempts := func(n int) serverOp {
   200  		return func(stream testpb.TestService_FullDuplexCallServer) error {
   201  			const key = "grpc-previous-rpc-attempts"
   202  			md, ok := metadata.FromIncomingContext(stream.Context())
   203  			if !ok {
   204  				return status.Errorf(codes.Internal, "server: no header metadata received")
   205  			}
   206  			if got := md[key]; len(got) != 1 || got[0] != strconv.Itoa(n) {
   207  				return status.Errorf(codes.Internal, "server: metadata = %v; want <contains %q: %q>", md, key, n)
   208  			}
   209  			return nil
   210  		}
   211  	}
   212  	sReq := func(b byte) serverOp {
   213  		return func(stream testpb.TestService_FullDuplexCallServer) error {
   214  			want := req(b)
   215  			if got, err := stream.Recv(); err != nil || !proto.Equal(got, want) {
   216  				return status.Errorf(codes.Internal, "server: Recv() = %v, %v; want %v, <nil>", got, err, want)
   217  			}
   218  			return nil
   219  		}
   220  	}
   221  	sReqPayload := func(p *testpb.Payload) serverOp {
   222  		return func(stream testpb.TestService_FullDuplexCallServer) error {
   223  			want := &testpb.StreamingOutputCallRequest{Payload: p}
   224  			if got, err := stream.Recv(); err != nil || !proto.Equal(got, want) {
   225  				return status.Errorf(codes.Internal, "server: Recv() = %v, %v; want %v, <nil>", got, err, want)
   226  			}
   227  			return nil
   228  		}
   229  	}
   230  	sRes := func(b byte) serverOp {
   231  		return func(stream testpb.TestService_FullDuplexCallServer) error {
   232  			msg := res(b)
   233  			if err := stream.Send(msg); err != nil {
   234  				return status.Errorf(codes.Internal, "server: Send(%v) = %v; want <nil>", msg, err)
   235  			}
   236  			return nil
   237  		}
   238  	}
   239  	sErr := func(c codes.Code) serverOp {
   240  		return func(stream testpb.TestService_FullDuplexCallServer) error {
   241  			return status.New(c, "").Err()
   242  		}
   243  	}
   244  	sCloseSend := func() serverOp {
   245  		return func(stream testpb.TestService_FullDuplexCallServer) error {
   246  			if msg, err := stream.Recv(); msg != nil || err != io.EOF {
   247  				return status.Errorf(codes.Internal, "server: Recv() = %v, %v; want <nil>, io.EOF", msg, err)
   248  			}
   249  			return nil
   250  		}
   251  	}
   252  	sPushback := func(s string) serverOp {
   253  		return func(stream testpb.TestService_FullDuplexCallServer) error {
   254  			stream.SetTrailer(metadata.MD{"grpc-retry-pushback-ms": []string{s}})
   255  			return nil
   256  		}
   257  	}
   258  
   259  	// Client Operations
   260  	cReq := func(b byte) clientOp {
   261  		return func(stream testpb.TestService_FullDuplexCallClient) error {
   262  			msg := req(b)
   263  			if err := stream.Send(msg); err != nil {
   264  				return fmt.Errorf("client: Send(%v) = %v; want <nil>", msg, err)
   265  			}
   266  			return nil
   267  		}
   268  	}
   269  	cReqPayload := func(p *testpb.Payload) clientOp {
   270  		return func(stream testpb.TestService_FullDuplexCallClient) error {
   271  			msg := &testpb.StreamingOutputCallRequest{Payload: p}
   272  			if err := stream.Send(msg); err != nil {
   273  				return fmt.Errorf("client: Send(%v) = %v; want <nil>", msg, err)
   274  			}
   275  			return nil
   276  		}
   277  	}
   278  	cRes := func(b byte) clientOp {
   279  		return func(stream testpb.TestService_FullDuplexCallClient) error {
   280  			want := res(b)
   281  			if got, err := stream.Recv(); err != nil || !proto.Equal(got, want) {
   282  				return fmt.Errorf("client: Recv() = %v, %v; want %v, <nil>", got, err, want)
   283  			}
   284  			return nil
   285  		}
   286  	}
   287  	cErr := func(c codes.Code) clientOp {
   288  		return func(stream testpb.TestService_FullDuplexCallClient) error {
   289  			want := status.New(c, "").Err()
   290  			if c == codes.OK {
   291  				want = io.EOF
   292  			}
   293  			res, err := stream.Recv()
   294  			if res != nil ||
   295  				((err == nil) != (want == nil)) ||
   296  				(want != nil && err.Error() != want.Error()) {
   297  				return fmt.Errorf("client: Recv() = %v, %v; want <nil>, %v", res, err, want)
   298  			}
   299  			return nil
   300  		}
   301  	}
   302  	cCloseSend := func() clientOp {
   303  		return func(stream testpb.TestService_FullDuplexCallClient) error {
   304  			if err := stream.CloseSend(); err != nil {
   305  				return fmt.Errorf("client: CloseSend() = %v; want <nil>", err)
   306  			}
   307  			return nil
   308  		}
   309  	}
   310  	var curTime time.Time
   311  	cGetTime := func() clientOp {
   312  		return func(_ testpb.TestService_FullDuplexCallClient) error {
   313  			curTime = time.Now()
   314  			return nil
   315  		}
   316  	}
   317  	cCheckElapsed := func(d time.Duration) clientOp {
   318  		return func(_ testpb.TestService_FullDuplexCallClient) error {
   319  			if elapsed := time.Since(curTime); elapsed < d {
   320  				return fmt.Errorf("elapsed time: %v; want >= %v", elapsed, d)
   321  			}
   322  			return nil
   323  		}
   324  	}
   325  	cHdr := func() clientOp {
   326  		return func(stream testpb.TestService_FullDuplexCallClient) error {
   327  			_, err := stream.Header()
   328  			return err
   329  		}
   330  	}
   331  	cCtx := func() clientOp {
   332  		return func(stream testpb.TestService_FullDuplexCallClient) error {
   333  			stream.Context()
   334  			return nil
   335  		}
   336  	}
   337  
   338  	testCases := []struct {
   339  		desc      string
   340  		serverOps []serverOp
   341  		clientOps []clientOp
   342  	}{{
   343  		desc:      "Non-retryable error code",
   344  		serverOps: []serverOp{sReq(1), sErr(codes.Internal)},
   345  		clientOps: []clientOp{cReq(1), cErr(codes.Internal)},
   346  	}, {
   347  		desc:      "One retry necessary",
   348  		serverOps: []serverOp{sReq(1), sErr(codes.Unavailable), sReq(1), sAttempts(1), sRes(1)},
   349  		clientOps: []clientOp{cReq(1), cRes(1), cErr(codes.OK)},
   350  	}, {
   351  		desc: "Exceed max attempts (4); check attempts header on server",
   352  		serverOps: []serverOp{
   353  			sReq(1), sErr(codes.Unavailable),
   354  			sReq(1), sAttempts(1), sErr(codes.Unavailable),
   355  			sAttempts(2), sReq(1), sErr(codes.Unavailable),
   356  			sAttempts(3), sReq(1), sErr(codes.Unavailable),
   357  		},
   358  		clientOps: []clientOp{cReq(1), cErr(codes.Unavailable)},
   359  	}, {
   360  		desc: "Multiple requests",
   361  		serverOps: []serverOp{
   362  			sReq(1), sReq(2), sErr(codes.Unavailable),
   363  			sReq(1), sReq(2), sRes(5),
   364  		},
   365  		clientOps: []clientOp{cReq(1), cReq(2), cRes(5), cErr(codes.OK)},
   366  	}, {
   367  		desc: "Multiple successive requests",
   368  		serverOps: []serverOp{
   369  			sReq(1), sErr(codes.Unavailable),
   370  			sReq(1), sReq(2), sErr(codes.Unavailable),
   371  			sReq(1), sReq(2), sReq(3), sRes(5),
   372  		},
   373  		clientOps: []clientOp{cReq(1), cReq(2), cReq(3), cRes(5), cErr(codes.OK)},
   374  	}, {
   375  		desc: "No retry after receiving",
   376  		serverOps: []serverOp{
   377  			sReq(1), sErr(codes.Unavailable),
   378  			sReq(1), sRes(3), sErr(codes.Unavailable),
   379  		},
   380  		clientOps: []clientOp{cReq(1), cRes(3), cErr(codes.Unavailable)},
   381  	}, {
   382  		desc:      "No retry after header",
   383  		serverOps: []serverOp{sReq(1), sErr(codes.Unavailable)},
   384  		clientOps: []clientOp{cReq(1), cHdr(), cErr(codes.Unavailable)},
   385  	}, {
   386  		desc:      "No retry after context",
   387  		serverOps: []serverOp{sReq(1), sErr(codes.Unavailable)},
   388  		clientOps: []clientOp{cReq(1), cCtx(), cErr(codes.Unavailable)},
   389  	}, {
   390  		desc: "Replaying close send",
   391  		serverOps: []serverOp{
   392  			sReq(1), sReq(2), sCloseSend(), sErr(codes.Unavailable),
   393  			sReq(1), sReq(2), sCloseSend(), sRes(1), sRes(3), sRes(5),
   394  		},
   395  		clientOps: []clientOp{cReq(1), cReq(2), cCloseSend(), cRes(1), cRes(3), cRes(5), cErr(codes.OK)},
   396  	}, {
   397  		desc:      "Negative server pushback - no retry",
   398  		serverOps: []serverOp{sReq(1), sPushback("-1"), sErr(codes.Unavailable)},
   399  		clientOps: []clientOp{cReq(1), cErr(codes.Unavailable)},
   400  	}, {
   401  		desc:      "Non-numeric server pushback - no retry",
   402  		serverOps: []serverOp{sReq(1), sPushback("xxx"), sErr(codes.Unavailable)},
   403  		clientOps: []clientOp{cReq(1), cErr(codes.Unavailable)},
   404  	}, {
   405  		desc:      "Multiple server pushback values - no retry",
   406  		serverOps: []serverOp{sReq(1), sPushback("100"), sPushback("10"), sErr(codes.Unavailable)},
   407  		clientOps: []clientOp{cReq(1), cErr(codes.Unavailable)},
   408  	}, {
   409  		desc:      "1s server pushback - delayed retry",
   410  		serverOps: []serverOp{sReq(1), sPushback("1000"), sErr(codes.Unavailable), sReq(1), sRes(2)},
   411  		clientOps: []clientOp{cGetTime(), cReq(1), cRes(2), cCheckElapsed(time.Second), cErr(codes.OK)},
   412  	}, {
   413  		desc:      "Overflowing buffer - no retry",
   414  		serverOps: []serverOp{sReqPayload(largePayload), sErr(codes.Unavailable)},
   415  		clientOps: []clientOp{cReqPayload(largePayload), cErr(codes.Unavailable)},
   416  	}}
   417  
   418  	var serverOpIter int
   419  	var serverOps []serverOp
   420  	ss := &stubserver.StubServer{
   421  		FullDuplexCallF: func(stream testpb.TestService_FullDuplexCallServer) error {
   422  			for serverOpIter < len(serverOps) {
   423  				op := serverOps[serverOpIter]
   424  				serverOpIter++
   425  				if err := op(stream); err != nil {
   426  					return err
   427  				}
   428  			}
   429  			return nil
   430  		},
   431  	}
   432  	if err := ss.Start([]grpc.ServerOption{}, grpc.WithDefaultCallOptions(grpc.MaxRetryRPCBufferSize(200))); err != nil {
   433  		t.Fatalf("Error starting endpoint server: %v", err)
   434  	}
   435  	defer ss.Stop()
   436  	ss.NewServiceConfig(`{
   437      "methodConfig": [{
   438        "name": [{"service": "grpc.testing.TestService"}],
   439        "waitForReady": true,
   440        "retryPolicy": {
   441            "MaxAttempts": 4,
   442            "InitialBackoff": ".01s",
   443            "MaxBackoff": ".01s",
   444            "BackoffMultiplier": 1.0,
   445            "RetryableStatusCodes": [ "UNAVAILABLE" ]
   446        }
   447      }]}`)
   448  	ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second)
   449  	for {
   450  		if ctx.Err() != nil {
   451  			t.Fatalf("Timed out waiting for service config update")
   452  		}
   453  		if ss.CC.GetMethodConfig("/grpc.testing.TestService/FullDuplexCall").WaitForReady != nil {
   454  			break
   455  		}
   456  		time.Sleep(time.Millisecond)
   457  	}
   458  	cancel()
   459  
   460  	for _, tc := range testCases {
   461  		func() {
   462  			serverOpIter = 0
   463  			serverOps = tc.serverOps
   464  
   465  			ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
   466  			defer cancel()
   467  			stream, err := ss.Client.FullDuplexCall(ctx)
   468  			if err != nil {
   469  				t.Fatalf("%v: Error while creating stream: %v", tc.desc, err)
   470  			}
   471  			for _, op := range tc.clientOps {
   472  				if err := op(stream); err != nil {
   473  					t.Errorf("%v: %v", tc.desc, err)
   474  					break
   475  				}
   476  			}
   477  			if serverOpIter != len(serverOps) {
   478  				t.Errorf("%v: serverOpIter = %v; want %v", tc.desc, serverOpIter, len(serverOps))
   479  			}
   480  		}()
   481  	}
   482  }
   483  
   484  type retryStatsHandler struct {
   485  	mu sync.Mutex
   486  	s  []stats.RPCStats
   487  }
   488  
   489  func (*retryStatsHandler) TagRPC(ctx context.Context, _ *stats.RPCTagInfo) context.Context {
   490  	return ctx
   491  }
   492  func (h *retryStatsHandler) HandleRPC(_ context.Context, s stats.RPCStats) {
   493  	h.mu.Lock()
   494  	h.s = append(h.s, s)
   495  	h.mu.Unlock()
   496  }
   497  func (*retryStatsHandler) TagConn(ctx context.Context, _ *stats.ConnTagInfo) context.Context {
   498  	return ctx
   499  }
   500  func (*retryStatsHandler) HandleConn(context.Context, stats.ConnStats) {}
   501  
   502  func (s) TestRetryStats(t *testing.T) {
   503  	lis, err := net.Listen("tcp", "localhost:0")
   504  	if err != nil {
   505  		t.Fatalf("Failed to listen. Err: %v", err)
   506  	}
   507  	defer lis.Close()
   508  	server := &httpServer{
   509  		waitForEndStream: true,
   510  		responses: []httpServerResponse{{
   511  			trailers: [][]string{{
   512  				":status", "200",
   513  				"content-type", "application/grpc",
   514  				"grpc-status", "14", // UNAVAILABLE
   515  				"grpc-message", "unavailable retry",
   516  				"grpc-retry-pushback-ms", "10",
   517  			}},
   518  		}, {
   519  			headers: [][]string{{
   520  				":status", "200",
   521  				"content-type", "application/grpc",
   522  			}},
   523  			payload: []byte{0, 0, 0, 0, 0}, // header for 0-byte response message.
   524  			trailers: [][]string{{
   525  				"grpc-status", "0", // OK
   526  			}},
   527  		}},
   528  		refuseStream: func(i uint32) bool {
   529  			return i == 1
   530  		},
   531  	}
   532  	server.start(t, lis)
   533  	handler := &retryStatsHandler{}
   534  	cc, err := grpc.Dial(lis.Addr().String(), grpc.WithInsecure(), grpc.WithStatsHandler(handler),
   535  		grpc.WithDefaultServiceConfig((`{
   536      "methodConfig": [{
   537        "name": [{"service": "grpc.testing.TestService"}],
   538        "retryPolicy": {
   539            "MaxAttempts": 4,
   540            "InitialBackoff": ".01s",
   541            "MaxBackoff": ".01s",
   542            "BackoffMultiplier": 1.0,
   543            "RetryableStatusCodes": [ "UNAVAILABLE" ]
   544        }
   545      }]}`)))
   546  	if err != nil {
   547  		t.Fatalf("failed to dial due to err: %v", err)
   548  	}
   549  	defer cc.Close()
   550  
   551  	ctx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout)
   552  	defer cancel()
   553  
   554  	client := testpb.NewTestServiceClient(cc)
   555  
   556  	if _, err := client.EmptyCall(ctx, &testpb.Empty{}); err != nil {
   557  		t.Fatalf("unexpected EmptyCall error: %v", err)
   558  	}
   559  	handler.mu.Lock()
   560  	want := []stats.RPCStats{
   561  		&stats.Begin{},
   562  		&stats.OutHeader{FullMethod: "/grpc.testing.TestService/EmptyCall"},
   563  		&stats.OutPayload{WireLength: 5},
   564  		&stats.End{},
   565  
   566  		&stats.Begin{IsTransparentRetryAttempt: true},
   567  		&stats.OutHeader{FullMethod: "/grpc.testing.TestService/EmptyCall"},
   568  		&stats.OutPayload{WireLength: 5},
   569  		&stats.InTrailer{Trailer: metadata.Pairs("content-type", "application/grpc", "grpc-retry-pushback-ms", "10")},
   570  		&stats.End{},
   571  
   572  		&stats.Begin{},
   573  		&stats.OutHeader{FullMethod: "/grpc.testing.TestService/EmptyCall"},
   574  		&stats.OutPayload{WireLength: 5},
   575  		&stats.InHeader{},
   576  		&stats.InPayload{WireLength: 5},
   577  		&stats.InTrailer{},
   578  		&stats.End{},
   579  	}
   580  
   581  	toString := func(ss []stats.RPCStats) (ret []string) {
   582  		for _, s := range ss {
   583  			ret = append(ret, fmt.Sprintf("%T - %v", s, s))
   584  		}
   585  		return ret
   586  	}
   587  	t.Logf("Handler received frames:\n%v\n---\nwant:\n%v\n",
   588  		strings.Join(toString(handler.s), "\n"),
   589  		strings.Join(toString(want), "\n"))
   590  
   591  	if len(handler.s) != len(want) {
   592  		t.Fatalf("received unexpected number of RPCStats: got %v; want %v", len(handler.s), len(want))
   593  	}
   594  
   595  	// There is a race between receiving the payload (triggered by the
   596  	// application / gRPC library) and receiving the trailer (triggered at the
   597  	// transport layer).  Adjust the received stats accordingly if necessary.
   598  	const tIdx, pIdx = 13, 14
   599  	_, okT := handler.s[tIdx].(*stats.InTrailer)
   600  	_, okP := handler.s[pIdx].(*stats.InPayload)
   601  	if okT && okP {
   602  		handler.s[pIdx], handler.s[tIdx] = handler.s[tIdx], handler.s[pIdx]
   603  	}
   604  
   605  	for i := range handler.s {
   606  		w, s := want[i], handler.s[i]
   607  
   608  		// Validate the event type
   609  		if reflect.TypeOf(w) != reflect.TypeOf(s) {
   610  			t.Fatalf("at position %v: got %T; want %T", i, s, w)
   611  		}
   612  		wv, sv := reflect.ValueOf(w).Elem(), reflect.ValueOf(s).Elem()
   613  
   614  		// Validate that Client is always true
   615  		if sv.FieldByName("Client").Interface().(bool) != true {
   616  			t.Fatalf("at position %v: got Client=false; want true", i)
   617  		}
   618  
   619  		// Validate any set fields in want
   620  		for i := 0; i < wv.NumField(); i++ {
   621  			if !wv.Field(i).IsZero() {
   622  				if got, want := sv.Field(i).Interface(), wv.Field(i).Interface(); !reflect.DeepEqual(got, want) {
   623  					name := reflect.TypeOf(w).Elem().Field(i).Name
   624  					t.Fatalf("at position %v, field %v: got %v; want %v", i, name, got, want)
   625  				}
   626  			}
   627  		}
   628  
   629  		// Since the above only tests non-zero-value fields, test
   630  		// IsTransparentRetryAttempt=false explicitly when needed.
   631  		if wb, ok := w.(*stats.Begin); ok && !wb.IsTransparentRetryAttempt {
   632  			if s.(*stats.Begin).IsTransparentRetryAttempt {
   633  				t.Fatalf("at position %v: got IsTransparentRetryAttempt=true; want false", i)
   634  			}
   635  		}
   636  	}
   637  
   638  	// Validate timings between last Begin and preceding End.
   639  	end := handler.s[8].(*stats.End)
   640  	begin := handler.s[9].(*stats.Begin)
   641  	diff := begin.BeginTime.Sub(end.EndTime)
   642  	if diff < 10*time.Millisecond || diff > 50*time.Millisecond {
   643  		t.Fatalf("pushback time before final attempt = %v; want ~10ms", diff)
   644  	}
   645  }