Downgrade token auth JWT logging from error to info

The token auth package logs JWT validation and verification failures at
the `error` level.  But from the server's perspective, these aren't
errors.  They're the expected response to bad input.  Logging them at
the `info` level better reflects that distinction.

Signed-off-by: Noah Treuhaft <noah.treuhaft@docker.com>
This commit is contained in:
Noah Treuhaft 2016-09-07 10:45:06 -07:00
parent ed0b3aebb3
commit 91f268e5a5

View file

@ -95,7 +95,7 @@ func NewToken(rawToken string) (*Token, error) {
defer func() { defer func() {
if err != nil { if err != nil {
log.Errorf("error while unmarshalling raw token: %s", err) log.Infof("error while unmarshalling raw token: %s", err)
} }
}() }()
@ -135,13 +135,13 @@ func NewToken(rawToken string) (*Token, error) {
func (t *Token) Verify(verifyOpts VerifyOptions) error { func (t *Token) Verify(verifyOpts VerifyOptions) error {
// Verify that the Issuer claim is a trusted authority. // Verify that the Issuer claim is a trusted authority.
if !contains(verifyOpts.TrustedIssuers, t.Claims.Issuer) { if !contains(verifyOpts.TrustedIssuers, t.Claims.Issuer) {
log.Errorf("token from untrusted issuer: %q", t.Claims.Issuer) log.Infof("token from untrusted issuer: %q", t.Claims.Issuer)
return ErrInvalidToken return ErrInvalidToken
} }
// Verify that the Audience claim is allowed. // Verify that the Audience claim is allowed.
if !contains(verifyOpts.AcceptedAudiences, t.Claims.Audience) { if !contains(verifyOpts.AcceptedAudiences, t.Claims.Audience) {
log.Errorf("token intended for another audience: %q", t.Claims.Audience) log.Infof("token intended for another audience: %q", t.Claims.Audience)
return ErrInvalidToken return ErrInvalidToken
} }
@ -150,32 +150,32 @@ func (t *Token) Verify(verifyOpts VerifyOptions) error {
ExpWithLeeway := time.Unix(t.Claims.Expiration, 0).Add(Leeway) ExpWithLeeway := time.Unix(t.Claims.Expiration, 0).Add(Leeway)
if currentTime.After(ExpWithLeeway) { if currentTime.After(ExpWithLeeway) {
log.Errorf("token not to be used after %s - currently %s", ExpWithLeeway, currentTime) log.Infof("token not to be used after %s - currently %s", ExpWithLeeway, currentTime)
return ErrInvalidToken return ErrInvalidToken
} }
NotBeforeWithLeeway := time.Unix(t.Claims.NotBefore, 0).Add(-Leeway) NotBeforeWithLeeway := time.Unix(t.Claims.NotBefore, 0).Add(-Leeway)
if currentTime.Before(NotBeforeWithLeeway) { if currentTime.Before(NotBeforeWithLeeway) {
log.Errorf("token not to be used before %s - currently %s", NotBeforeWithLeeway, currentTime) log.Infof("token not to be used before %s - currently %s", NotBeforeWithLeeway, currentTime)
return ErrInvalidToken return ErrInvalidToken
} }
// Verify the token signature. // Verify the token signature.
if len(t.Signature) == 0 { if len(t.Signature) == 0 {
log.Error("token has no signature") log.Info("token has no signature")
return ErrInvalidToken return ErrInvalidToken
} }
// Verify that the signing key is trusted. // Verify that the signing key is trusted.
signingKey, err := t.VerifySigningKey(verifyOpts) signingKey, err := t.VerifySigningKey(verifyOpts)
if err != nil { if err != nil {
log.Error(err) log.Info(err)
return ErrInvalidToken return ErrInvalidToken
} }
// Finally, verify the signature of the token using the key which signed it. // Finally, verify the signature of the token using the key which signed it.
if err := signingKey.Verify(strings.NewReader(t.Raw), t.Header.SigningAlg, t.Signature); err != nil { if err := signingKey.Verify(strings.NewReader(t.Raw), t.Header.SigningAlg, t.Signature); err != nil {
log.Errorf("unable to verify token signature: %s", err) log.Infof("unable to verify token signature: %s", err)
return ErrInvalidToken return ErrInvalidToken
} }