diff --git a/changelog.d/3333-hardcover-language-evidence-timeout.md b/changelog.d/3333-hardcover-language-evidence-timeout.md new file mode 100644 index 000000000..ee7d1759e --- /dev/null +++ b/changelog.d/3333-hardcover-language-evidence-timeout.md @@ -0,0 +1,2 @@ +### Fixed +- **Hardcover language checks no longer time out on every author refresh** (#3333). When a metadata profile restricts languages, Bindery asks Hardcover which of an author's works have an edition in an allowed language. Hardcover could not answer that query in time and cancelled it after about 15 seconds, so every author with Hardcover works spent close to a minute on retries during a refresh, and those works fell back to their default-edition language. The lookup now uses queries Hardcover answers in under a second, so the edition languages are checked again. diff --git a/internal/metadata/hardcover/client.go b/internal/metadata/hardcover/client.go index 54a49d327..fce97afa5 100644 --- a/internal/metadata/hardcover/client.go +++ b/internal/metadata/hardcover/client.go @@ -349,7 +349,8 @@ func (c *Client) GetAuthorWorks(ctx context.Context, authorForeignID string) ([] } // GetAuthorWorkLanguageEvidence resolves language-filter evidence in one -// bounded GraphQL query for the whole author catalogue. It asks only whether +// bounded GraphQL query for the whole author catalogue, two when some works +// are named by numeric id (see fetchWorkEditions). It asks only whether // each Hardcover work has an edition in one of the profile's allowed // languages and uses distinct_on(book_id), so the response contains at most // one small row per work. The explicit limit equals the unique requested work @@ -396,40 +397,16 @@ func (c *Client) GetAuthorWorkLanguageEvidence(ctx context.Context, books []mode return nil, metadata.ErrProviderNotConfigured } - const gql = `query GetAuthorWorkLanguageEvidence($slugs: [String!]!, $bookIds: [Int!]!, $languageCodes: [String!]!, $limit: Int!) { - editions( - where: { - _and: [ - {_or: [{book: {slug: {_in: $slugs}}}, {book_id: {_in: $bookIds}}]}, - {language: {_or: [{code2: {_in: $languageCodes}}, {code3: {_in: $languageCodes}}]}} - ] - }, - distinct_on: [book_id], - order_by: [{book_id: asc}, {id: asc}], - limit: $limit - ) { - book { id slug } - language { code2 code3 language } - } - }` - var resp struct { - Data struct { - Editions []struct { - Book hcBookRef `json:"book"` - Language *hcLanguage `json:"language"` - } `json:"editions"` - } `json:"data"` - } - if err := c.query(ctx, gql, map[string]any{ - "slugs": slugs, - "bookIds": bookIDs, - "languageCodes": models.LanguageCodeVariants(allowed), - "limit": len(evidence), - }, &resp); err != nil { + editions, err := c.fetchWorkEditions(ctx, "GetAuthorWorkLanguageEvidence", + "$languageCodes: [String!]!", + "{language: {_or: [{code2: {_in: $languageCodes}}, {code3: {_in: $languageCodes}}]}}", + map[string]any{"languageCodes": models.LanguageCodeVariants(allowed)}, + slugs, bookIDs) + if err != nil { return nil, fmt.Errorf("hardcover get author work language evidence: %w", err) } - // A successful, explicitly bounded distinct query proves absence of an allowed + // Successful, explicitly bounded distinct queries prove absence of an allowed // edition. Preserve the default edition only as known non-allowed evidence; // it never gets to overrule a matching edition returned below. for _, book := range books { @@ -447,7 +424,7 @@ func (c *Client) GetAuthorWorkLanguageEvidence(ctx context.Context, books []mode evidence[key] = metadata.AuthorWorkLanguageEvidence{State: metadata.AuthorWorkLanguageNotAllowed, Language: language} } } - for _, edition := range resp.Data.Editions { + for _, edition := range editions { key := edition.Book.foreignID() if _, ok := evidence[key]; !ok { continue @@ -462,6 +439,93 @@ func (c *Client) GetAuthorWorkLanguageEvidence(ctx context.Context, books []mode return evidence, nil } +// hcWorkEdition is one row of fetchWorkEditions: a work and the language of +// the one edition kept for it. +type hcWorkEdition struct { + Book hcBookRef `json:"book"` + Language *hcLanguage `json:"language"` +} + +// fetchWorkEditions returns, for the works named by slugs and by numeric book +// ids, the editions that pass editionFilter, at most one per work: +// distinct_on(book_id) keeps the first by edition id. filterVarDecls declares +// the variables editionFilter uses, and filterVars carries their values. +// +// The slugs and the book ids go out as separate queries and their rows are +// merged, never joined in one _or. Hardcover cannot serve an _or between the +// book.slug relationship and the book_id column from an index, so that query +// ran until Hardcover cancelled it with HTTP 408 after about 15 s, for every +// author, while either predicate alone answers in under a second (#3333). +// Book ids are filled only for numeric slugs, so this is normally the slug +// query alone. Each query declares only the variables it uses, because +// Hasura refuses any other with validation-failed. +// +// Each query is bounded by the number of works it names. Any failure returns +// an error and no rows: callers read a successful result as proof that a work +// it leaves out has no such edition, which holds only if every query +// succeeded. +func (c *Client) fetchWorkEditions(ctx context.Context, name, filterVarDecls, editionFilter string, filterVars map[string]any, slugs []string, bookIDs []int) ([]hcWorkEdition, error) { + lookups := []struct { + predicate, varDecl, varName string + values any + count int + }{ + {"{book: {slug: {_in: $slugs}}}", "$slugs: [String!]!", "slugs", slugs, len(slugs)}, + {"{book_id: {_in: $bookIds}}", "$bookIds: [Int!]!", "bookIds", bookIDs, len(bookIDs)}, + } + var editions []hcWorkEdition + seen := make(map[int]bool) + for _, lookup := range lookups { + if lookup.count == 0 { + continue + } + varDecls := lookup.varDecl + if filterVarDecls != "" { + varDecls += ", " + filterVarDecls + } + gql := `query ` + name + `(` + varDecls + `, $limit: Int!) { + editions( + where: { + _and: [ + ` + lookup.predicate + `, + ` + editionFilter + ` + ] + }, + distinct_on: [book_id], + order_by: [{book_id: asc}, {id: asc}], + limit: $limit + ) { + book { id slug } + language { code2 code3 language } + } + }` + vars := make(map[string]any, len(filterVars)+2) + for k, v := range filterVars { + vars[k] = v + } + vars[lookup.varName] = lookup.values + vars["limit"] = lookup.count + var resp struct { + Data struct { + Editions []hcWorkEdition `json:"editions"` + } `json:"data"` + } + if err := c.query(ctx, gql, vars, &resp); err != nil { + return nil, err + } + for _, edition := range resp.Data.Editions { + // Both queries keep one edition per work under the same order, + // so a work they both name comes back as the same row twice. + if seen[edition.Book.ID] { + continue + } + seen[edition.Book.ID] = true + editions = append(editions, edition) + } + } + return editions, nil +} + // resolveBlankWorkLanguages settles the works the allowed-language query left // indeterminate only because they carry no language of their own. Hardcover // sets a work's language from its default ebook or audio edition, which is @@ -473,7 +537,7 @@ func (c *Client) GetAuthorWorkLanguageEvidence(ctx context.Context, books []mode // language Hardcover records by name only, which the code match misses) keeps // it. A work with no language recorded on any edition stays indeterminate. // -// One bounded distinct_on query, like the one above. It is best effort: a +// The same bounded distinct_on lookup as above. It is best effort: a // failure leaves the works indeterminate, which is what they were before it // ran, rather than discarding the evidence already established. func (c *Client) resolveBlankWorkLanguages(ctx context.Context, books []models.Book, allowed []string, evidence map[string]metadata.AuthorWorkLanguageEvidence) { @@ -498,39 +562,13 @@ func (c *Client) resolveBlankWorkLanguages(ctx context.Context, books []models.B return } - const gql = `query GetAuthorWorkKnownLanguages($slugs: [String!]!, $bookIds: [Int!]!, $limit: Int!) { - editions( - where: { - _and: [ - {_or: [{book: {slug: {_in: $slugs}}}, {book_id: {_in: $bookIds}}]}, - {language: {id: {_is_null: false}}} - ] - }, - distinct_on: [book_id], - order_by: [{book_id: asc}, {id: asc}], - limit: $limit - ) { - book { id slug } - language { code2 code3 language } - } - }` - var resp struct { - Data struct { - Editions []struct { - Book hcBookRef `json:"book"` - Language *hcLanguage `json:"language"` - } `json:"editions"` - } `json:"data"` - } - if err := c.query(ctx, gql, map[string]any{ - "slugs": slugs, - "bookIds": bookIDs, - "limit": len(slugs), - }, &resp); err != nil { + editions, err := c.fetchWorkEditions(ctx, "GetAuthorWorkKnownLanguages", + "", "{language: {id: {_is_null: false}}}", nil, slugs, bookIDs) + if err != nil { slog.Debug("hardcover: known edition language lookup failed; blank-language works stay indeterminate", "works", len(slugs), "error", err) return } - for _, edition := range resp.Data.Editions { + for _, edition := range editions { key := edition.Book.foreignID() if !asked[key] { continue diff --git a/internal/metadata/hardcover/client_test.go b/internal/metadata/hardcover/client_test.go index 34630a148..5722ba9f6 100644 --- a/internal/metadata/hardcover/client_test.go +++ b/internal/metadata/hardcover/client_test.go @@ -827,11 +827,20 @@ func TestGetAuthorWorkLanguageEvidence_BatchesAllowedEditionLookup(t *testing.T) if !slices.Equal(gotCodes, []string{"en", "eng"}) { t.Errorf("languageCodes = %v, want [en eng]", gotCodes) } - bookIDs, ok := req.Variables["bookIds"].([]interface{}) - if !ok || len(bookIDs) != 1 || bookIDs[0] != float64(42) { - t.Errorf("bookIds = %#v, want [42]", req.Variables["bookIds"]) - } - if limit := req.Variables["limit"]; limit != float64(6) { + if _, byID := req.Variables["bookIds"]; byID { + // hc:42 is named by numeric id, so it also gets a book_id query, + // sent on its own rather than in an _or with the slugs (#3333). + bookIDs, ok := req.Variables["bookIds"].([]interface{}) + if !ok || len(bookIDs) != 1 || bookIDs[0] != float64(42) { + t.Errorf("bookIds = %#v, want [42]", req.Variables["bookIds"]) + } + if _, ok := req.Variables["slugs"]; ok { + t.Errorf("book_id query also sent slugs: %#v", req.Variables) + } + if limit := req.Variables["limit"]; limit != float64(1) { + t.Errorf("book_id limit = %#v, want 1", limit) + } + } else if limit := req.Variables["limit"]; limit != float64(6) { t.Errorf("limit = %#v, want 6 unique applicable works", limit) } return gqlResponse(t, http.StatusOK, map[string]interface{}{ @@ -875,8 +884,8 @@ func TestGetAuthorWorkLanguageEvidence_BatchesAllowedEditionLookup(t *testing.T) if err != nil { t.Fatal(err) } - if requests != 1 { - t.Fatalf("requests = %d, want one batch request", requests) + if requests != 2 { + t.Fatalf("requests = %d, want one batch request per predicate (slug, book_id)", requests) } want := map[string]metadata.AuthorWorkLanguageEvidence{ "hc:translated-default": {State: metadata.AuthorWorkLanguageAllowed, Language: "eng"}, diff --git a/internal/metadata/hardcover/language_evidence_predicates_test.go b/internal/metadata/hardcover/language_evidence_predicates_test.go new file mode 100644 index 000000000..e4ef0d446 --- /dev/null +++ b/internal/metadata/hardcover/language_evidence_predicates_test.go @@ -0,0 +1,321 @@ +package hardcover + +import ( + "context" + "encoding/json" + "io" + "net/http" + "reflect" + "regexp" + "slices" + "strings" + "testing" + + "github.com/vavallee/bindery/internal/metadata" + "github.com/vavallee/bindery/internal/models" +) + +// fakeEditionsAPI answers the editions queries behind the language evidence +// lookup the way Hardcover answered them when #3333 was measured: +// +// - a query that joins the book.slug and book_id predicates in one _or runs +// into Hardcover's statement timeout and comes back as HTTP 408 +// {"error":"Request timeout"}. Live that takes about 15 s, for every +// author with Hardcover works; here it is immediate. +// - a variable that the query declares but never uses, or sends without +// declaring, is refused with validation-failed, as Hasura does. +// - otherwise the slug or the book_id predicate picks the works, the +// language filter picks their editions, and distinct_on(book_id) keeps the +// first matching edition of each work, up to $limit. +type fakeEditionsAPI struct { + t *testing.T + works []fakeWork + // fail, when set, answers the requests it matches with HTTP 500. + fail func(gqlRequest) bool + requests []gqlRequest +} + +type fakeWork struct { + id int + slug string + // editions in edition-id order. A zero hcLanguage records no language. + editions []hcLanguage +} + +var ( + english = hcLanguage{Code2: "en", Code3: "eng", Language: "English"} + italian = hcLanguage{Code2: "it", Code3: "ita", Language: "Italian"} + spanish = hcLanguage{Code2: "es", Code3: "spa", Language: "Spanish"} + + gqlVariableDecl = regexp.MustCompile(`\$(\w+)\s*:`) +) + +func (f *fakeEditionsAPI) client() *Client { + return newMockClient(f.handle) +} + +func (f *fakeEditionsAPI) handle(r *http.Request) (*http.Response, error) { + t := f.t + body, err := io.ReadAll(r.Body) + if err != nil { + t.Fatal(err) + } + var req gqlRequest + if err := json.Unmarshal(body, &req); err != nil { + t.Fatal(err) + } + f.requests = append(f.requests, req) + + bySlug := strings.Contains(req.Query, "book: {slug: {_in: $slugs}}") + byID := strings.Contains(req.Query, "book_id: {_in: $bookIds}") + if bySlug && byID { + return gqlResponse(t, http.StatusRequestTimeout, `{"error":"Request timeout"}`), nil + } + + head, selection, _ := strings.Cut(req.Query, ")") + declared := map[string]bool{} + for _, m := range gqlVariableDecl.FindAllStringSubmatch(head, -1) { + declared[m[1]] = true + _, sent := req.Variables[m[1]] + used := regexp.MustCompile(`\$` + m[1] + `\b`).MatchString(selection) + if !sent || !used { + return validationFailed(t, m[1]), nil + } + } + for name := range req.Variables { + if !declared[name] { + return validationFailed(t, name), nil + } + } + + if f.fail != nil && f.fail(req) { + return gqlResponse(t, http.StatusInternalServerError, `{"error":"upstream unavailable"}`), nil + } + + var named func(fakeWork) bool + switch { + case bySlug: + slugs := stringVars(t, req.Variables["slugs"]) + named = func(w fakeWork) bool { return slices.Contains(slugs, w.slug) } + case byID: + ids := intVars(t, req.Variables["bookIds"]) + named = func(w fakeWork) bool { return slices.Contains(ids, w.id) } + default: + t.Fatalf("editions query names no works: %s", req.Query) + } + var keep func(hcLanguage) bool + switch { + case strings.Contains(selection, "$languageCodes"): + codes := stringVars(t, req.Variables["languageCodes"]) + keep = func(l hcLanguage) bool { return slices.Contains(codes, l.Code2) || slices.Contains(codes, l.Code3) } + case strings.Contains(selection, "language: {id: {_is_null: false}}"): + keep = func(l hcLanguage) bool { return l != hcLanguage{} } + default: + t.Fatalf("unrecognised edition filter: %s", req.Query) + } + limit, _ := req.Variables["limit"].(float64) + + works := slices.Clone(f.works) + slices.SortFunc(works, func(a, b fakeWork) int { return a.id - b.id }) + rows := []map[string]any{} + for _, w := range works { + if len(rows) == int(limit) { + break + } + if !named(w) { + continue + } + for _, l := range w.editions { + if keep(l) { + rows = append(rows, map[string]any{ + "book": map[string]any{"id": w.id, "slug": w.slug}, + "language": map[string]any{"code2": l.Code2, "code3": l.Code3, "language": l.Language}, + }) + break + } + } + } + return gqlResponse(t, http.StatusOK, map[string]any{"editions": rows}), nil +} + +func validationFailed(t *testing.T, variable string) *http.Response { + return gqlResponse(t, http.StatusOK, `{"errors":[{"message":"unexpected variables in variableValues: `+variable+`","extensions":{"path":"$","code":"validation-failed"}}]}`) +} + +func stringVars(t *testing.T, v any) []string { + t.Helper() + raw, ok := v.([]any) + if !ok { + t.Fatalf("variable = %#v, want a list", v) + } + out := make([]string, 0, len(raw)) + for _, item := range raw { + out = append(out, item.(string)) + } + return out +} + +func intVars(t *testing.T, v any) []int { + t.Helper() + raw, ok := v.([]any) + if !ok { + t.Fatalf("variable = %#v, want a list", v) + } + out := make([]int, 0, len(raw)) + for _, item := range raw { + out = append(out, int(item.(float64))) + } + return out +} + +// requestsUsing returns the requests whose query names works by the given +// predicate variable ("slugs" or "bookIds"). +func (f *fakeEditionsAPI) requestsUsing(variable string) []gqlRequest { + var out []gqlRequest + for _, req := range f.requests { + if strings.Contains(req.Query, "$"+variable) { + out = append(out, req) + } + } + return out +} + +// Works that Hardcover names by slug, which is every supplement work in +// practice, must be looked up by slug alone (#3333). The lookup used to join +// the slug predicate to an empty book_id predicate in one _or, Hardcover +// cancelled that query with HTTP 408 after about 15 s for every author, and +// the works fell back to their default-edition language. +func TestGetAuthorWorkLanguageEvidence_SlugNamedWorksQueryBySlugAlone(t *testing.T) { + api := &fakeEditionsAPI{t: t, works: []fakeWork{ + {id: 101, slug: "four-thousand-weeks", editions: []hcLanguage{italian, english}}, + {id: 102, slug: "quattromila-settimane", editions: []hcLanguage{italian}}, + {id: 103, slug: "the-antidote", editions: []hcLanguage{english}}, + {id: 104, slug: "el-antidoto", editions: []hcLanguage{spanish}}, + {id: 105, slug: "aliveness", editions: []hcLanguage{{}}}, + }} + books := []models.Book{ + {ForeignID: "hc:four-thousand-weeks"}, + {ForeignID: "hc:quattromila-settimane"}, + {ForeignID: "hc:the-antidote", Language: "eng"}, + {ForeignID: "hc:el-antidoto", Language: "spa"}, + {ForeignID: "hc:aliveness"}, + } + + got, err := api.client().GetAuthorWorkLanguageEvidence(context.Background(), books, []string{"eng"}) + if err != nil { + t.Fatalf("language evidence lookup failed: %v", err) + } + want := map[string]metadata.AuthorWorkLanguageEvidence{ + "hc:four-thousand-weeks": {State: metadata.AuthorWorkLanguageAllowed, Language: "eng"}, + "hc:quattromila-settimane": {State: metadata.AuthorWorkLanguageNotAllowed, Language: "ita"}, + "hc:the-antidote": {State: metadata.AuthorWorkLanguageAllowed, Language: "eng"}, + "hc:el-antidoto": {State: metadata.AuthorWorkLanguageNotAllowed, Language: "spa"}, + "hc:aliveness": {State: metadata.AuthorWorkLanguageIndeterminate}, + } + if !reflect.DeepEqual(got, want) { + t.Fatalf("evidence = %#v, want %#v", got, want) + } + // The allowed-language query, then the follow up for the blank works that + // it did not settle. Both by slug, and neither carries $bookIds. + if len(api.requests) != 2 { + t.Fatalf("requests = %d, want 2 (allowed languages, then known languages)", len(api.requests)) + } + for _, req := range api.requests { + if strings.Contains(req.Query, "bookIds") { + t.Errorf("slug-named works sent the book_id predicate: %s", req.Query) + } + if _, ok := req.Variables["bookIds"]; ok { + t.Errorf("slug-named works sent a bookIds variable: %v", req.Variables) + } + } + if limit := api.requests[0].Variables["limit"]; limit != float64(len(books)) { + t.Errorf("allowed-language limit = %v, want %d", limit, len(books)) + } +} + +// A work Bindery knows only by its numeric Hardcover id (the slug was empty) +// still needs the book_id predicate. It goes out as its own query and the rows +// are merged, rather than joined to the slug predicate in an _or (#3333). +func TestGetAuthorWorkLanguageEvidence_NumericIDsQueriedSeparatelyAndMerged(t *testing.T) { + api := &fakeEditionsAPI{t: t, works: []fakeWork{ + {id: 42, slug: "", editions: []hcLanguage{spanish, english}}, + {id: 77, slug: "", editions: []hcLanguage{italian}}, + {id: 101, slug: "four-thousand-weeks", editions: []hcLanguage{english}}, + {id: 102, slug: "quattromila-settimane", editions: []hcLanguage{italian}}, + }} + books := []models.Book{ + {ForeignID: "hc:four-thousand-weeks"}, + {ForeignID: "hc:42", Language: "spa"}, + {ForeignID: "hc:quattromila-settimane"}, + {ForeignID: "hc:77"}, + } + + got, err := api.client().GetAuthorWorkLanguageEvidence(context.Background(), books, []string{"eng"}) + if err != nil { + t.Fatalf("language evidence lookup failed: %v", err) + } + want := map[string]metadata.AuthorWorkLanguageEvidence{ + "hc:four-thousand-weeks": {State: metadata.AuthorWorkLanguageAllowed, Language: "eng"}, + "hc:42": {State: metadata.AuthorWorkLanguageAllowed, Language: "eng"}, + "hc:quattromila-settimane": {State: metadata.AuthorWorkLanguageNotAllowed, Language: "ita"}, + "hc:77": {State: metadata.AuthorWorkLanguageNotAllowed, Language: "ita"}, + } + if !reflect.DeepEqual(got, want) { + t.Fatalf("evidence = %#v, want %#v", got, want) + } + + bySlug, byID := api.requestsUsing("slugs"), api.requestsUsing("bookIds") + if len(bySlug)+len(byID) != len(api.requests) { + t.Fatalf("a request named works by both predicates: %d requests, %d by slug, %d by id", len(api.requests), len(bySlug), len(byID)) + } + // Allowed languages, then known languages for the blank works left: once + // by slug and once by id each. + if len(bySlug) != 2 || len(byID) != 2 { + t.Fatalf("requests by slug = %d, by id = %d; want 2 and 2", len(bySlug), len(byID)) + } + if ids := intVars(t, byID[0].Variables["bookIds"]); !slices.Equal(ids, []int{42, 77}) { + t.Errorf("allowed-language bookIds = %v, want [42 77]", ids) + } + if limit := byID[0].Variables["limit"]; limit != float64(2) { + t.Errorf("allowed-language book_id limit = %v, want 2", limit) + } + if limit := bySlug[0].Variables["limit"]; limit != float64(4) { + t.Errorf("allowed-language slug limit = %v, want 4", limit) + } + // hc:42 is settled by its English edition; only hc:77 is still blank. + if ids := intVars(t, byID[1].Variables["bookIds"]); !slices.Equal(ids, []int{77}) { + t.Errorf("known-language bookIds = %v, want [77]", ids) + } +} + +// The evidence is authoritative only when every query that ran succeeded: +// absence of an allowed edition from a partial answer proves nothing. A +// failure of either query fails the whole lookup, so the caller keeps its +// existing fallbacks, as it did when the single query failed. +func TestGetAuthorWorkLanguageEvidence_EitherPredicateFailingReturnsNoEvidence(t *testing.T) { + for _, variable := range []string{"slugs", "bookIds"} { + t.Run(variable, func(t *testing.T) { + api := &fakeEditionsAPI{ + t: t, + works: []fakeWork{ + {id: 42, slug: "", editions: []hcLanguage{english}}, + {id: 101, slug: "four-thousand-weeks", editions: []hcLanguage{english}}, + }, + fail: func(req gqlRequest) bool { + _, ok := req.Variables[variable] + return ok + }, + } + got, err := api.client().GetAuthorWorkLanguageEvidence(context.Background(), []models.Book{ + {ForeignID: "hc:four-thousand-weeks", Language: "spa"}, + {ForeignID: "hc:42", Language: "spa"}, + }, []string{"eng"}) + if err == nil { + t.Fatal("expected the lookup to fail") + } + if got != nil { + t.Fatalf("evidence after a failed %s query = %#v, want nil", variable, got) + } + }) + } +}