Skip to content

Commit ebb9c10

Browse files
authored
Bulk-ingest resilience: stop retrying deterministic failures; stabilize local storage root (HAL-321) (#48)
* queue: add PermanentError so deterministic failures stop retrying A handler can now return queue.Permanent(err) to mark a failure as non-retryable. The River backend translates it to river.JobCancel, which dead-letters the job immediately instead of burning the full retry budget on an input that can never succeed. Transient failures stay ordinary errors and keep retrying. Fixes the HAL-321 symptom where an encrypted/malformed PDF was retried 5x, interleaving confusing 'object not found' errors into its history. * ingest: classify deterministic parse failures as permanent parse() now splits failures: a not-yet-visible source and a parse timeout stay transient (retry can recover them under load); an encrypted/malformed/no-text document is wrapped queue.Permanent so the queue cancels it. fail() marks a permanent failure as terminal immediately, regardless of attempt number, so a cancelled doc no longer wedges in 'parsing' forever. * storage: pin local root to absolute + self-diagnosing not-found NewLocal resolves its root with filepath.Abs so a relative default (./data/documents) can't resolve against a different working directory after an engine restart while River still holds jobs for earlier uploads — the path drift that made a source 'not found' though it was on disk. Get's not-found error now carries the resolved path, and the engine logs the absolute root at boot (also where to point a Defender exclusion).
1 parent b81db7e commit ebb9c10

8 files changed

Lines changed: 288 additions & 12 deletions

File tree

cmd/engine/main.go

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -96,6 +96,14 @@ func run() error {
9696
if err != nil {
9797
return fmt.Errorf("init storage: %w", err)
9898
}
99+
// Log the resolved storage location at boot. For the local driver this is
100+
// the absolute root every source/section object is read from and written
101+
// to — the single most useful fact when diagnosing an "object not found",
102+
// and the place to point a Windows Defender exclusion so antivirus scans of
103+
// freshly-written PDFs don't transiently hide them from the ingest worker.
104+
if local, ok := store.(*storage.Local); ok {
105+
logger.Info("storage: local root resolved", "root", local.Root())
106+
}
99107

100108
q, err := buildQueue(cfg.Queue, cfg.Database.URL)
101109
if err != nil {

pkg/ingest/ingest.go

Lines changed: 47 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -566,10 +566,44 @@ func runParallelStages(ctx context.Context, summarizeFn, hydeFn func(context.Con
566566
func (p *Pipeline) parse(ctx context.Context, parsers *parser.Registry, pl Payload) (*parser.ParsedDoc, error) {
567567
rc, _, err := getSourceWithRetry(ctx, p.Storage, pl.SourceRef)
568568
if err != nil {
569+
// A not-yet-visible source is transient (the upload's fsync'd bytes can
570+
// briefly read back as ErrNotFound under heavy concurrent ingestion, or
571+
// while antivirus scans a freshly-written file), so it is returned as an
572+
// ordinary, retryable error — never permanent.
569573
return nil, fmt.Errorf("fetch source: %w", err)
570574
}
571575
defer func() { _ = rc.Close() }() // best-effort close
572-
return parsers.Parse(ctx, pl.ContentType, pl.Filename, rc)
576+
577+
parsed, perr := parsers.Parse(ctx, pl.ContentType, pl.Filename, rc)
578+
if perr != nil {
579+
// Classify the failure so the queue stops wasting retries on inputs
580+
// that can never succeed. A parse TIMEOUT or a context cancellation is
581+
// transient — the same document may parse on a less-loaded attempt — so
582+
// it stays an ordinary (retryable) error. Everything else from the
583+
// parser is deterministic on these bytes (encrypted PDF that won't open
584+
// with the empty password, a backend-rejected/malformed structure, a
585+
// scanned image with no extractable text): retrying only re-derives the
586+
// same failure, so mark it permanent and dead-letter it immediately.
587+
if isTransientParseErr(perr) {
588+
return nil, perr
589+
}
590+
return nil, queue.Permanent(perr)
591+
}
592+
return parsed, nil
593+
}
594+
595+
// isTransientParseErr reports whether a parser error is worth retrying. Parse
596+
// timeouts and context cancellations are load-dependent (a complex document may
597+
// finish within budget on a quieter attempt), so they are transient. A genuine
598+
// structural rejection is not.
599+
func isTransientParseErr(err error) bool {
600+
if errors.Is(err, context.DeadlineExceeded) || errors.Is(err, context.Canceled) {
601+
return true
602+
}
603+
// The PDF parser's own deadline wrapper formats a plain (unwrapped) message
604+
// when its internal timer fires, so match it textually as a fallback.
605+
msg := err.Error()
606+
return strings.Contains(msg, "parse exceeded") || strings.Contains(msg, "parse cancelled")
573607
}
574608

575609
// getSourceWithRetry fetches a freshly-uploaded object, tolerating the
@@ -1035,13 +1069,18 @@ func (p *Pipeline) fail(ctx context.Context, store docPersister, id tree.Documen
10351069
failCtx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
10361070
defer cancel()
10371071

1038-
// If the queue will retry this job, the failure is (so far) transient —
1039-
// under heavy concurrent ingestion, parse can hit a parse-timeout or a
1040-
// not-yet-visible source and recover on a later attempt. Surfacing
1041-
// "failed" now would tell a polling client the document is dead when it
1042-
// isn't, so keep it in "parsing" and let the retry run. Only the final
1043-
// attempt produces a terminal "failed".
1044-
if !isLastAttempt(ctx) {
1072+
// A permanent failure (encrypted/malformed/no-text document) will NOT be
1073+
// retried by the queue — the worker cancels the job — so it is terminal
1074+
// right now regardless of which attempt we're on. Marking it failed
1075+
// immediately gives the caller the real reason instead of leaving the
1076+
// document wedged in "parsing" forever waiting for a retry that never runs.
1077+
if !queue.IsPermanent(cause) && !isLastAttempt(ctx) {
1078+
// Otherwise, if the queue will retry this job, the failure is (so far)
1079+
// transient — under heavy concurrent ingestion, parse can hit a
1080+
// parse-timeout or a not-yet-visible source and recover on a later
1081+
// attempt. Surfacing "failed" now would tell a polling client the
1082+
// document is dead when it isn't, so keep it in "parsing" and let the
1083+
// retry run. Only the final attempt produces a terminal "failed".
10451084
p.Logger.Warn("ingest: transient failure, will retry",
10461085
"document_id", string(id), "stage", stage, "cause", cause.Error())
10471086
if err := store.SetDocumentStatus(failCtx, id, db.StatusParsing, ""); err != nil {

pkg/ingest/parse_classify_test.go

Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,38 @@
1+
package ingest
2+
3+
import (
4+
"context"
5+
"errors"
6+
"fmt"
7+
"testing"
8+
)
9+
10+
// The classifier decides whether a parser failure is worth retrying. Getting
11+
// this wrong is expensive in both directions: marking a transient timeout
12+
// permanent dead-letters a document that would have parsed on a quieter
13+
// attempt; marking a deterministic rejection transient burns the whole retry
14+
// budget (and, as seen in HAL-321, interleaves confusing "object not found"
15+
// errors into the job history).
16+
func TestIsTransientParseErr(t *testing.T) {
17+
cases := []struct {
18+
name string
19+
err error
20+
transient bool
21+
}{
22+
{"deadline exceeded", context.DeadlineExceeded, true},
23+
{"canceled", context.Canceled, true},
24+
{"wrapped deadline", fmt.Errorf("pdf: parse cancelled: %w", context.DeadlineExceeded), true},
25+
{"pdf timeout message", errors.New("pdf: parse exceeded 5m0s — document too complex or malformed"), true},
26+
{"pdf cancelled message", errors.New("pdf: parse cancelled: context deadline exceeded"), true},
27+
{"encrypted", errors.New("pdf: open: encrypted and could not be unlocked with empty password: x"), false},
28+
{"backend rejected", errors.New("pdf: open: ledongthuc/pdf backend rejected the document: malformed PDF: 256-bit encryption key"), false},
29+
{"no extractable text", errors.New("pdf: parsed but no extractable text — the document may be a scanned image"), false},
30+
}
31+
for _, tc := range cases {
32+
t.Run(tc.name, func(t *testing.T) {
33+
if got := isTransientParseErr(tc.err); got != tc.transient {
34+
t.Fatalf("isTransientParseErr(%q) = %v, want %v", tc.err, got, tc.transient)
35+
}
36+
})
37+
}
38+
}

pkg/queue/permanent_test.go

Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,47 @@
1+
package queue
2+
3+
import (
4+
"errors"
5+
"fmt"
6+
"testing"
7+
)
8+
9+
func TestPermanentWrapsAndUnwraps(t *testing.T) {
10+
base := errors.New("encrypted PDF")
11+
perm := Permanent(base)
12+
13+
if !IsPermanent(perm) {
14+
t.Fatal("IsPermanent should be true for a wrapped permanent error")
15+
}
16+
if !errors.Is(perm, base) {
17+
t.Fatal("errors.Is should still match the wrapped cause")
18+
}
19+
if perm.Error() != base.Error() {
20+
t.Fatalf("Error() = %q, want %q", perm.Error(), base.Error())
21+
}
22+
}
23+
24+
func TestPermanentDetectedThroughWrapping(t *testing.T) {
25+
// A permanent error wrapped again with fmt.Errorf("%w") must still be
26+
// detectable — the ingest pipeline returns queue.Permanent(...) which a
27+
// caller may decorate with stage context.
28+
wrapped := fmt.Errorf("parse: %w", Permanent(errors.New("malformed")))
29+
if !IsPermanent(wrapped) {
30+
t.Fatal("IsPermanent should see through an outer fmt.Errorf wrap")
31+
}
32+
}
33+
34+
func TestPermanentOfNilIsNil(t *testing.T) {
35+
if Permanent(nil) != nil {
36+
t.Fatal("Permanent(nil) must be nil so success paths stay clean")
37+
}
38+
if IsPermanent(nil) {
39+
t.Fatal("IsPermanent(nil) must be false")
40+
}
41+
}
42+
43+
func TestOrdinaryErrorIsNotPermanent(t *testing.T) {
44+
if IsPermanent(errors.New("storage: object not found")) {
45+
t.Fatal("a plain (transient) error must not be classified permanent")
46+
}
47+
}

pkg/queue/queue.go

Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -79,3 +79,41 @@ type Queue interface {
7979
// ErrUnknownKind is returned by Queue implementations when a job with no
8080
// registered handler is received.
8181
var ErrUnknownKind = errors.New("queue: no handler registered for job kind")
82+
83+
// PermanentError marks a handler failure as NON-retryable: the input is
84+
// deterministically bad (e.g. an encrypted or malformed document the parser
85+
// can't open, or content with no extractable text), so re-running the job can
86+
// only fail the same way. A queue backend that understands retries MUST stop
87+
// retrying a job whose handler returns a PermanentError and dead-letter it
88+
// immediately, instead of burning the full retry budget on an outcome that
89+
// will never change.
90+
//
91+
// Transient failures (a not-yet-visible source under heavy concurrent
92+
// ingestion, a parse timeout under load, a flaky network call) are the
93+
// opposite: they are returned as ordinary errors so the queue retries them.
94+
type PermanentError struct{ Err error }
95+
96+
func (e *PermanentError) Error() string {
97+
if e.Err == nil {
98+
return "permanent failure"
99+
}
100+
return e.Err.Error()
101+
}
102+
103+
func (e *PermanentError) Unwrap() error { return e.Err }
104+
105+
// Permanent wraps err so the queue treats the failure as non-retryable. It
106+
// returns nil for a nil err so `return queue.Permanent(doThing())` stays
107+
// correct on the success path.
108+
func Permanent(err error) error {
109+
if err == nil {
110+
return nil
111+
}
112+
return &PermanentError{Err: err}
113+
}
114+
115+
// IsPermanent reports whether err (or anything it wraps) is a PermanentError.
116+
func IsPermanent(err error) bool {
117+
var pe *PermanentError
118+
return errors.As(err, &pe)
119+
}

pkg/queue/river.go

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -80,12 +80,20 @@ func (w *envelopeWorker) Work(ctx context.Context, job *river.Job[envelopeArgs])
8080
if job.JobRow != nil {
8181
attempt, maxAttempts = job.Attempt, job.MaxAttempts
8282
}
83-
return h(ctx, Job{
83+
err := h(ctx, Job{
8484
Kind: job.Args.DomainKind,
8585
Payload: job.Args.Payload,
8686
Attempt: attempt,
8787
MaxAttempts: maxAttempts,
8888
})
89+
// A PermanentError means the input is deterministically bad — retrying it
90+
// can only waste the remaining attempts (and, worse, interleave confusing
91+
// transient errors into the job's history). river.JobCancel stops all
92+
// further retries and dead-letters the job now, preserving the real cause.
93+
if IsPermanent(err) {
94+
return river.JobCancel(err)
95+
}
96+
return err
8997
}
9098

9199
// NewRiver constructs a new River-backed Queue. It opens its own pgxpool

pkg/storage/local.go

Lines changed: 25 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -18,13 +18,31 @@ type Local struct {
1818

1919
// NewLocal returns a Local storage rooted at dir. The directory is created
2020
// if it does not exist.
21+
//
22+
// dir is resolved to an ABSOLUTE path up front. A relative root (the default
23+
// is "./data/documents") is otherwise resolved against the process's current
24+
// working directory on every call — so if the engine is ever relaunched from a
25+
// different directory while the queue still holds jobs that reference earlier
26+
// uploads (River persists jobs in Postgres across restarts), the worker would
27+
// look under a different root than the one the bytes were written to and fail
28+
// with "object not found" on a file that is in fact on disk. Pinning the root
29+
// to an absolute path at construction makes it stable for the process lifetime.
2130
func NewLocal(dir string) (*Local, error) {
22-
if err := os.MkdirAll(dir, 0o755); err != nil {
31+
abs, err := filepath.Abs(dir)
32+
if err != nil {
33+
return nil, fmt.Errorf("resolve storage root %q: %w", dir, err)
34+
}
35+
if err := os.MkdirAll(abs, 0o755); err != nil {
2336
return nil, fmt.Errorf("create storage root: %w", err)
2437
}
25-
return &Local{root: dir}, nil
38+
return &Local{root: abs}, nil
2639
}
2740

41+
// Root returns the absolute filesystem path the storage is rooted at. Exposed
42+
// so the engine can log the resolved root at boot (the single most useful fact
43+
// when diagnosing an "object not found" on a file that appears to be on disk).
44+
func (l *Local) Root() string { return l.root }
45+
2846
func (l *Local) path(key string) string {
2947
// Keys may include slashes; treat them as path separators.
3048
return filepath.Join(l.root, filepath.FromSlash(key))
@@ -62,7 +80,11 @@ func (l *Local) Get(ctx context.Context, key string) (io.ReadCloser, Metadata, e
6280
info, err := os.Stat(full)
6381
if err != nil {
6482
if errors.Is(err, os.ErrNotExist) {
65-
return nil, Metadata{}, ErrNotFound
83+
// Wrap ErrNotFound (errors.Is still matches) but carry the resolved
84+
// absolute path so the failure is self-diagnosing: a caller seeing
85+
// this in a log can immediately tell whether it looked in the wrong
86+
// root vs. the bytes genuinely being absent.
87+
return nil, Metadata{}, fmt.Errorf("%w: %s", ErrNotFound, full)
6688
}
6789
return nil, Metadata{}, err
6890
}

pkg/storage/local_test.go

Lines changed: 76 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,76 @@
1+
package storage
2+
3+
import (
4+
"bytes"
5+
"context"
6+
"errors"
7+
"io"
8+
"os"
9+
"path/filepath"
10+
"strings"
11+
"testing"
12+
)
13+
14+
func TestLocalResolvesRootToAbsolute(t *testing.T) {
15+
// A relative root must be pinned to an absolute path so the worker reads
16+
// from the same place regardless of the process's working directory at
17+
// read time (the HAL-321 "object not found on a file that is on disk" bug).
18+
dir := t.TempDir()
19+
rel, err := filepath.Rel(mustGetwd(t), dir)
20+
if err != nil {
21+
t.Skipf("cannot relativise temp dir: %v", err)
22+
}
23+
l, err := NewLocal(rel)
24+
if err != nil {
25+
t.Fatalf("NewLocal: %v", err)
26+
}
27+
if !filepath.IsAbs(l.Root()) {
28+
t.Fatalf("Root() = %q, want absolute", l.Root())
29+
}
30+
}
31+
32+
func TestLocalGetNotFoundCarriesPath(t *testing.T) {
33+
l, err := NewLocal(t.TempDir())
34+
if err != nil {
35+
t.Fatalf("NewLocal: %v", err)
36+
}
37+
_, _, err = l.Get(context.Background(), "documents/missing/source.pdf")
38+
if !errors.Is(err, ErrNotFound) {
39+
t.Fatalf("err = %v, want ErrNotFound", err)
40+
}
41+
// The error must name the resolved path so an operator can immediately see
42+
// WHERE the worker looked.
43+
if !strings.Contains(err.Error(), "source.pdf") {
44+
t.Fatalf("not-found error %q should include the resolved path", err)
45+
}
46+
}
47+
48+
func TestLocalPutThenGetRoundTrip(t *testing.T) {
49+
l, err := NewLocal(t.TempDir())
50+
if err != nil {
51+
t.Fatalf("NewLocal: %v", err)
52+
}
53+
ctx := context.Background()
54+
want := []byte("hello vectorless")
55+
if err := l.Put(ctx, "documents/doc1/source.pdf", bytes.NewReader(want), Metadata{}); err != nil {
56+
t.Fatalf("Put: %v", err)
57+
}
58+
rc, _, err := l.Get(ctx, "documents/doc1/source.pdf")
59+
if err != nil {
60+
t.Fatalf("Get: %v", err)
61+
}
62+
defer func() { _ = rc.Close() }()
63+
got, _ := io.ReadAll(rc)
64+
if !bytes.Equal(got, want) {
65+
t.Fatalf("round-trip = %q, want %q", got, want)
66+
}
67+
}
68+
69+
func mustGetwd(t *testing.T) string {
70+
t.Helper()
71+
wd, err := os.Getwd()
72+
if err != nil {
73+
t.Fatalf("getwd: %v", err)
74+
}
75+
return wd
76+
}

0 commit comments

Comments
 (0)