breakfix: Token used before issued

[cceslick]

Describe the issue

This is my first time using Caddy for any project. I am attempting to provide Google authentication to internal websites. I started a few days ago with caddy-auth-portal and today I converted it to caddy-security. However, on both versions, I randomly get the error:

"failed validating OAuth 2.0 access token: OAuth 2.0 failed to parse id_token: Token used before issued"

This results in an "Unauthorized" response from the login portal.

If you sign into the portal, and then click the "logout" button, when you sign in again it will often give you the error the second time.

Some Googling provides this link to a discussion about "clock skew":
dgrijalva/jwt-go#383

Client and server are synchronized and no more than a fraction of a second different so I'm not sure if that is the problem.

Configuration

{
    debug
    order authorize before reverse_proxy
    order authenticate before authorize

	security {
		authentication portal myportal {
			backend google <redacted>.apps.googleusercontent.com <redacted>
			ui {
				links {
					"My Identity" "/auth/whoami" icon "las la-star"
				}
			}
			transform user {
				match origin google
				suffix match email @my.domain
				action add role authp/user
				ui link "Application" "https://app.my.domain/secure"
			}
			transform user {
#not sure if "exact match" is appropriate here, but was based on examples
				exact match origin google
				exact match email admin@my.domain
				action add role authp/admin
			}
			cookie domain my.domain
		}
		authorization policy mypolicy {
			set auth url /auth/oauth2/google
			allow roles authp/admin authp/user
		}		
	}
}

auth.my.domain {
	route /auth* {
		authenticate * with myportal
	}
}	

app.my.domain {
	route /secure* {
		authorize with mypolicy
		reverse_proxy https://app.mydomain
	}
	route {
		reverse_proxy https://app.mydomain
	}
}

Version Information

Windows version of Caddy built this morning from the download page with only caddy-security included.

Expected behavior

Should authenticate as normal without error.

Additional context

Caddy is running on Windows.

[greenpau]

@cceslick , this is a bug. releasing shortly.

[greenpau]

Released fix in https://github.com/greenpau/caddy-security/releases/tag/v1.0.2

Please retest and re-open if necessary.

[cceslick]

Thanks for the speedy fix. How often are new releases added to https://caddyserver.com/download? I downloaded a fresh copy and it is still at 1.01. I can set up Docker if necessary.

Thanks again.

[greenpau]

It is automatic. Specify the version and you should be good to go.

[greenpau]

@cceslick , the latest docker image is: https://github.com/greenpau/caddy-security/pkgs/container/authp

[cceslick]

If I type in 1.0.5 manually it gives me a "build failed" error

.

[greenpau]

@cceslick , what happens when you try the download links over here? https://github.com/greenpau/caddy-security#getting-started

Perhaps there is an issue with the Download page.

[cceslick]

The link worked. Build-info reports 1.0.5. It looks like you have to include the "v" (e.g. "v1.0.5") to get the specific version.

Unfortunately, I am still getting the "token used before issued" error. I cleared my cache and reloaded the web browser first.

[greenpau]

"failed validating OAuth 2.0 access token: OAuth 2.0 failed to parse id_token: Token used before issued"

@cceslick, did you verify that the clock is being synchronized with UTC?

Are you able to login and browse to /whoami in the authentication portal?

[cceslick]

As far as I can tell, the clocks between server and client are within ~100ms. When it works, I am able to go to /whoami. I've logged in and out a dozen times in the last few minutes and it has worked every time. The server did a time sync about an hour ago, and the previous one was on Friday when I did a manual sync. Earlier today it wouldn't work at all, and last week it would work and then not work the next time. So, if it is caused by the time sync, it is extremely sensitive to the time. The discussion I linked to above talks about a "clocktolerence," "clockskew," or "leeway" setting that some libraries have to account for this. There is also some talk in the JWT RFC https://datatracker.ietf.org/doc/html/rfc7519#section-4.1.4

[cceslick]

Whoami shows that the "not_before_utc" time is one minute before the "issued_at_utc" which should be enough leeway. Maybe I wasn't paying attention and ran the old version? I'll keep checking the time sync. This is a Windows virtual machine, which might be related to the problem.

[greenpau]

Whoami shows that the "not_before_utc" time is one minute before the "issued_at_utc" which should be enough leeway.

@cceslick , please share the text of the /whoami.

[cceslick]

{
  "addr": "<ipaddress>",
  "authenticated": true,
  "exp": 1643065179,
  "expires_at_utc": "Mon Jan 24 15:59:39 MST 2022",
  "iat": 1643064279,
  "iss": "https://auth.my.domain/auth/oauth2/google/",
  "issued_at_utc": "Mon Jan 24 15:44:39 MST 2022",
  "jti": "<redacted>",
  "mail": "me@my.domain",
  "name": "My Name",
  "nbf": 1643064219,
  "not_before_utc": "Mon Jan 24 15:43:39 MST 2022",
  "origin": "google",
  "picture": "https://lh3.googleusercontent.com/a-/<redacted>",
  "realm": "google",
  "roles": [
    "authp/user",
    "domain_user",
    "authp/admin"
  ],
  "sub": "<redacted>"
}

[greenpau]

"failed validating OAuth 2.0 access token: OAuth 2.0 failed to parse id_token: Token used before issued"

@cceslick I misinterpreted the above error. This is being the issue with the token you get from Google (not the token you access the portal).

https://github.com/greenpau/go-authcrunch/blob/b79f26580ef7ca654d48af51a06428a368eac62a/pkg/authn/backends/oauth2/validator.go#L38-L59

I randomly get the error: "failed validating OAuth 2.0 access token: OAuth 2.0 failed to parse id_token: Token used before issued"

This is normal behavior.

Does it impact your authentication flow?

[cceslick]

When it occurs, authentication fails with "unauthorized." I'll see if there is anything that can be done to improve clock sync and continue to test.

[greenpau]

I'll see if there is anything that can be done to improve clock sync and continue to test.

@cceslick , it looks like it has nothing to do with your clock. It looks like Google provisions its keys ahead of time. If anything, it is I who needs to put a check that would recognize the "early provisioning." At the moment, it will be in a backlog.

[gingermike]

Hi @greenpau - did you manage to pick this fix up at all? I'm also struggling with a similar issue - have to go through the auth hop a number of times before Caddy validates the token correctly.

Definitely some clock skew going on - maybe on the Google side - my server is sync'ed using chrony on Ubuntu

[greenpau]

@gingermike , unfortunately not. Busy at work/home.

[binarious]

Is it currently possible to define a tolerance/leeway for the clock skew? Maybe this could help.

[greenpau]

Is it currently possible to define a tolerance/leeway for the clock skew? Maybe this could help.

@binarious , no. Designing around clock sync issues is not in scope for the project.