diff --git a/cmd/away.go b/cmd/away.go index 6455e99..95551d0 100644 --- a/cmd/away.go +++ b/cmd/away.go @@ -54,7 +54,8 @@ func main() { bindNetwork := flag.String("bind-network", "tcp", "network family to bind HTTP to, e.g. unix, tcp") socketMode := flag.String("socket-mode", "0770", "socket mode (permissions) for unix domain sockets.") - slogLevel := flag.String("slog-level", "INFO", "logging level (see https://pkg.go.dev/log/slog#hdr-Levels)") + slogLevel := flag.String("slog-level", "WARN", "logging level (see https://pkg.go.dev/log/slog#hdr-Levels)") + debug := flag.Bool("debug", false, "debug mode with logs and server timings") policyFile := flag.String("policy", "", "path to policy YAML file") challengeTemplate := flag.String("challenge-template", "anubis", "name or path of the challenge template to use (anubis, forgejo)") @@ -73,7 +74,7 @@ func main() { leveler.Set(programLevel) h := slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{ - AddSource: true, + AddSource: *debug, Level: leveler, }) slog.SetDefault(slog.New(h)) @@ -91,6 +92,7 @@ func main() { } state, err := lib.NewState(p, lib.StateSettings{ + Debug: *debug, PackagePath: "git.gammaspectra.live/git/go-away/cmd", ChallengeTemplate: *challengeTemplate, ChallengeTemplateTheme: *challengeTemplateTheme, diff --git a/lib/challenge.go b/lib/challenge.go index d8cbec0..a62629e 100644 --- a/lib/challenge.go +++ b/lib/challenge.go @@ -6,6 +6,7 @@ import ( "crypto/sha256" "encoding/binary" "errors" + "fmt" "github.com/go-jose/go-jose/v4" "github.com/go-jose/go-jose/v4/jwt" "github.com/tetratelabs/wazero" @@ -117,9 +118,9 @@ func (state *State) VerifyChallengeToken(name string, expectedKey []byte, w http } } } - if cookie == nil { - return false, err - } + } + if cookie == nil { + return false, err } token, err := jwt.ParseSigned(cookie.Value, []jose.SignatureAlgorithm{jose.EdDSA}) @@ -147,14 +148,20 @@ func (state *State) VerifyChallengeToken(name string, expectedKey []byte, w http return false, errors.New("key mismatch") } - if c.Verify != nil && rand.Float64() < c.VerifyProbability { - // random spot check - if ok, err := c.Verify(expectedKey, string(i.Result)); err != nil { - return false, err - } else if !ok { - return false, errors.New("failed challenge verification") + if c.Verify != nil { + if rand.Float64() < c.VerifyProbability { + // random spot check + if ok, err := c.Verify(expectedKey, string(i.Result)); err != nil { + return false, err + } else if !ok { + return false, errors.New("failed challenge verification") + } + r.Header.Set(fmt.Sprintf("X-Away-Challenge-%s-Verify", name), "FULL") + } else { + r.Header.Set(fmt.Sprintf("X-Away-Challenge-%s-Verify", name), "BRIEF") } } + r.Header.Set(fmt.Sprintf("X-Away-Challenge-%s-Verify", name), "CHECK") return true, nil } diff --git a/lib/http.go b/lib/http.go index e758411..18a884e 100644 --- a/lib/http.go +++ b/lib/http.go @@ -6,6 +6,7 @@ import ( "context" "crypto/rand" "encoding/base64" + "encoding/hex" "errors" "fmt" go_away "git.gammaspectra.live/git/go-away" @@ -13,12 +14,14 @@ import ( "git.gammaspectra.live/git/go-away/lib/policy" "github.com/google/cel-go/common/types" "html/template" + "log/slog" "maps" "net" "net/http" "net/http/httputil" "net/url" "path/filepath" + "strconv" "strings" "time" ) @@ -67,7 +70,7 @@ func initTemplate(name, data string) error { return nil } -func makeReverseProxy(target string) (http.Handler, error) { +func makeReverseProxy(target string) (*httputil.ReverseProxy, error) { u, err := url.Parse(target) if err != nil { return nil, fmt.Errorf("failed to parse target URL: %w", err) @@ -95,8 +98,9 @@ func makeReverseProxy(target string) (http.Handler, error) { return rp, nil } -func (state *State) challengePage(w http.ResponseWriter, status int, challenge string, params map[string]any) error { +func (state *State) challengePage(w http.ResponseWriter, id string, status int, challenge string, params map[string]any) error { input := make(map[string]any) + input["Id"] = id input["Random"] = cacheBust input["Challenge"] = challenge input["Path"] = state.UrlPath @@ -114,7 +118,7 @@ func (state *State) challengePage(w http.ResponseWriter, status int, challenge s err := templates["challenge-"+state.Settings.ChallengeTemplate+".gohtml"].Execute(buf, input) if err != nil { - _ = state.errorPage(w, http.StatusInternalServerError, err) + _ = state.errorPage(w, id, http.StatusInternalServerError, err) } else { w.WriteHeader(status) _, _ = w.Write(buf.Bytes()) @@ -122,12 +126,13 @@ func (state *State) challengePage(w http.ResponseWriter, status int, challenge s return nil } -func (state *State) errorPage(w http.ResponseWriter, status int, err error) error { +func (state *State) errorPage(w http.ResponseWriter, id string, status int, err error) error { w.Header().Set("Content-Type", "text/html; charset=utf-8") buf := bytes.NewBuffer(make([]byte, 0, 8192)) err2 := templates["challenge-"+state.Settings.ChallengeTemplate+".gohtml"].Execute(buf, map[string]any{ + "Id": id, "Random": cacheBust, "Error": err.Error(), "Path": state.UrlPath, @@ -145,8 +150,23 @@ func (state *State) errorPage(w http.ResponseWriter, status int, err error) erro return nil } -func (state *State) handleRequest(w http.ResponseWriter, r *http.Request) { +func (state *State) addTiming(w http.ResponseWriter, name, desc string, duration time.Duration) { + if state.Settings.Debug { + w.Header().Add("Server-Timing", fmt.Sprintf("%s;desc=%s;dur=%d", name, strconv.Quote(desc), duration.Milliseconds())) + } +} +func (state *State) getLogger(r *http.Request) *slog.Logger { + return slog.With( + "request_id", r.Header.Get("X-Away-Id"), + "remote_address", state.GetRequestAddress(r), + "user_agent", r.UserAgent(), + "host", r.Host, + "path", r.URL.Path, + ) +} + +func (state *State) handleRequest(w http.ResponseWriter, r *http.Request) { host := r.Host backend, ok := state.Backends[host] @@ -155,6 +175,10 @@ func (state *State) handleRequest(w http.ResponseWriter, r *http.Request) { return } + lg := state.getLogger(r) + + start := time.Now() + //TODO better matcher! combo ast? env := map[string]any{ "host": host, @@ -178,23 +202,55 @@ func (state *State) handleRequest(w http.ResponseWriter, r *http.Request) { }(), } + state.addTiming(w, "rule-env", "Setup the rule environment", time.Since(start)) + + var ( + ruleEvalDuration time.Duration + ) + + serve := func() { + state.addTiming(w, "rule-eval", "Evaluate access rules", ruleEvalDuration) + backend.ServeHTTP(w, r) + } + + fail := func(code int, err error) { + state.addTiming(w, "rule-eval", "Evaluate access rules", ruleEvalDuration) + _ = state.errorPage(w, r.Header.Get("X-Away-Id"), code, err) + } + + setAwayState := func(rule RuleState) { + r.Header.Set("X-Away-Rule", rule.Name) + r.Header.Set("X-Away-Hash", rule.Hash) + r.Header.Set("X-Away-Action", string(rule.Action)) + } + for _, rule := range state.Rules { // skip rules that have host match if rule.Host != nil && *rule.Host != host { continue } - if out, _, err := rule.Program.Eval(env); err != nil { - //TODO error + start = time.Now() + out, _, err := rule.Program.Eval(env) + ruleEvalDuration += time.Since(start) + + if err != nil { + fail(http.StatusInternalServerError, err) + lg.Error(err.Error(), "rule", rule.Name, "rule_hash", rule.Hash) panic(err) + return } else if out != nil && out.Type() == types.BoolType { if out.Equal(types.True) == types.True { switch rule.Action { default: panic(fmt.Errorf("unknown action %s", rule.Action)) case policy.RuleActionPASS: - backend.ServeHTTP(w, r) + lg.Debug("request passed", "rule", rule.Name, "rule_hash", rule.Hash) + setAwayState(rule) + serve() return case policy.RuleActionCHALLENGE, policy.RuleActionCHECK: + start = time.Now() + expiry := time.Now().UTC().Add(DefaultValidity).Round(DefaultValidity) for _, challengeName := range rule.Challenges { @@ -209,11 +265,14 @@ func (state *State) handleRequest(w http.ResponseWriter, r *http.Request) { goto nextRule } // we passed the challenge! - //TODO log? - backend.ServeHTTP(w, r) + + lg.Debug("request passed", "rule", rule.Name, "rule_hash", rule.Hash, "challenge", challengeName) + setAwayState(rule) + serve() return } } + state.addTiming(w, "challenge-token-check", "Verify client challenge tokens", time.Since(start)) // none matched, issue first challenge in priority for _, challengeName := range rule.Challenges { @@ -222,6 +281,7 @@ func (state *State) handleRequest(w http.ResponseWriter, r *http.Request) { result := c.Challenge(w, r, state.GetChallengeKeyForRequest(challengeName, expiry, r), expiry) switch result { case ChallengeResultStop: + lg.Info("request challenged", "rule", rule.Name, "rule_hash", rule.Hash, "challenge", challengeName) return case ChallengeResultContinue: continue @@ -230,7 +290,11 @@ func (state *State) handleRequest(w http.ResponseWriter, r *http.Request) { goto nextRule } // we pass the challenge early! - backend.ServeHTTP(w, r) + r.Header.Set(fmt.Sprintf("X-Away-Challenge-%s-Verify", challengeName), "PASS") + + lg.Debug("request passed", "rule", rule.Name, "rule_hash", rule.Hash, "challenge", challengeName) + setAwayState(rule) + serve() return } } else { @@ -238,13 +302,15 @@ func (state *State) handleRequest(w http.ResponseWriter, r *http.Request) { } } case policy.RuleActionDENY: + lg.Info("request denied", "rule", rule.Name, "rule_hash", rule.Hash) //TODO: config error code - _ = state.errorPage(w, http.StatusForbidden, fmt.Errorf("access denied: denied by administrative rule %s", rule.Hash)) + fail(http.StatusForbidden, fmt.Errorf("access denied: denied by administrative rule %s/%s", r.Header.Get("X-Away-Id"), rule.Hash)) return case policy.RuleActionBLOCK: + lg.Info("request blocked", "rule", rule.Name, "rule_hash", rule.Hash) //TODO: config error code //TODO: configure block - _ = state.errorPage(w, http.StatusForbidden, fmt.Errorf("access denied: blocked by administrative rule %s", rule.Hash)) + fail(http.StatusForbidden, fmt.Errorf("access denied: blocked by administrative rule %s/%s", r.Header.Get("X-Away-Id"), rule.Hash)) return } } @@ -253,7 +319,7 @@ func (state *State) handleRequest(w http.ResponseWriter, r *http.Request) { nextRule: } - backend.ServeHTTP(w, r) + serve() return } @@ -285,13 +351,25 @@ func (state *State) setupRoutes() error { key := state.GetChallengeKeyForRequest(challengeName, expiry, r) result := r.FormValue("result") - if ok, err := c.Verify(key, result); err != nil { + requestId, err := hex.DecodeString(r.FormValue("requestId")) + if err == nil { + r.Header.Set("X-Away-Id", hex.EncodeToString(requestId)) + } + + start := time.Now() + ok, err := c.Verify(key, result) + state.addTiming(w, "challenge-verify", "Verify client challenge", time.Since(start)) + + if err != nil { + state.getLogger(r).Error(fmt.Errorf("challenge error: %w", err).Error(), "challenge", challengeName, "redirect", r.FormValue("redirect")) return err } else if !ok { + state.getLogger(r).Warn("challenge failed", "challenge", challengeName, "redirect", r.FormValue("redirect")) ClearCookie(CookiePrefix+challengeName, w) - _ = state.errorPage(w, http.StatusForbidden, fmt.Errorf("access denied: failed challenge %s", challengeName)) + _ = state.errorPage(w, r.Header.Get("X-Away-Id"), http.StatusForbidden, fmt.Errorf("access denied: failed challenge %s", challengeName)) return nil } + state.getLogger(r).Info("challenge passed", "challenge", challengeName, "redirect", r.FormValue("redirect")) token, err := state.IssueChallengeToken(challengeName, key, []byte(result), expiry) if err != nil { @@ -305,7 +383,7 @@ func (state *State) setupRoutes() error { }() if err != nil { ClearCookie(CookiePrefix+challengeName, w) - _ = state.errorPage(w, http.StatusInternalServerError, err) + _ = state.errorPage(w, r.Header.Get("X-Away-Id"), http.StatusInternalServerError, err) return } }) diff --git a/lib/state.go b/lib/state.go index cfe3791..f14b37d 100644 --- a/lib/state.go +++ b/lib/state.go @@ -98,6 +98,7 @@ type ChallengeState struct { } type StateSettings struct { + Debug bool PackagePath string ChallengeTemplate string ChallengeTemplateTheme string @@ -120,6 +121,10 @@ func NewState(p policy.Policy, settings StateSettings) (state *State, err error) if err != nil { return nil, fmt.Errorf("backend %s: failed to make reverse proxy: %w", k, err) } + backend.ErrorHandler = func(w http.ResponseWriter, r *http.Request, err error) { + state.getLogger(r).Error(fmt.Errorf("backend %s error: %w", k, err).Error()) + _ = state.errorPage(w, r.Header.Get("X-Away-Id"), http.StatusBadGateway, err) + } state.Backends[k] = backend } @@ -166,7 +171,7 @@ func NewState(p policy.Policy, settings StateSettings) (state *State, err error) } } - slog.Debug("loaded network prefixes", "network", k, "count", ranger.Len()) + slog.Info("loaded network prefixes", "network", k, "count", ranger.Len()) state.Networks[k] = ranger } @@ -218,7 +223,6 @@ func NewState(p policy.Policy, settings StateSettings) (state *State, err error) expectedCookie := p.Parameters["http-cookie"] - //todo c.Challenge = func(w http.ResponseWriter, r *http.Request, key []byte, expiry time.Time) ChallengeResult { if expectedCookie != "" { if cookie, err := r.Cookie(expectedCookie); err != nil || cookie == nil { @@ -278,10 +282,11 @@ func NewState(p policy.Policy, settings StateSettings) (state *State, err error) values := make(url.Values) values.Set("result", hex.EncodeToString(key)) values.Set("redirect", r.URL.String()) + values.Set("requestId", r.Header.Get("X-Away-Id")) redirectUri.RawQuery = values.Encode() - _ = state.challengePage(w, http.StatusTeapot, "", map[string]any{ + _ = state.challengePage(w, r.Header.Get("X-Away-Id"), http.StatusTeapot, "", map[string]any{ "Meta": map[string]string{ "refresh": "0; url=" + redirectUri.String(), }, @@ -297,13 +302,14 @@ func NewState(p policy.Policy, settings StateSettings) (state *State, err error) values := make(url.Values) values.Set("result", hex.EncodeToString(key)) values.Set("redirect", r.URL.String()) + values.Set("requestId", r.Header.Get("X-Away-Id")) redirectUri.RawQuery = values.Encode() // self redirect! w.Header().Set("Refresh", "0; url="+redirectUri.String()) - _ = state.challengePage(w, http.StatusTeapot, "", nil) + _ = state.challengePage(w, r.Header.Get("X-Away-Id"), http.StatusTeapot, "", nil) return ChallengeResultStop } @@ -314,13 +320,14 @@ func NewState(p policy.Policy, settings StateSettings) (state *State, err error) values := make(url.Values) values.Set("result", hex.EncodeToString(key)) + values.Set("requestId", r.Header.Get("X-Away-Id")) redirectUri.RawQuery = values.Encode() // self redirect! w.Header().Set("Refresh", "2; url="+r.URL.String()) - _ = state.challengePage(w, http.StatusTeapot, "", map[string]any{ + _ = state.challengePage(w, r.Header.Get("X-Away-Id"), http.StatusTeapot, "", map[string]any{ "Tags": []template.HTML{ template.HTML(fmt.Sprintf("", redirectUri.String())), }, @@ -330,7 +337,7 @@ func NewState(p policy.Policy, settings StateSettings) (state *State, err error) } case "js": c.Challenge = func(w http.ResponseWriter, r *http.Request, key []byte, expiry time.Time) ChallengeResult { - _ = state.challengePage(w, http.StatusTeapot, challengeName, nil) + _ = state.challengePage(w, r.Header.Get("X-Away-Id"), http.StatusTeapot, challengeName, nil) return ChallengeResultStop } @@ -405,13 +412,20 @@ func NewState(p policy.Policy, settings StateSettings) (state *State, err error) key := state.GetChallengeKeyForRequest(challengeName, expiry, r) result := r.FormValue("result") + requestId, err := hex.DecodeString(r.FormValue("requestId")) + if err == nil { + r.Header.Set("X-Away-Id", hex.EncodeToString(requestId)) + } + if ok, err := c.Verify(key, result); err != nil { return err } else if !ok { + state.getLogger(r).Warn("challenge failed", "challenge", challengeName, "redirect", r.FormValue("redirect")) ClearCookie(CookiePrefix+challengeName, w) - _ = state.errorPage(w, http.StatusForbidden, fmt.Errorf("access denied: failed challenge %s", challengeName)) + _ = state.errorPage(w, r.Header.Get("X-Away-Id"), http.StatusForbidden, fmt.Errorf("access denied: failed challenge %s", challengeName)) return nil } + state.getLogger(r).Warn("challenge passed", "challenge", challengeName, "redirect", r.FormValue("redirect")) token, err := state.IssueChallengeToken(challengeName, key, []byte(result), expiry) if err != nil { @@ -435,7 +449,7 @@ func NewState(p policy.Policy, settings StateSettings) (state *State, err error) }() if err != nil { ClearCookie(CookiePrefix+challengeName, w) - _ = state.errorPage(w, http.StatusInternalServerError, err) + _ = state.errorPage(w, r.Header.Get("X-Away-Id"), http.StatusInternalServerError, err) return } }) @@ -478,7 +492,7 @@ func NewState(p policy.Policy, settings StateSettings) (state *State, err error) return nil }) if err != nil { - _ = state.errorPage(w, http.StatusInternalServerError, err) + _ = state.errorPage(w, r.Header.Get("X-Away-Id"), http.StatusInternalServerError, err) return } }) @@ -641,5 +655,10 @@ func NewState(p policy.Policy, settings StateSettings) (state *State, err error) } func (state *State) ServeHTTP(w http.ResponseWriter, r *http.Request) { + requestId := make([]byte, 16) + _, _ = rand.Read(requestId) + + r.Header.Set("X-Away-Id", hex.EncodeToString(requestId)) + state.Mux.ServeHTTP(w, r) } diff --git a/templates/challenge-anubis.gohtml b/templates/challenge-anubis.gohtml index 653a421..d42d1f4 100644 --- a/templates/challenge-anubis.gohtml +++ b/templates/challenge-anubis.gohtml @@ -177,6 +177,7 @@ Why am I seeing this?

You are seeing this because the administrator of this website has set up go-away to protect the server against the scourge of AI companies aggressively scraping websites. This can and does cause downtime for the websites, which makes their resources inaccessible for everyone.

Please note that some challenges requires the use of modern JavaScript features and some plugins may will disable. Please disable such plugins for this domain (for example, JShelter).

+

If you have any issues contact the administrator and provide this request id: {{ .Id }}