fix: a crawl whose store runs out of time still ends failed

The store keeps FinishTimeout, the final status write and the conga job
end get their own 30 s bound and prune its own store-sized bound, so the
row no longer stays running with the error lost until RecoverStale; adds
the code-only crawl.WithFinishTimeout seam.

quick-261104-xae, review WR-03.
This commit is contained in:
Jakub Zych
2026-11-05 00:22:07 +01:00
parent 2a288a9570
commit c71b58eea7
3 changed files with 114 additions and 15 deletions

View File

@@ -247,7 +247,7 @@ A crawl is a conga job (`golem15.seo.crawl`, one attempt) started from **Start c
**What it fetches.** `robots.txt`, the sitemap index at `/sitemap.xml` and its files (or a single urlset), then breadth-first from the home page and the sitemap addresses over same-host links, redirect targets, canonicals and hreflang alternates. Requests go through a `fetchguard` client limited to the site host and its `www` twin: HTTPS only, private and reserved addresses refused at dial time, redirects never followed (each `Location` is a new address checked again), the User-Agent `SummerCMS-SEO-Crawler/1 (+<site>)`. Links to other hosts, credentials in a URL and plain http are never fetched. A staging or local site served over http or on a private address needs `golem15.seo.crawl_trusted: true` in config (or `SUMMER_GOLEM15__SEO__CRAWL_TRUSTED`), which no setting or MCP call can set; trusted mode still fetches only the site host and its twin. robots.txt rules are read for the report, not obeyed.
**Limits.** Two requests at a time with the settings' pause between requests (default 250 ms), a 10 s timeout and a 5 MiB body cap per request, at most 1000 links read per page, and the settings' page limit (default 5000; a crawl that stops there is marked "limit reached"). Cancelling (**Cancel crawl**, `seo_cancel_crawl`) ends a queued crawl at once; a running crawl records the request (`cancel_requested` in the API and MCP answers, **Cancelling** in the list) and keeps running until its job stops between requests, then ends cancelled with what was fetched. Until then no other crawl starts (409 `crawls.already_running`) and the crawl cannot be deleted; a failed crawl keeps the pages and issues found before the failure and records the error. A crawl that reaches the job's time limit (`crawl.JobTimeout`, 6 h) ends failed with "the crawl reached its time limit of 6h" and keeps what it fetched: the final writes run on a context the job's cancellation cannot reach, bounded by `crawl.FinishTimeout` (10 min). A running crawl's job writes `heartbeat_at` every minute (`crawl.HeartbeatEvery`); a running crawl without a heartbeat for 10 minutes (`crawl.StaleAfter`, its job is gone, for example after a worker restart) is ended by the next start or delete (`crawl.RecoverStale`): failed with "the crawl job stopped without finishing (no heartbeat since …)", or cancelled when its cancel was requested. Every crawled address is keyed by its decoded path with the raw query (`classes.PathKey`, the form of the resolver, the descriptors and the SEO entries; a path that does not decode to valid text, or holds `%` or `?`, keeps its encoded form) and requested percent-encoded (`classes.EscapeKeyPath`), so a non-ASCII address matches its CMS record, its focus keyphrase and its links in the E10 widget, written either way. The crawler writes only its own tables (`golem15_seo_crawls`, `golem15_seo_crawl_pages`, `golem15_seo_crawl_links`, `golem15_seo_issues`); crawls beyond the settings' "Crawls kept" are deleted with their pages, links and issues.
**Limits.** Two requests at a time with the settings' pause between requests (default 250 ms), a 10 s timeout and a 5 MiB body cap per request, at most 1000 links read per page, and the settings' page limit (default 5000; a crawl that stops there is marked "limit reached"). Cancelling (**Cancel crawl**, `seo_cancel_crawl`) ends a queued crawl at once; a running crawl records the request (`cancel_requested` in the API and MCP answers, **Cancelling** in the list) and keeps running until its job stops between requests, then ends cancelled with what was fetched. Until then no other crawl starts (409 `crawls.already_running`) and the crawl cannot be deleted; a failed crawl keeps the pages and issues found before the failure and records the error. A crawl that reaches the job's time limit (`crawl.JobTimeout`, 6 h) ends failed with "the crawl reached its time limit of 6h" and keeps what it fetched: storing what it found runs on a context the job's cancellation cannot reach, bounded by `crawl.FinishTimeout` (10 min), and the crawl's final status is then written on a 30-second bound of its own, so a crawl whose results take longer to store still ends at once, failed with "storing the crawl results took longer than 10m0s: …". A running crawl's job writes `heartbeat_at` every minute (`crawl.HeartbeatEvery`); a running crawl without a heartbeat for 10 minutes (`crawl.StaleAfter`, its job is gone, for example after a worker restart) is ended by the next start or delete (`crawl.RecoverStale`): failed with "the crawl job stopped without finishing (no heartbeat since …)", or cancelled when its cancel was requested. Every crawled address is keyed by its decoded path with the raw query (`classes.PathKey`, the form of the resolver, the descriptors and the SEO entries; a path that does not decode to valid text, or holds `%` or `?`, keeps its encoded form) and requested percent-encoded (`classes.EscapeKeyPath`), so a non-ASCII address matches its CMS record, its focus keyphrase and its links in the E10 widget, written either way. The crawler writes only its own tables (`golem15_seo_crawls`, `golem15_seo_crawl_pages`, `golem15_seo_crawl_links`, `golem15_seo_issues`); crawls beyond the settings' "Crawls kept" are deleted with their pages, links and issues.
**Checks** (kind, severity): `page_status` (error), `sitemap_error` (error), `sitemap_noindex` (error), `sitemap_blocked` (error), `sitemap_missing` (notice), `broken_link` (error, with the linking pages), `redirected_link` (notice), `canonical_missing` (warning), `canonical_error` (error), `missing_title` and `duplicate_title` (warning), `missing_description` and `duplicate_description` (notice), `h1_missing` and `h1_multiple` (error), `heading_skipped` and `heading_empty` (warning), `h1_title_mismatch` (notice), `jsonld_invalid` (error), `jsonld_multiple` (warning), `jsonld_required` (error) and `jsonld_recommended` (notice) from the same rules as the structured data preview (`schema.Validate`; FAQPage and other types without Google rules find nothing), `hreflang_reciprocal` (warning), `hreflang_error` (error), `generic_anchor` (warning, the settings' generic link texts, whole text, any case), `image_alt` (warning: an `<img>` without `alt`; `alt=""` is decorative), `image_size` and `featured_lazy` (notice), `content_js` (warning) and `orphan_page` (warning: an indexable sitemap page no crawled page links to, with up to 10 pages whose text mentions its title or focus keyphrase). The CMS-data checks run at the end of every crawl (and when the list is opened before any crawl) and are stored with the crawl's issues as source `cms`; a CMS issue the crawl found too is stored once.
@@ -343,6 +343,7 @@ The element bundle (`assets/dist/seo.js` and `seo.css`) is built from `assets/sr
| `crawl.Start`, `crawl.Run`, `crawl.Cancel`, `crawl.Recheck`, `crawl.Ignore`, `crawl.Unignore`, `crawl.DeleteCrawls`, `crawl.Prune`, `crawl.Current`, `crawl.ScheduledDue` | Starting, running and cancelling a crawl, checking an address again, ignores, deletes and the schedule's decision. |
| `crawl.CrawlArgs`, `crawl.CrawlKind` | The crawl job's arguments and River kind `golem15.seo.crawl`. |
| `crawl.Renderer`, `crawl.WithRenderer`, `crawl.NewRenderer`, `crawl.RenderMax` | The rendered comparison's seam, its code-only test override, the guarded Chrome renderer built from config and the configured page cap. |
| `crawl.WithFinishTimeout` | A code-only test override of `crawl.FinishTimeout`, like `crawl.WithRenderer`. |
| `crawl.ChromePathConfigKey`, `crawl.RenderMaxConfigKey`, `crawl.TrustedConfigKey`, `crawl.RenderTimeout`, `crawl.MaxDOM` | The renderer's and crawler's config keys and the per-page render limits. |
| `classes.IssueImageAlt`, `classes.IssueH1InContent` | The CMS-data kinds from the content descriptors (`Service.ContentIssues`). |
| `classes.Service` | The single entry point for SEO reads and writes: `SaveRecord`, `Record` (history), `GenerateEntries`, `EnqueueGenerate`, `RecordDeleted`, `RecordCreated`, `Resolver`, `SiteURL`, `Staging`. Redirects: `SaveRedirect`, `DeleteRedirect`, `CheckRedirect`, `AddressChanges`, `AddressChanged`. 404 log: `ReportNotFound`, `ResolveNotFound`. robots.txt: `ServedFile`, `TestRobots`, `BlockedNoindex`, `SaveRobots`. `VerificationFileByName`. Management: `FindOwner`, `SetURLSEO`, `SaveRule`, `DeleteRule`, `SaveSettings`, `DeleteNotFound`, `Issues`. |

View File

@@ -45,7 +45,8 @@ func (CrawlArgs) Kind() string { return CrawlKind }
// The crawl job's time bounds (P33-60). JobTimeout is the job's deadline;
// FinishTimeout bounds storing what a crawl found, on a context the job's
// cancellation cannot reach; the job writes heartbeat_at every
// cancellation cannot reach; the final status is then written on a
// 30-second bound of its own. The job writes heartbeat_at every
// HeartbeatEvery, and a running crawl without a heartbeat for StaleAfter
// is ended by the next Start or delete (RecoverStale).
const (
@@ -58,6 +59,33 @@ const (
// heartbeatWrite bounds one heartbeat update.
const heartbeatWrite = 10 * time.Second
// finalWriteTimeout bounds a crawl's final status write and the end of its
// conga record, on a context of their own, so a store that used up its
// FinishTimeout bound still ends the crawl (33-REVIEW-GAPFIX WR-03).
const finalWriteTimeout = 30 * time.Second
type finishTimeoutKey struct{}
// WithFinishTimeout returns a context whose crawls bound storing their
// results by d instead of FinishTimeout. It is the test seam of the store
// bound, settable only from Go code (like WithRenderer and
// fetchguard.WithTransport): no config key, setting, request or MCP call
// reaches it.
func WithFinishTimeout(ctx context.Context, d time.Duration) context.Context {
return context.WithValue(ctx, finishTimeoutKey{}, d)
}
// finishTimeoutFrom returns the store bound of ctx: its WithFinishTimeout
// value when that is positive, else FinishTimeout.
func finishTimeoutFrom(ctx context.Context) time.Duration {
if ctx != nil {
if d, ok := ctx.Value(finishTimeoutKey{}).(time.Duration); ok && d > 0 {
return d
}
}
return FinishTimeout
}
// The crawl limits used until the Site audit settings say otherwise.
const (
DefaultMaxPages = 5000
@@ -194,8 +222,10 @@ func LoadCrawl(db *gorm.DB, id uint) (models.Crawl, error) {
//
// The job's context ends on a cancel (River cancels a running job's
// context) or at the job timeout; what was fetched is then stored on a
// context detached from it with its own FinishTimeout bound, so a
// cancelled or timed-out crawl keeps its results and never stays running.
// context detached from it with its own FinishTimeout bound, and the final
// status is written on another detached context bounded by
// finalWriteTimeout, so a cancelled or timed-out crawl keeps its results
// and a crawl whose store ran out of time still ends: none stays running.
// While it runs, the job writes heartbeat_at every HeartbeatEvery.
func Run(ctx context.Context, svc *classes.Service, id uint) error {
gdb, err := svc.GormDB()
@@ -222,9 +252,7 @@ func Run(ctx context.Context, svc *classes.Service, id uint) error {
stop := heartbeat(ctx, gdb, id)
defer stop()
res, runErr := run(ctx, svc, db, row)
fctx, cancel := context.WithTimeout(context.WithoutCancel(ctx), FinishTimeout)
defer cancel()
return finish(fctx, svc, gdb.WithContext(fctx), row, res, runErr, ctx.Err())
return finish(context.WithoutCancel(ctx), svc, gdb, row, res, runErr, ctx.Err(), finishTimeoutFrom(ctx))
}
// heartbeat writes the crawl's heartbeat_at every HeartbeatEvery until the
@@ -354,11 +382,19 @@ func finalStatus(requested bool, res *Result, runErr, ctxErr error) (string, str
return models.CrawlFinished, ""
}
// finish stores what a crawl found and writes its final state. ctx is the
// detached, bounded context of Run, ctxErr the job context's error (nil
// while it was alive). A LoadLimits failure falls back to the default
// limits.
func finish(ctx context.Context, svc *classes.Service, db *gorm.DB, row models.Crawl, res *Result, runErr, ctxErr error) error {
// finish stores what a crawl found and writes its final state. parent is
// Run's context detached from the job's cancellation, gdb the undecorated
// database, ctxErr the job context's error (nil while it was alive). The
// cancel check, the limits and the store run on a context bounded by
// storeBound; a store that runs past it fails the crawl with an error that
// names the bound and the store error. The final status write
// and the end of the conga record then run on a fresh context bounded by
// finalWriteTimeout, and Prune on one of its own. A LoadLimits failure
// falls back to the default limits.
func finish(parent context.Context, svc *classes.Service, gdb *gorm.DB, row models.Crawl, res *Result, runErr, ctxErr error, storeBound time.Duration) error {
storeCtx, cancelStore := context.WithTimeout(parent, storeBound)
defer cancelStore()
db := gdb.WithContext(storeCtx)
status, errText := finalStatus(cancelRequested(db, row.ID), res, runErr, ctxErr)
limits, err := LoadLimits(db)
if err != nil {
@@ -384,9 +420,14 @@ func finish(ctx context.Context, svc *classes.Service, db *gorm.DB, row models.C
id := row.ID
return SaveIssues(tx, &id, findings, cms)
}
if err := lagoon.Transaction(ctx, db, store); err != nil {
if err := lagoon.Transaction(storeCtx, db, store); err != nil {
status, errText = models.CrawlFailed, err.Error()
if errors.Is(storeCtx.Err(), context.DeadlineExceeded) {
errText = "storing the crawl results took longer than " + storeBound.String() + ": " + err.Error()
}
}
ctx, cancelWrite := context.WithTimeout(parent, finalWriteTimeout)
defer cancelWrite()
updates := map[string]any{"status": status, "error": errText, "finished_at": time.Now().UTC()}
if res != nil {
updates["pages"] = len(res.Order)
@@ -395,7 +436,7 @@ func finish(ctx context.Context, svc *classes.Service, db *gorm.DB, row models.C
updates["render_pages"] = res.Render.Pages
updates["render_note"] = res.Render.Note
}
if err := db.Model(&models.Crawl{}).Where("id = ?", row.ID).Updates(updates).Error; err != nil {
if err := gdb.WithContext(ctx).Model(&models.Crawl{}).Where("id = ?", row.ID).Updates(updates).Error; err != nil {
return err
}
if m, err := conga.From(svc.App()); err == nil && row.JobID != nil {
@@ -412,7 +453,12 @@ func finish(ctx context.Context, svc *classes.Service, db *gorm.DB, row models.C
if status == models.CrawlFailed {
pluginLog.Warn("golem15.seo: crawl failed", "crawl", row.ID, "error", errText)
}
if err := Prune(db, limits.Keep); err != nil {
// Prune deletes old crawls with their pages and links, so it keeps a
// store-sized bound; it runs after the final state is written, so it
// never holds a crawl running.
pruneCtx, cancelPrune := context.WithTimeout(parent, storeBound)
defer cancelPrune()
if err := Prune(gdb.WithContext(pruneCtx), limits.Keep); err != nil {
pluginLog.Warn("golem15.seo: prune crawls", "error", err)
}
return nil

View File

@@ -250,6 +250,58 @@ func TestCrawlTimeout(t *testing.T) {
env.startCrawl(t, token)
}
// TestCrawlStoreTimeout pins 33-REVIEW-GAPFIX WR-03: a crawl whose
// result store runs past its bound (crawl.WithFinishTimeout here, the
// 10-minute FinishTimeout in production) ends at once, failed with the
// store error and finished_at, on a final write of its own; the job
// answers nil and a later Start succeeds.
func TestCrawlStoreTimeout(t *testing.T) {
env := bootCrawlEnv(t)
token := env.admin(t, true)
site := newFakeSite()
site.sitemap("/a")
site.plant(doc{path: "/", title: "Home"}, doc{path: "/a", title: "Page a"})
id := env.startCrawl(t, token)
// The store's first write (SavePages' insert of the pages) waits on
// this lock until the row has left running.
lock := env.db.Begin()
if lock.Error != nil {
t.Fatal(lock.Error)
}
var unlockOnce sync.Once
unlock := func() { unlockOnce.Do(func() { _ = lock.Rollback().Error }) }
t.Cleanup(unlock)
if err := lock.Exec(`LOCK TABLE golem15_seo_crawl_pages IN SHARE MODE`).Error; err != nil {
t.Fatal(err)
}
ctx := crawl.WithFinishTimeout(fetchguard.WithTransport(t.Context(), site), 2*time.Second)
done := env.runCrawlAsync(t, ctx, id)
deadline := time.Now().Add(20 * time.Second)
row := env.crawlRow(t, id)
for row.Status == models.CrawlQueued || row.Status == models.CrawlRunning {
if time.Now().After(deadline) {
unlock()
t.Fatalf("the crawl is still %s 20 s after its store bound: %+v", row.Status, row)
}
time.Sleep(100 * time.Millisecond)
row = env.crawlRow(t, id)
}
unlock()
if row.Status != models.CrawlFailed || !strings.Contains(row.Error, "storing the crawl results took longer than 2s") ||
strings.Contains(row.Error, "time limit") || row.FinishedAt == nil {
t.Fatalf("row after the store timeout = %+v", row)
}
if err := waitJob(t, done); err != nil {
t.Fatalf("the job answered %v", err)
}
if pages := env.storedPages(t, id); len(pages) != 0 {
t.Fatalf("stored pages = %v, want none (the store rolled back)", pages)
}
env.startCrawl(t, token)
}
// TestCrawlStaleRecovery pins P33-60: a running crawl whose heartbeat is
// older than StaleAfter is ended by the next Start (failed with the
// no-heartbeat error, or cancelled when its cancel was requested), which