Open2022/01/07にコメント追加2

golang と仲良くなる人

satoya 2022/01/07

context.DeadlineExceeded と context.Canceled と仲良くなる人。

func TestRequestTimeout(t *testing.T) {
	t.Parallel()

	h := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		time.Sleep(5 * time.Second)
	})

	t.Run("WithTimeout なし", func(t *testing.T) {
		t.Parallel()

		ts := httptest.NewServer(h)
		before := time.Now()

		ctx := context.Background()

		req, err := http.NewRequestWithContext(ctx, http.MethodGet, ts.URL, nil)
		if err != nil {
			t.Fatal(err)
		}
		res, err := http.DefaultClient.Do(req)
		if err != nil {
			// 今回のテストだと http handler による sleep なので err としては返らない
			t.Fatal(err)
		}
		defer res.Body.Close()
		if res.StatusCode != http.StatusOK {
			t.Errorf("want=http.StatusOK, got=%d", res.StatusCode)
		}

		// request 先の分（ 5sec ）経過してる
		after := time.Now()
		if after.Unix() != before.Add(5*time.Second).Unix() {
			t.Logf("%d", after.Unix())
			t.Logf("%d", before.Add(time.Second).Unix())
			t.Errorf("before=%+v, after=%+v", before, after)
		}
	})
	t.Run("WithTimeout あり", func(t *testing.T) {
		t.Parallel()

		ts := httptest.NewServer(h)
		before := time.Now()
		ctx, cancel := context.WithTimeout(context.Background(), time.Second)
		defer cancel()

		req, err := http.NewRequestWithContext(ctx, http.MethodGet, ts.URL, nil)
		if err != nil {
			t.Fatal(err)
		}
		res, err := http.DefaultClient.Do(req)
		if res != nil {
			t.Fatal(res)
		}

		// timeout を過ぎる場合、context.DeadlineExceeded が返る
		if err != nil && !errors.Is(err, context.DeadlineExceeded) {
			t.Errorf("want=context.DeadlineExceeded, got=%+v", err)
		}

		// request 先の 5sec 分を待たず WithTimeout で指定した time.Duration 分のみ経過してる
		after := time.Now()
		if after.Unix() != before.Add(time.Second).Unix() {
			t.Logf("%d", after.Unix())
			t.Logf("%d", before.Add(time.Second).Unix())
			t.Errorf("before=%+v, after=%+v", before, after)
		}
	})
	t.Run("WithTimeout あり（途中でキャンセルする）", func(t *testing.T) {
		t.Parallel()

		ts := httptest.NewServer(h)
		before := time.Now()
		ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)

		go func() {
			time.Sleep(2 * time.Second)
			cancel()
		}()

		req, err := http.NewRequestWithContext(ctx, http.MethodGet, ts.URL, nil)
		if err != nil {
			t.Fatal(err)
		}
		res, err := http.DefaultClient.Do(req)
		if res != nil {
			t.Fatal(res)
		}
		if err != nil && !errors.Is(err, context.Canceled) {
			t.Errorf("want=context.Canceled, got=%+v", err)
		}

		// request 先の 5sec 分を待たずキャンセルを行った 2sec 分のみ経過してる
		after := time.Now()
		if after.Unix() != before.Add(2*time.Second).Unix() {
			t.Logf("%d", after.Unix())
			t.Logf("%d", before.Add(time.Second).Unix())
			t.Errorf("before=%+v, after=%+v", before, after)
		}
	})
}

結論: それぞれ timeout 時、client からの cancel 時に返るエラー。timeout は（ものによっては）exponential backoff and jitter でリトライ。cancel は適当に 4xx 系で response するなどする。

satoya 2022/01/07

exponential backoff and jitter と仲良くなる人

