Allow for some clock skew in JWT Validation #369
Description
While developing, I randomly encounter errors such as rpc error: code = Unauthenticated desc = {"code":401,"message":"Jwt not yet valid"} - ESPv2 logs this and it seems doesn't allow for any skew.
Message logged: 2020-10-09 01:50:53.281 EDT (Taken from Cloud Run Logs)
JWT IAT: 2020-10-09 01:51:00 EDT
My PC seems to be ahead of Google's by ~7 seconds - is this beyond the allowed skew from ESP?
Google's official guidance specifies allowing a 30 second skew when validating the IAT and EXP claims (this guidance is inconsistent throughout various JWT sources best practice documents).
Does ESPv2 allow for a skew when validating the JWT IAT and EXP claims? If not, can we specify one via the config, or can ESPv2 be updated to allow for some skew?
A side note but related - logs from ESPv2 don't always reflect the actual response status of the request, although I got a 401 response (gRPC), the log reflects a 200 response:
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][jwt][bazel-out/k8-opt/bin/external/envoy/source/extensions/filters/http/jwt_authn/_virtual_includes/filter_config_interface/extensions/filters/http/jwt_authn/filter_config.h:117] use filter state value <REMOVED> to find verifier.
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][jwt][external/envoy/source/extensions/filters/http/jwt_authn/extractor.cc:188] extract authorizationBearer
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][jwt][external/envoy/source/extensions/filters/http/jwt_authn/extractor.cc:188] extract x-goog-iap-jwt-assertion
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][jwt][external/envoy/source/extensions/filters/http/jwt_authn/authenticator.cc:127] google_service_account: JWT authentication starts (allow_failed=false), tokens size=1
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][jwt][external/envoy/source/extensions/filters/http/jwt_authn/authenticator.cc:138] google_service_account: startVerify: tokens size 1
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][jwt][external/envoy/source/extensions/filters/http/jwt_authn/authenticator.cc:149] google_service_account: Verifying JWT token of issuer <REMOVED>>
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][jwt][external/envoy/source/extensions/filters/http/jwt_authn/authenticator.cc:267] google_service_account: JWT token verification completed with: Jwt not yet valid
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][jwt][external/envoy/source/extensions/filters/http/jwt_authn/filter.cc:87] Called Filter : check complete Jwt not yet valid
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][http][external/envoy/source/common/http/conn_manager_impl.cc:1520] [C5][S10267617114464069896] Sending local reply with details jwt_authn_access_denied
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][filter][src/envoy/http/grpc_metadata_scrubber/filter.cc:29] Filter::encodeHeaders is called.
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][http][external/envoy/source/common/http/conn_manager_impl.cc:1777] [C5][S10267617114464069896] encoding headers via codec (end_stream=true):\n\':status\', \'200\'\n\'content-type\', \'application/grpc\'\n\'grpc-status\', \'16\'\n\'grpc-message\', \'{\"message\":\"Jwt not yet valid\",\"code\":401}\'\n\'date\', \'Fri, 09 Oct 2020 05:50:53 GMT\'\n\'server\', \'envoy\'\n\'x-envoy-decorator-operation\', \'ingress MutateFiles\'
Default
2020-10-09 01:50:53.281 EDT
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][http][external/envoy/source/common/http/conn_manager_impl.cc:207] [C5][S10267617114464069896] doEndStream() resetting stream
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][http][external/envoy/source/common/http/conn_manager_impl.cc:2007] [C5][S10267617114464069896] stream reset
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][jwt][external/envoy/source/extensions/filters/http/jwt_authn/filter.cc:42] Called Filter : onDestroy
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][filter][src/envoy/http/service_control/filter.cc:38] Called ServiceControl Filter : onDestroy
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][jwt][external/envoy/source/extensions/filters/http/jwt_authn/filter.cc:76] Called Filter : decodeHeaders Stop
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][http2][external/envoy/source/common/http/http2/codec_impl.cc:862] [C5] stream closed: 0
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.280 28 envoy] [28][filter][src/envoy/http/service_control/filter.cc:122] Called ServiceControl Filter : log
Default
2020-10-09 01:50:53.281 EDT
D1009 05:50:53.281 28 envoy] [28][filter][src/envoy/http/service_control/service_control_call_impl.cc:160] Sending report : service_name: <REMOVED>
Info
2020-10-09 01:50:53.282 EDT
**POST 200 391B 5 ms grpc-go 1.32.0 https://<REMOVED>**