happydpc / goauth2

Automatically exported from code.google.com/p/goauth2
BSD 3-Clause "New" or "Revised" License
0 stars 0 forks source link

Intermittest TestOAuth failures #22

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago
We see occasional TestOAuth failures, always exactly like this:

--- FAIL: TestOAuth (0.00 seconds)
    oauth_test.go:74: request[5] got path /secure, want /token
    oauth_test.go:79: query[grant_type] = , want refresh_token
    oauth_test.go:79: query[refresh_token] = , want refreshtoken2
    oauth_test.go:79: query[client_id] = , want cl13nt1d
    oauth_test.go:158: request body mismatch: got "access_token=token3&refresh_token=refreshtoken3&id_token=idtoken3&expires_in=3600", want "third payload"
    oauth_test.go:138: AccessToken = "token2", want "token3"
    oauth_test.go:141: RefreshToken = "refreshtoken2", want "refreshtoken3"
    oauth_test.go:144: Extra['id_token'] = "idtoken2", want "idtoken3"
    oauth_test.go:148: Expiry = -158.99us, want ~1 hour

It looks like the requests are coming in out of order (although it is not clear 
to me how this happens).

Please provide any additional information below.

We are using Go 1.2 rc2. I have yet to be able to reproduce on OS X; we're 
seeing these failures from within OpenShift.

Original issue reported on code.google.com by joshar...@gmail.com on 31 Oct 2013 at 6:09

GoogleCodeExporter commented 9 years ago
This is very strange. I'm not sure how this could be happening. Any additional 
info you could provide would be great.

Original comment by a...@golang.org on 31 Oct 2013 at 11:44

GoogleCodeExporter commented 9 years ago
I'm thoroughly stumped as well. The most promising lead I have is that it only 
reproduces (so far) on OpenShift. That's all I know at the moment. I'll dig 
into it more, though...

Original comment by joshar...@gmail.com on 1 Nov 2013 at 12:49

GoogleCodeExporter commented 9 years ago
Ok, I finally understand what is happening. It looks like there's a bit of 
clock jitter in this environment.

Twice during TestOAuth, transport.Expiry is set to time.Now() to trigger a 
token refresh. Due to clock jitter, however, sometimes the token is *not* 
detected as expired, and the expected refresh call never gets made. (Cf. 
Expiry=-158.99us in the last line of the test output above.)

I'll see about resolving the clock jitter, but I'm not optimistic. 
Independently, changing:

https://code.google.com/p/goauth2/source/browse/oauth/oauth_test.go#118
https://code.google.com/p/goauth2/source/browse/oauth/oauth_test.go#127

to use (say) time.Now.Add(-time.Hour) instead of time.Now() fixes the problem. 
Are you open to that?

Original comment by joshar...@gmail.com on 1 Nov 2013 at 10:09

GoogleCodeExporter commented 9 years ago
Sure, I'd accept that fix. Seems fine.

Original comment by a...@golang.org on 4 Nov 2013 at 2:25

GoogleCodeExporter commented 9 years ago

Original comment by a...@golang.org on 4 Nov 2013 at 2:25

GoogleCodeExporter commented 9 years ago
This issue was closed by revision 8eeae4635bf6.

Original comment by a...@golang.org on 5 Nov 2013 at 2:04