diff --git a/docs/docs/CHANGELOG.md b/docs/docs/CHANGELOG.md index 633f9eb..0d1067b 100644 --- a/docs/docs/CHANGELOG.md +++ b/docs/docs/CHANGELOG.md @@ -16,6 +16,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - The [Thoth client](https://anubis.techaro.lol/docs/admin/thoth) is now public in the repo instead of being an internal package. - [Custom-AsyncHttpClient](https://github.com/AsyncHttpClient/async-http-client)'s default User-Agent has an increased weight by default ([#852](https://github.com/TecharoHQ/anubis/issues/852)). - The [`segments`](./admin/configuration/expressions.mdx#segments) function was added for splitting a path into its slash-separated segments. +- When issuing a challenge, Anubis stores information about that challenge into the store. That stored information is later used to validate challenge responses. This works around nondeterminism in bot rules. ([#917](https://github.com/TecharoHQ/anubis/issues/917)) ## v1.21.3: Minfilia Warde - Echo 3 diff --git a/internal/log.go b/internal/log.go index a711407..c3a6a0f 100644 --- a/internal/log.go +++ b/internal/log.go @@ -28,6 +28,9 @@ func InitSlog(level string) { func GetRequestLogger(r *http.Request) *slog.Logger { return slog.With( + "host", r.Host, + "method", r.Method, + "path", r.URL.Path, "user_agent", r.UserAgent(), "accept_language", r.Header.Get("Accept-Language"), "priority", r.Header.Get("Priority"), diff --git a/lib/anubis.go b/lib/anubis.go index 123b517..06b030a 100644 --- a/lib/anubis.go +++ b/lib/anubis.go @@ -90,41 +90,39 @@ func (s *Server) getTokenKeyfunc() jwt.Keyfunc { } } -func (s *Server) challengeFor(r *http.Request) (*challenge.Challenge, error) { +func (s *Server) getChallenge(r *http.Request) (*challenge.Challenge, error) { ckies := r.CookiesNamed(anubis.TestCookieName) - if len(ckies) == 0 { - return s.issueChallenge(r.Context(), r) + return nil, store.ErrNotFound } j := store.JSON[challenge.Challenge]{Underlying: s.store} ckie := ckies[0] chall, err := j.Get(r.Context(), "challenge:"+ckie.Value) - if err != nil { - if errors.Is(err, store.ErrNotFound) { - return s.issueChallenge(r.Context(), r) - } - return nil, err - } - - return &chall, nil + return &chall, err } -func (s *Server) issueChallenge(ctx context.Context, r *http.Request) (*challenge.Challenge, error) { +func (s *Server) issueChallenge(ctx context.Context, r *http.Request, lg *slog.Logger, cr policy.CheckResult, rule *policy.Bot) (*challenge.Challenge, error) { + if cr.Rule != config.RuleChallenge { + slog.Error("this should be impossible, asked to issue a challenge but the rule is not a challenge rule", "cr", cr, "rule", rule) + //return nil, errors.New("[unexpected] this codepath should be impossible, asked to issue a challenge for a non-challenge rule") + } + id, err := uuid.NewV7() if err != nil { return nil, err } - var randomData = make([]byte, 256) + var randomData = make([]byte, 64) if _, err := rand.Read(randomData); err != nil { return nil, err } chall := challenge.Challenge{ ID: id.String(), + Method: rule.Challenge.Algorithm, RandomData: fmt.Sprintf("%x", randomData), IssuedAt: time.Now(), Metadata: map[string]string{ @@ -138,6 +136,8 @@ func (s *Server) issueChallenge(ctx context.Context, r *http.Request) (*challeng return nil, err } + lg.Info("new challenge issued", "challenge", id.String()) + return &chall, err } @@ -185,21 +185,21 @@ func (s *Server) maybeReverseProxy(w http.ResponseWriter, r *http.Request, httpS if err != nil { lg.Debug("cookie not found", "path", r.URL.Path) s.ClearCookie(w, CookieOpts{Path: cookiePath, Host: r.Host}) - s.RenderIndex(w, r, rule, httpStatusOnly) + s.RenderIndex(w, r, cr, rule, httpStatusOnly) return } if err := ckie.Valid(); err != nil { lg.Debug("cookie is invalid", "err", err) s.ClearCookie(w, CookieOpts{Path: cookiePath, Host: r.Host}) - s.RenderIndex(w, r, rule, httpStatusOnly) + s.RenderIndex(w, r, cr, rule, httpStatusOnly) return } if time.Now().After(ckie.Expires) && !ckie.Expires.IsZero() { lg.Debug("cookie expired", "path", r.URL.Path) s.ClearCookie(w, CookieOpts{Path: cookiePath, Host: r.Host}) - s.RenderIndex(w, r, rule, httpStatusOnly) + s.RenderIndex(w, r, cr, rule, httpStatusOnly) return } @@ -208,7 +208,7 @@ func (s *Server) maybeReverseProxy(w http.ResponseWriter, r *http.Request, httpS if err != nil || !token.Valid { lg.Debug("invalid token", "path", r.URL.Path, "err", err) s.ClearCookie(w, CookieOpts{Path: cookiePath, Host: r.Host}) - s.RenderIndex(w, r, rule, httpStatusOnly) + s.RenderIndex(w, r, cr, rule, httpStatusOnly) return } @@ -216,7 +216,7 @@ func (s *Server) maybeReverseProxy(w http.ResponseWriter, r *http.Request, httpS if !ok { lg.Debug("invalid token claims type", "path", r.URL.Path) s.ClearCookie(w, CookieOpts{Path: cookiePath, Host: r.Host}) - s.RenderIndex(w, r, rule, httpStatusOnly) + s.RenderIndex(w, r, cr, rule, httpStatusOnly) return } @@ -224,14 +224,14 @@ func (s *Server) maybeReverseProxy(w http.ResponseWriter, r *http.Request, httpS if !ok { lg.Debug("policyRule claim is not a string") s.ClearCookie(w, CookieOpts{Path: cookiePath, Host: r.Host}) - s.RenderIndex(w, r, rule, httpStatusOnly) + s.RenderIndex(w, r, cr, rule, httpStatusOnly) return } if policyRule != rule.Hash() { lg.Debug("user originally passed with a different rule, issuing new challenge", "old", policyRule, "new", rule.Name) s.ClearCookie(w, CookieOpts{Path: cookiePath, Host: r.Host}) - s.RenderIndex(w, r, rule, httpStatusOnly) + s.RenderIndex(w, r, cr, rule, httpStatusOnly) return } @@ -346,7 +346,7 @@ func (s *Server) MakeChallenge(w http.ResponseWriter, r *http.Request) { } lg = lg.With("check_result", cr) - chall, err := s.challengeFor(r) + chall, err := s.issueChallenge(r.Context(), r, lg, cr, rule) if err != nil { lg.Error("failed to fetch or issue challenge", "err", err) w.WriteHeader(http.StatusInternalServerError) @@ -436,19 +436,21 @@ func (s *Server) PassChallenge(w http.ResponseWriter, r *http.Request) { } lg = lg.With("check_result", cr) - impl, ok := challenge.Get(rule.Challenge.Algorithm) + chall, err := s.getChallenge(r) + if err != nil { + lg.Error("getChallenge failed", "err", err) + s.respondWithError(w, r, fmt.Sprintf("%s: %s", localizer.T("internal_server_error"), rule.Challenge.Algorithm)) + return + } + + impl, ok := challenge.Get(chall.Method) if !ok { lg.Error("check failed", "err", err) s.respondWithError(w, r, fmt.Sprintf("%s: %s", localizer.T("internal_server_error"), rule.Challenge.Algorithm)) return } - chall, err := s.challengeFor(r) - if err != nil { - lg.Error("check failed", "err", err) - s.respondWithError(w, r, fmt.Sprintf("%s: %s", localizer.T("internal_server_error"), rule.Challenge.Algorithm)) - return - } + lg = lg.With("challenge", chall.ID) in := &challenge.ValidateInput{ Challenge: chall, @@ -466,9 +468,13 @@ func (s *Server) PassChallenge(w http.ResponseWriter, r *http.Request) { case errors.As(err, &cerr): switch { case errors.Is(err, challenge.ErrFailed): + lg.Error("challenge failed", "err", err) s.respondWithStatus(w, r, cerr.PublicReason, cerr.StatusCode) + return case errors.Is(err, challenge.ErrInvalidFormat), errors.Is(err, challenge.ErrMissingField): + lg.Error("invalid challenge format", "err", err) s.respondWithError(w, r, cerr.PublicReason) + return } } } diff --git a/lib/challenge/challenge.go b/lib/challenge/challenge.go index 4c975c8..1200e33 100644 --- a/lib/challenge/challenge.go +++ b/lib/challenge/challenge.go @@ -5,6 +5,7 @@ import "time" // Challenge is the metadata about a single challenge issuance. type Challenge struct { ID string `json:"id"` // UUID identifying the challenge + Method string `json:"method"` // Challenge method RandomData string `json:"randomData"` // The random data the client processes IssuedAt time.Time `json:"issuedAt"` // When the challenge was issued Metadata map[string]string `json:"metadata"` // Challenge metadata such as IP address and user agent diff --git a/lib/http.go b/lib/http.go index 9ee0847..ad1a244 100644 --- a/lib/http.go +++ b/lib/http.go @@ -111,7 +111,7 @@ func randomChance(n int) bool { return rand.Intn(n) == 0 } -func (s *Server) RenderIndex(w http.ResponseWriter, r *http.Request, rule *policy.Bot, returnHTTPStatusOnly bool) { +func (s *Server) RenderIndex(w http.ResponseWriter, r *http.Request, cr policy.CheckResult, rule *policy.Bot, returnHTTPStatusOnly bool) { localizer := localization.GetLocalizer(r) if returnHTTPStatusOnly { @@ -125,17 +125,20 @@ func (s *Server) RenderIndex(w http.ResponseWriter, r *http.Request, rule *polic if !strings.Contains(r.Header.Get("Accept-Encoding"), "gzip") && randomChance(64) { lg.Error("client was given a challenge but does not in fact support gzip compression") s.respondWithError(w, r, localizer.T("client_error_browser")) + return } challengesIssued.WithLabelValues("embedded").Add(1) - chall, err := s.challengeFor(r) + chall, err := s.issueChallenge(r.Context(), r, lg, cr, rule) if err != nil { - lg.Error("can't get challenge", "err", "err") + lg.Error("can't get challenge", "err", err) s.ClearCookie(w, CookieOpts{Name: anubis.TestCookieName, Host: r.Host}) s.respondWithError(w, r, fmt.Sprintf("%s: %s", localizer.T("internal_server_error"), rule.Challenge.Algorithm)) return } + lg = lg.With("challenge", chall.ID) + var ogTags map[string]string = nil if s.opts.OpenGraph.Enabled { var err error @@ -153,7 +156,7 @@ func (s *Server) RenderIndex(w http.ResponseWriter, r *http.Request, rule *polic Expiry: 30 * time.Minute, }) - impl, ok := challenge.Get(rule.Challenge.Algorithm) + impl, ok := challenge.Get(chall.Method) if !ok { lg.Error("check failed", "err", "can't get algorithm", "algorithm", rule.Challenge.Algorithm) s.ClearCookie(w, CookieOpts{Name: anubis.TestCookieName, Host: r.Host})