diff --git a/internal/config/config.go b/internal/config/config.go index c6e1ec1..2e85641 100644 --- a/internal/config/config.go +++ b/internal/config/config.go @@ -50,6 +50,16 @@ type Config struct { // can read this environment can restart it, which is true of anybody with the // host anyway. It is never sent to a browser: the settings page is told only // whether it is set. + // GmailSyncBudget bounds one "fetch now", well under whatever proxy sits in + // front of this server. Configurable so a test can prove the budget is applied + // without spending the real one on every run. + GmailSyncBudget time.Duration + + // GmailEndpoints redirects the Gmail calls at a server the tests control. Empty + // in production, where it means Google. + GmailTokenURL string + GmailAPIURL string + PanelURL string PanelToken string PanelServerID string @@ -85,6 +95,7 @@ func Load() (*Config, error) { Dev: envBool("VERDANDE_DEV", false), GmailClientID: env("VERDANDE_GMAIL_CLIENT_ID", ""), + GmailSyncBudget: 25 * time.Second, PanelURL: strings.TrimSuffix(env("VERDANDE_PANEL_URL", ""), "/"), PanelToken: env("VERDANDE_PANEL_TOKEN", ""), PanelServerID: env("VERDANDE_PANEL_SERVER_ID", ""), diff --git a/internal/gmail/gmail.go b/internal/gmail/gmail.go index b62515e..a93613d 100644 --- a/internal/gmail/gmail.go +++ b/internal/gmail/gmail.go @@ -25,20 +25,50 @@ import ( ) const ( - authEndpoint = "https://accounts.google.com/o/oauth2/v2/auth" - tokenEndpoint = "https://oauth2.googleapis.com/token" - apiBase = "https://gmail.googleapis.com/gmail/v1" + authEndpoint = "https://accounts.google.com/o/oauth2/v2/auth" + defaultTokenEndpoint = "https://oauth2.googleapis.com/token" + defaultAPIBase = "https://gmail.googleapis.com/gmail/v1" // Read-only, and only mail. Not profile, not contacts, not send. Scope = "https://www.googleapis.com/auth/gmail.readonly" ) +// Endpoints is where Google is. +// +// A field rather than a constant so a test can point it at a server it controls. +// There is no other way to exercise what happens when Gmail is slow or refuses — +// and "the sync comes back before whatever sits in front of this server gives up +// on it" is exactly the kind of promise worth a test and impossible to make +// against the real thing. +// +// The zero value is Google, so nothing outside a test has to know it exists. +type Endpoints struct { + Token string + API string +} + +func (e Endpoints) token() string { + if e.Token != "" { + return e.Token + } + return defaultTokenEndpoint +} + +func (e Endpoints) api() string { + if e.API != "" { + return e.API + } + return defaultAPIBase +} + // Config is the OAuth client the operator registered in Google Cloud. It belongs to // the instance rather than to a person: one registration, any number of users. type Config struct { ClientID string ClientSecret string RedirectURL string + // Endpoints is Google unless a test says otherwise. + Endpoints Endpoints } func (c Config) Configured() bool { @@ -128,7 +158,7 @@ func (c Config) Refresh(ctx context.Context, refreshToken string) (Token, error) } func (c Config) token(ctx context.Context, form url.Values) (Token, error) { - req, err := http.NewRequestWithContext(ctx, http.MethodPost, tokenEndpoint, + req, err := http.NewRequestWithContext(ctx, http.MethodPost, c.Endpoints.token(), strings.NewReader(form.Encode())) if err != nil { return Token{}, err @@ -171,6 +201,7 @@ func (c Config) token(ctx context.Context, form url.Values) (Token, error) { type Client struct { accessToken string + endpoints Endpoints http *http.Client } @@ -178,6 +209,12 @@ func NewClient(accessToken string) *Client { return &Client{accessToken: accessToken, http: &http.Client{Timeout: 30 * time.Second}} } +// At points the client at another server. Tests only; the zero value is Google. +func (c *Client) At(e Endpoints) *Client { + c.endpoints = e + return c +} + // Message is the part of a Gmail message a task is made from. type Message struct { ID string @@ -196,7 +233,7 @@ func (c *Client) Profile(ctx context.Context) (string, error) { var parsed struct { EmailAddress string `json:"emailAddress"` } - if err := c.get(ctx, apiBase+"/users/me/profile", &parsed); err != nil { + if err := c.get(ctx, c.endpoints.api()+"/users/me/profile", &parsed); err != nil { return "", err } return parsed.EmailAddress, nil @@ -220,7 +257,7 @@ func (c *Client) List(ctx context.Context, query string, max int) ([]string, err ID string `json:"id"` } `json:"messages"` } - if err := c.get(ctx, apiBase+"/users/me/messages?"+v.Encode(), &parsed); err != nil { + if err := c.get(ctx, c.endpoints.api()+"/users/me/messages?"+v.Encode(), &parsed); err != nil { return nil, err } @@ -251,7 +288,7 @@ func (c *Client) Get(ctx context.Context, id string) (Message, error) { } `json:"headers"` } `json:"payload"` } - if err := c.get(ctx, apiBase+"/users/me/messages/"+url.PathEscape(id)+"?"+v.Encode(), &parsed); err != nil { + if err := c.get(ctx, c.endpoints.api()+"/users/me/messages/"+url.PathEscape(id)+"?"+v.Encode(), &parsed); err != nil { return Message{}, err } diff --git a/internal/httpapi/gmail_handlers.go b/internal/httpapi/gmail_handlers.go index c1df767..a45babe 100644 --- a/internal/httpapi/gmail_handlers.go +++ b/internal/httpapi/gmail_handlers.go @@ -2,6 +2,7 @@ package httpapi import ( "context" + "errors" "net/http" "strings" "time" @@ -10,6 +11,11 @@ import ( "github.com/kristianwind/verdande/internal/store" ) +// defaultGmailSyncBudget bounds one "fetch now" when nothing else says otherwise. +// Well under the hundred seconds a proxy is willing to wait, so this server is the +// one that answers a slow mailbox. +const defaultGmailSyncBudget = 25 * time.Second + // gmailConfig is the OAuth client this instance authorises with. // // The environment wins when it is set. A value in the environment is a deliberate @@ -17,11 +23,20 @@ import ( // applied on every recreate — and a form that could quietly override it would make // the manifest a lie. The stored pair is for the ordinary case, where nobody wants // to redeploy a container to paste a client id. +// gmailClient is the API client, pointed wherever the config says Google is. +func (s *Server) gmailClient(accessToken string) *gmail.Client { + return gmail.NewClient(accessToken).At(gmail.Endpoints{ + Token: s.cfg.GmailTokenURL, API: s.cfg.GmailAPIURL, + }) +} + func (s *Server) gmailConfig(ctx context.Context) gmail.Config { + endpoints := gmail.Endpoints{Token: s.cfg.GmailTokenURL, API: s.cfg.GmailAPIURL} cfg := gmail.Config{ ClientID: s.cfg.GmailClientID, ClientSecret: s.cfg.GmailClientSecret, RedirectURL: s.cfg.GmailRedirectURL(), + Endpoints: endpoints, } if cfg.ClientID != "" && cfg.ClientSecret != "" { return cfg @@ -153,7 +168,7 @@ func (s *Server) handleGmailCallback(w http.ResponseWriter, r *http.Request) { // Best effort: a mailbox that connects but cannot name itself is still // connected, and the status endpoint asks again when it finds no address — // so this failing is a delay rather than a dead end. - email, err := gmail.NewClient(token.AccessToken).Profile(r.Context()) + email, err := s.gmailClient(token.AccessToken).Profile(r.Context()) if err != nil { s.log.Warn("gmail profile", "err", err) } @@ -185,8 +200,35 @@ func (s *Server) handleGmailCallback(w http.ResponseWriter, r *http.Request) { func (s *Server) handleGmailSyncNow(w http.ResponseWriter, r *http.Request) { user := userFrom(r.Context()) - created, err := s.SyncGmail(r.Context(), user) + // A budget of its own, well under what sits in front of this server. + // + // The sync fetches up to twenty-five messages one at a time, each with its own + // thirty-second timeout — so a slow mailbox can hold the request open for + // minutes. Cloudflare gives up at a hundred seconds and answers with its own + // 502 page, which is HTML: the browser gets no JSON, no error code and no + // message, and shows "something went wrong". Nothing reaches the error log + // either, because this handler never returned. + // + // Whatever was created by the deadline is kept: every task is committed as it + // is made, so a short budget is a shorter run rather than a lost one. The + // background job keeps the full one; it has nobody waiting. + // An unset budget is not a budget of nothing: a zero here would expire the + // context before the first call and make every sync a silent no-op. + budget := s.cfg.GmailSyncBudget + if budget <= 0 { + budget = defaultGmailSyncBudget + } + ctx, cancel := context.WithTimeout(r.Context(), budget) + defer cancel() + + created, err := s.SyncGmail(ctx, user) if err != nil { + if errors.Is(err, context.DeadlineExceeded) { + // Not a failure: the mailbox is slow or busy, some tasks were made, and + // the rest arrive on the next run ten minutes from now. + writeJSON(w, http.StatusOK, map[string]any{"created": created, "partial": true}) + return + } s.upstream(w, r, CodeGmailFailed, "sync gmail", err) return } @@ -232,7 +274,7 @@ func (s *Server) SyncGmail(ctx context.Context, user *store.User) (int, error) { } } - client := gmail.NewClient(access) + client := s.gmailClient(access) ids, err := client.List(ctx, query, 25) if err != nil { if err == gmail.ErrUnauthorized { @@ -272,6 +314,11 @@ func (s *Server) SyncGmail(ctx context.Context, user *store.User) (int, error) { if seen[id] { continue } + // A spent budget ends the run rather than turning into twenty-five failed + // fetches logged one at a time. + if ctx.Err() != nil { + return created, ctx.Err() + } msg, err := client.Get(ctx, id) if err != nil { s.log.Warn("gmail get message", "err", err, "id", id) @@ -454,7 +501,7 @@ func (s *Server) gmailProfile(ctx context.Context, user *store.User, settings ma settings["expires_at"] = token.ExpiresAt.Unix() } - email, err := gmail.NewClient(access).Profile(ctx) + email, err := s.gmailClient(access).Profile(ctx) if err != nil { return "", err } diff --git a/internal/httpapi/gmail_test.go b/internal/httpapi/gmail_test.go index 74ed08d..768f024 100644 --- a/internal/httpapi/gmail_test.go +++ b/internal/httpapi/gmail_test.go @@ -3,7 +3,9 @@ package httpapi import ( "net/http" "net/http/httptest" + "net/url" "testing" + "time" "github.com/kristianwind/verdande/internal/config" ) @@ -26,6 +28,8 @@ func TestAGmailFailureSaysWhatGmailSaidAndIsRecorded(t *testing.T) { ts := newTestServerWith(t, func(cfg *config.Config) { cfg.GmailClientID = "test-client" cfg.GmailClientSecret = "test-secret" + cfg.GmailTokenURL = google.URL + "/token" + cfg.GmailAPIURL = google.URL }) ts.bootstrap(t) @@ -68,3 +72,88 @@ func TestAGmailFailureSaysWhatGmailSaidAndIsRecorded(t *testing.T) { t.Errorf("status = %v, want 502", row["status"]) } } + +// A slow mailbox must not hold the request open until something in front of this +// server gives up on it. +// +// This is what was actually happening in production: each Gmail call has its own +// thirty-second timeout, and the sync makes up to twenty-five of them one after the +// other. Cloudflare stopped waiting at a hundred seconds and answered with its own +// 502 page — HTML, so the browser got no code, no message and no error-log row, and +// showed "something went wrong". The handler had never returned. +func TestASlowMailboxDoesNotHangTheRequest(t *testing.T) { + // A Gmail that never answers. + blocked := make(chan struct{}) + defer close(blocked) + google := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + select { + case <-blocked: + case <-r.Context().Done(): + } + })) + defer google.Close() + + ts := newTestServerWith(t, func(cfg *config.Config) { + cfg.GmailClientID = "test-client" + cfg.GmailClientSecret = "test-secret" + cfg.GmailTokenURL = google.URL + "/token" + cfg.GmailAPIURL = google.URL + // A second rather than the real twenty-five: what is being tested is that a + // budget is applied at all, and spending the production one on every run + // would put half a minute into the suite to learn the same thing. + cfg.GmailSyncBudget = time.Second + }) + ts.bootstrap(t) + + user, err := ts.db.UserByEmail(t.Context(), "kristian@example.dk") + if err != nil { + t.Fatal(err) + } + // A token that has not expired, so the run goes straight to the message list + // rather than stopping at a refresh. + if err := ts.db.SetUserSettings(t.Context(), user.ID, "gmail", map[string]any{ + "refresh_token": "r", "access_token": "a", "trigger": "starred", + "expires_at": time.Now().Add(time.Hour).Unix(), + }); err != nil { + t.Fatal(err) + } + + // Its own client, because the shared one gives up after ten seconds — which is + // shorter than the budget being tested and would prove nothing either way. + req, _ := http.NewRequest("POST", ts.URL+"/api/v1/gmail/sync", nil) + req.Header.Set("Sec-Fetch-Site", "same-origin") + for _, c := range ts.client.Jar.Cookies(mustParse(t, ts.URL)) { + req.AddCookie(c) + } + + started := time.Now() + resp, err := (&http.Client{Timeout: 90 * time.Second}).Do(req) + if err != nil { + t.Fatalf("the request never came back (%v after %s); the sync has no budget of "+ + "its own, and whatever sits in front of this server answers for it", + err, time.Since(started).Round(time.Second)) + } + defer resp.Body.Close() + took := time.Since(started) + + // Cloudflare stops waiting at a hundred seconds. Anything close to that is the + // bug, whatever status eventually arrives. + // Comfortably over the one-second budget and far under any proxy's patience. + if took > 10*time.Second { + t.Errorf("the sync took %s; the budget is not being applied", + took.Round(time.Second)) + } + if resp.StatusCode >= 500 && resp.StatusCode != http.StatusBadGateway { + t.Errorf("status %d — a slow mailbox is not this server breaking", resp.StatusCode) + } + t.Logf("came back in %s with %d", took.Round(time.Millisecond), resp.StatusCode) +} + +func mustParse(t *testing.T, raw string) *url.URL { + t.Helper() + u, err := url.Parse(raw) + if err != nil { + t.Fatal(err) + } + return u +}