func TestRetryRequest(t *testing.T) {
	t.Parallel()

	h := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		time.Sleep(5 * time.Second)
	})

	t.Run("request に timeout を指定しない場合", func(t *testing.T) {
		t.Parallel()

		before := time.Now()
		ts := httptest.NewServer(h)

		ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
		defer cancel()

		request := func(ctx context.Context) (*http.Response, error) {
			req, err := http.NewRequestWithContext(ctx, http.MethodGet, ts.URL, nil)
			if err != nil {
				t.Fatal(err)
			}
			return http.DefaultClient.Do(req)
		}

		actLoop := 0
		policy := backoff.Exponential(
			backoff.WithMinInterval(500*time.Millisecond),
			backoff.WithMaxInterval(3*time.Second),
			backoff.WithMaxRetries(3),
			backoff.WithJitterFactor(0.05),
		)
		b := policy.Start(ctx)
		for backoff.Continue(b) {
			actLoop++
			res, err := request(context.Background())
			if err == nil {
				if res.StatusCode != http.StatusOK {
					t.Errorf("want=200, got=%d", res.StatusCode)
				}
				break
			}
		}

		// request に timeout を設けていないため request 先の 5sec 経過し request としては成功しているため loop数は 1回
		if actLoop != 1 {
			t.Errorf("want=1, actLoop=%d", actLoop)
		}
		after := time.Now()
		if after == before.Add(5*time.Second) {
			t.Errorf("before=%+v, after=%+v", before, after)
		}
	})
	t.Run("request に timeout を指定する場合", func(t *testing.T) {
		t.Parallel()

		before := time.Now()
		ts := httptest.NewServer(h)

		ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
		defer cancel()

		request := func(parent context.Context) (*http.Response, error) {
			ctx, cancel := context.WithTimeout(parent, time.Second)
			defer cancel()

			req, err := http.NewRequestWithContext(ctx, http.MethodGet, ts.URL, nil)
			if err != nil {
				t.Fatal(err)
			}
			return http.DefaultClient.Do(req)
		}

		actLoop := 0
		var beforeInterval time.Duration
		loopStart := before
		policy := backoff.Exponential(
			backoff.WithMinInterval(time.Second),
			backoff.WithMaxInterval(3*time.Second),
			backoff.WithMaxRetries(3),
			backoff.WithJitterFactor(0.05),
		)
		b := policy.Start(ctx)
		for backoff.Continue(b) {
			now := time.Now()
			if actLoop > 1 {
				// loop 毎に interval が伸びてる（ exponential backoff されてる）ことの確認
				// （常に今回の interval が前回の interval を超えているか）
				if beforeInterval >= now.Sub(loopStart) {
					t.Errorf("beforeInterval >= now.Sub(loopStart), beforeInterval=%+v, now.Sub(loopStart)=%+v", beforeInterval, now.Sub(loopStart))
				}
			}
			if actLoop >= 1 {
				beforeInterval = now.Sub(loopStart)
				loopStart = now
			}
			actLoop++
			res, err := request(context.Background())
			if err == nil {
				t.Fatal("must be set err")
			}
			if res != nil {
				t.Fatal(res)
			}
			if !errors.Is(err, context.DeadlineExceeded) {
				t.Errorf("want=context.DeadlineExceeded, got=%+v", err)
			}
		}

		// request に timeout がありすべての request が失敗するため上限 3 回リトライして 4loop
		// 時間としては、(0.5~3)*3 の範囲で収まってるはず 5sec とか 6sec とか？最大値の 10sec は超えないはず
		if actLoop != 4 {
			t.Errorf("want=1, actLoop=%d", actLoop)
		}
		after := time.Now()
		if after.Unix() >= before.Add(10*time.Second).Unix() {
			t.Errorf("before=%+v, after=%+v", before, after)
		}
	})
	t.Run("全体の最大値は超えない", func(t *testing.T) {
		t.Parallel()

		before := time.Now()
		ts := httptest.NewServer(h)

		ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
		defer cancel()

		request := func(parent context.Context) (*http.Response, error) {
			ctx, cancel := context.WithTimeout(parent, 4*time.Second)
			defer cancel()

			req, err := http.NewRequestWithContext(ctx, http.MethodGet, ts.URL, nil)
			if err != nil {
				t.Fatal(err)
			}
			return http.DefaultClient.Do(req)
		}

		policy := backoff.Exponential(
			backoff.WithMinInterval(time.Second),
			backoff.WithMaxInterval(3*time.Second),
			backoff.WithMaxRetries(3),
			backoff.WithJitterFactor(0.05),
		)
		b := policy.Start(ctx)
		for backoff.Continue(b) {
			res, err := request(context.Background())
			if err == nil {
				t.Fatal("must be set err")
			}
			if res != nil {
				t.Fatal(res)
			}
			if !errors.Is(err, context.DeadlineExceeded) {
				t.Errorf("want=context.DeadlineExceeded, got=%+v", err)
			}
		}

		// 実際は WithTimeout で設定した 10sec きっかりとならず（たぶん backoff 分待ってから context の判定に移ってる？ので 10+backoff sec 経過する）
		after := time.Now()
		if after.Unix() <= before.Add(10*time.Second).Unix() {
			t.Errorf("before=%+v, after=%+v", before, after)
		}
	})
}