Fix Timeout for token retrievals in consequent failures

[orenbm]

Summary

After we get the access token into the shared volume, we hit the reset button on the expBackoff clock
before waiting the token refresh timeout. This means that the next
interval will start 6 minutes (by default) into the clock and only one
cycle will run (as we exceed the max elapsed time of 2 minutes).

We should reset the clock after the timeout waits to ensure that the next cycle
will run for at most 2 minutes as intended.

Here is a log that shows the failure, in which we run only once before crashing (logs are written from bottom to top):

{"log":"ERROR: 2020/09/07 07:58:57 main.go:76: CAKC031E Retransmission backoff exhausted\n","stream":"stderr","time":"2020-09-07T07:58:57.784828076Z"}
{"log":"ERROR: 2020/09/07 07:58:57 main.go:48: CAKC016E Failed to authenticate\n","stream":"stderr","time":"2020-09-07T07:58:57.784823538Z"}
{"log":"ERROR: 2020/09/07 07:58:57 authenticator.go:233: CAKC027E Failed to send https authenticate request or receive response. Reason:...\n","stream":"stderr","time":"2020-09-07T07:58:57.784781083Z"}
{"log":"INFO: 2020/09/07 07:58:47 requests.go:47: CAKC012I Authn request to: ...\n","stream":"stdout","time":"2020-09-07T07:58:47.784448565Z"}
{"log":"INFO: 2020/09/07 07:58:47 authenticator.go:183: CAKC010I Buffer time:  30s\n","stream":"stdout","time":"2020-09-07T07:58:47.783685174Z"}
{"log":"INFO: 2020/09/07 07:58:47 authenticator.go:182: CAKC009I Current date: 2020-09-07 07:58:47.783493151 +0000 UTC\n","stream":"stdout","time":"2020-09-07T07:58:47.783680325Z"}
{"log":"INFO: 2020/09/07 07:58:47 authenticator.go:181: CAKC008I Cert expires: 2020-09-09 05:28:18 +0000 UTC\n","stream":"stdout","time":"2020-09-07T07:58:47.783676009Z"}
{"log":"INFO: 2020/09/07 07:58:47 main.go:45: CAKC006I Authenticating as user '...'\n","stream":"stdout","time":"2020-09-07T07:58:47.7836441Z"}
{"log":"\n","stream":"stdout","time":"2020-09-07T07:52:47.783548198Z"}
{"log":"INFO: 2020/09/07 07:52:47 main.go:63: CAKC013I Waiting for 6m0s to re-authenticate\n","stream":"stdout","time":"2020-09-07T07:52:47.783544229Z"} 

You can see that we start a new wait (CAKC013I) and this happens after we run expBackoff.Reset(). So we are supposed to run a new backoff cycle that will run for up to 2 minutes before crashing. However, we run only one time and finish the backoff before writing CAKC031E Retransmission backoff exhausted to the log.

Steps to Reproduce

Steps to reproduce the behavior:

1. Run the authn-client as a side car
2. Fail the second interval

Expected Results

The authenticator retries to authenticate

Actual Results (including error logs, if applicable)

The authenticator exists with failure after one try

[orenbm]

fixed by #157

[alexkalish]

@orenbm: Could you please explain this fix from the user/customer's perspective? I don't understand the details of the K8s token refresh feature/logic and need to detail this in the release notes. Also, is this logic captured in our docs anywhere? I don't see anything about it here. Thanks!

[orenbm]

i don't think the logic is captured in the docs. Our authn-k8s docs are lacking a lot of details on the flow.

What are you missing here? I was about to write the fix but it won't be different than what is explained in the description above and in the PR description.

CAn you please elaborate. on what is not clear?

[alexkalish]

@orenbm: I just find the description a little confusing. For example, "expBackoff clock" seems like an implementation detail. The clock isn't exposed to users, right? And the rest of the description is written around this clock. Why would someone care about this fix?