grpc_retry: WithPerRetryTimeout does not timeout

[isiddi4]

So my understanding of WithPerRetryTimeout is that it sets a timeout for each retry.
For example, if I have the following call options:

grpc_retry.WithMax(5)
grpc_retry.WithBackoff(grpc_retry.BackoffLinear(5 * time.Millisecond)
grpc_retry.WithPerRetryTimeout(5 * time.Millisecond)

the longest time I can expect my rpc to take should be about 100ms correct (backoff 4 times, each try takes 5 ms)?

Given that these assumptions hold true (I would greatly appreciate it if you could correct any misunderstandings I may have), then the following should be considered a bug:

Under retry/retry_test.go, if we alter the following test which currently looks like this:

func (s *RetrySuite) TestUnary_PerCallDeadline_Succeeds() {
	// This tests 5 requests, with first 4 sleeping for 10 millisecond, and the retry logic firing
	// a retry call with a 5 millisecond deadline. The 5th one doesn't sleep and succeeds.
	deadlinePerCall := 5 * time.Millisecond
	s.srv.resetFailingConfiguration(5, codes.NotFound, 2*deadlinePerCall)
        .
        .
        .

into this:

func (s *RetrySuite) TestUnary_PerCallDeadline_Succeeds() {
	// This tests 5 requests, with first 4 sleeping for 10 millisecond, and the retry logic firing
	// a retry call with a 5 millisecond deadline. The 5th one doesn't sleep and succeeds.
	deadlinePerCall := 5 * time.Millisecond
	s.srv.resetFailingConfiguration(5, codes.NotFound, 10*time.Second)
        .
        .
        .

changing the amount of time the server sleeps for, the tests ends up taking 40seconds and fails with DeadlineExceeded.

Just to clarify, my assumption is that this test should only take around 100ms at most given that WithPerRetryTimeout is set to 5ms.

I'm personally experiencing issues where calls will hang forever, and won't be canceled as I assume WithPerRetryTimeout should do.

[johanbrandhorst]

I'd have to dig into the code to answer this question, and unfortunately I don't have time for that right now, so I invite you to take a look at and play around with the source: https://github.com/grpc-ecosystem/go-grpc-middleware/blob/master/retry/retry.go#L29. If you're already gone to the lengths of trying to edit the tests, this is only a minor step further, and you can add some logging debugging etc to understand what's happening.

If you find an issue, then we can talk fixes :).

Hope that helps.

[isiddi4]

So, it seems like the reason why the test is failing isn't an issue with the implementation, its an issue with the test itself: https://github.com/grpc-ecosystem/go-grpc-middleware/blob/master/retry/retry_test.go#L60. Having this mutex only unlock after the sleep, and having the sleep be significantly longer than the WithPerRetryTimeout, causes the test (TestUnary_PerCallDeadline_Succeeds()) to fail as the final retry never gets to this line: https://github.com/grpc-ecosystem/go-grpc-middleware/blob/master/retry/retry_test.go#L62. This can be fixed by simply unlocking the mutex after incrementing s.reqCounter.

As far as I can tell, WithPerRetryTimeout works as intended, and the issue that I'm facing is probably unrelated.

Let me know if I can provide any additional clarification.

[johanbrandhorst]

Great find Ismail! Would you be interested in contributing a fix for the test? Sorry it didn't resolve your underlying issue 😞.