From c71e7ee25eb5b7cda81124924b56908cf40df7e5 Mon Sep 17 00:00:00 2001 From: TheodorAdrienIsaak Mattli Date: Fri, 2 Oct 2026 15:11:50 +0200 Subject: [PATCH 1/8] Add audited host recovery for unmapped accounts --- cmd/dispatcher/account_recovery.go | 163 +++++++++++++ cmd/dispatcher/account_recovery_other.go | 15 ++ cmd/dispatcher/account_recovery_test.go | 215 ++++++++++++++++++ cmd/dispatcher/account_recovery_unix.go | 21 ++ cmd/dispatcher/main.go | 33 +++ docs/operations/auth-migration.md | 76 ++++++- .../database/account_recovery.sql.go | 108 +++++++++ internal/dispatcher/database/auth.sql.go | 5 + .../migrations/00020_account_recovery.sql | 21 ++ internal/dispatcher/database/models.go | 13 ++ .../database/queries/account_recovery.sql | 24 ++ internal/dispatcher/database/queries/auth.sql | 7 +- .../transport/api/admin_recovery_test.go | 112 +++++++++ internal/dispatcher/transport/api/auth.go | 6 + .../dispatcher/transport/api/handlers_auth.go | 4 + internal/storagecheck/init_test.go | 3 +- internal/storagecheck/policy.go | 3 +- 17 files changed, 820 insertions(+), 9 deletions(-) create mode 100644 cmd/dispatcher/account_recovery.go create mode 100644 cmd/dispatcher/account_recovery_other.go create mode 100644 cmd/dispatcher/account_recovery_test.go create mode 100644 cmd/dispatcher/account_recovery_unix.go create mode 100644 internal/dispatcher/database/account_recovery.sql.go create mode 100644 internal/dispatcher/database/migrations/00020_account_recovery.sql create mode 100644 internal/dispatcher/database/queries/account_recovery.sql create mode 100644 internal/dispatcher/transport/api/admin_recovery_test.go diff --git a/cmd/dispatcher/account_recovery.go b/cmd/dispatcher/account_recovery.go new file mode 100644 index 00000000..f70bd63c --- /dev/null +++ b/cmd/dispatcher/account_recovery.go @@ -0,0 +1,163 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package main + +import ( + "context" + "database/sql" + "errors" + "flag" + "fmt" + "os" + "path/filepath" + "strings" + "time" + "unicode" + + "github.com/google/uuid" + "github.com/netsec-ethz/debuglet/internal/dispatcher/config" + "github.com/netsec-ethz/debuglet/internal/dispatcher/database" + "github.com/netsec-ethz/debuglet/internal/dispatcher/models" + "github.com/netsec-ethz/debuglet/internal/dispatcher/transport/api" + "github.com/netsec-ethz/debuglet/internal/fsutil" + "github.com/netsec-ethz/debuglet/internal/sqlitedb" + "github.com/netsec-ethz/debuglet/internal/storagecheck" +) + +func validateRecoveryFlags(flags *flag.FlagSet, recover, revoke, reference, output string) error { + if (recover == "") == (revoke == "") || reference == "" || (recover != "") != (output != "") { + return errors.New("use either -recover-unmapped-account UUID -recovery-case CASE -recovery-output FILE, or -revoke-account-recovery UUID -recovery-case CASE") + } + var invalid string + flags.Visit(func(f *flag.Flag) { + switch f.Name { + case "config", "recover-unmapped-account", "revoke-account-recovery", "recovery-case", "recovery-output": + default: + invalid = f.Name + } + }) + if invalid != "" || flags.NArg() != 0 { + return errors.New("account recovery cannot be combined with other administration flags or arguments") + } + return nil +} + +// administerAccountRecovery changes access to one existing account, never its +// ownership. The host administrator must independently verify the requester; +// the case reference records that decision, it does not prove identity itself. +func administerAccountRecovery(ctx context.Context, cfg *config.DispatcherConfig, account, reference, output string, revoke bool) (err error) { + id, err := uuid.Parse(account) + if err != nil { + return fmt.Errorf("account identifier is not a UUID: %w", err) + } + if strings.TrimSpace(reference) != reference || reference == "" || len(reference) > 256 || strings.IndexFunc(reference, unicode.IsControl) >= 0 { + return errors.New("recovery case must be a nonempty reference of at most 256 bytes without control characters") + } + if err := storagecheck.Check(ctx, storagecheck.Dispatcher, cfg.Database.Path); err != nil { + return err + } + db, err := sqlitedb.Open(cfg.Database.Path) + if err != nil { + return err + } + defer db.Close() + tx, err := db.BeginTx(ctx, nil) + if err != nil { + return err + } + defer tx.Rollback() + queries := database.New(tx) + changed, err := queries.LockAccountForRecovery(ctx, id) + if err != nil { + return err + } + if changed == 0 { + return errors.New("account does not exist") + } + if revoke { + selector, err := queries.RevokeAdminAccountRecovery(ctx, database.RevokeAdminAccountRecoveryParams{ + RevokedByUid: sql.NullInt64{Int64: int64(os.Geteuid()), Valid: true}, RevocationReference: reference, Uuid: id, + }) + if errors.Is(err, sql.ErrNoRows) { + return errors.New("account has no unused administrator recovery to revoke") + } + if err != nil { + return err + } + if err := queries.DeleteAdminRecoveryCredential(ctx, selector); err != nil { + return err + } + return tx.Commit() + } + user, err := queries.GetUnmappedAccountForRecovery(ctx, id) + if errors.Is(err, sql.ErrNoRows) { + return errors.New("account already has credentials, a provider identity or a pending administrator recovery; ordinary recovery or explicit revocation is required") + } + if err != nil { + return err + } + token, selector, digest, err := api.NewRecoveryCredential() + if err != nil { + return err + } + now := time.Now().UTC() + if err := queries.RecordAdminAccountRecovery(ctx, database.RecordAdminAccountRecoveryParams{ + Selector: selector, UserID: user.ID, CaseReference: reference, IssuedByUid: int64(os.Geteuid()), + IssuedAt: now.Unix(), ExpiresAt: now.Add(24 * time.Hour).Unix(), + }); err != nil { + return fmt.Errorf("record recovery approval (case references must be unique): %w", err) + } + if err := queries.UpsertUserCredential(ctx, database.UpsertUserCredentialParams{ + UserID: user.ID, Kind: "recovery", Selector: selector, SecretHash: digest, CreatedAt: models.NewUTCTime(now), + }); err != nil { + return err + } + if err := queries.RevokeUserSessions(ctx, id); err != nil { + return err + } + // Publish and sync the private file before committing a usable code. A + // failure or crash before commit leaves no valid new credential in SQLite. + if err := publishRecoveryCode(output, token); err != nil { + return err + } + if err := tx.Commit(); err != nil { + return fmt.Errorf("recovery commit did not confirm success: %w; private output retained at %s; inspect the audit and use -revoke-account-recovery %s before retrying with a new case", err, output, account) + } + return nil +} + +func publishRecoveryCode(path, code string) (err error) { + if !filepath.IsAbs(path) { + return errors.New("recovery output must be an absolute path") + } + parent := filepath.Dir(path) + info, err := os.Lstat(parent) + if err != nil { + return err + } + if !info.IsDir() || info.Mode().Perm() != 0700 { + return errors.New("recovery output requires a real mode-0700 parent directory") + } + if err := recoveryDirectoryOwned(info); err != nil { + return err + } + f, err := os.CreateTemp(parent, ".account-recovery-*") + if err != nil { + return err + } + defer os.Remove(f.Name()) + _, writeErr := fmt.Fprintln(f, code) + if err := errors.Join(writeErr, f.Chmod(0600), f.Sync(), f.Close()); err != nil { + return err + } + // Link publishes complete bytes without replacing an existing file or + // following an output symlink. The parent stays under the operator's control. + if err := os.Link(f.Name(), path); err != nil { + return fmt.Errorf("publish recovery file: %w", err) + } + if err := fsutil.SyncDir(parent); err != nil { + return errors.Join(err, os.Remove(path)) + } + return nil +} diff --git a/cmd/dispatcher/account_recovery_other.go b/cmd/dispatcher/account_recovery_other.go new file mode 100644 index 00000000..ebcc3a7f --- /dev/null +++ b/cmd/dispatcher/account_recovery_other.go @@ -0,0 +1,15 @@ +//go:build !linux && !darwin + +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package main + +import ( + "errors" + "io/fs" +) + +func recoveryDirectoryOwned(fs.FileInfo) error { + return errors.New("account recovery requires a supported Unix host") +} diff --git a/cmd/dispatcher/account_recovery_test.go b/cmd/dispatcher/account_recovery_test.go new file mode 100644 index 00000000..825dcd19 --- /dev/null +++ b/cmd/dispatcher/account_recovery_test.go @@ -0,0 +1,215 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package main + +import ( + "context" + "database/sql" + "flag" + "os" + "path/filepath" + "strings" + "sync" + "testing" + + "github.com/google/uuid" + "github.com/netsec-ethz/debuglet/internal/dispatcher/config" + "github.com/netsec-ethz/debuglet/internal/dispatcher/database" + "github.com/netsec-ethz/debuglet/internal/sqlitedb" + "github.com/netsec-ethz/debuglet/internal/storagecheck" +) + +func recoveryFixture(t *testing.T) (*config.DispatcherConfig, *sql.DB, database.User, string) { + t.Helper() + dir := t.TempDir() + if err := os.Chmod(dir, 0700); err != nil { + t.Fatal(err) + } + path := filepath.Join(dir, "dispatcher.sqlite") + if err := storagecheck.BootstrapFresh(t.Context(), storagecheck.Dispatcher, path); err != nil { + t.Fatal(err) + } + db, err := sqlitedb.Open(path) + if err != nil { + t.Fatal(err) + } + t.Cleanup(func() { db.Close() }) + user, err := database.New(db).CreateUser(t.Context(), database.CreateUserParams{Uuid: uuid.New(), Name: "historical researcher"}) + if err != nil { + t.Fatal(err) + } + return dispatcherConfig(path), db, user, filepath.Join(dir, "recovery.txt") +} + +func TestAdminRecoveryPreservesIdentityAndRevokesSessions(t *testing.T) { + cfg, db, user, output := recoveryFixture(t) + for _, query := range []string{ + "INSERT INTO owned_executors(executor_id,user_id,name,created_at) VALUES ('node',?,'historical node',CURRENT_TIMESTAMP)", + "INSERT INTO sessions(selector,verifier_hash,csrf_hash,user_id,created_at,expires_at) VALUES ('old',X'01',X'02',?,CURRENT_TIMESTAMP,'2999-01-01')", + } { + if _, err := db.Exec(query, user.ID); err != nil { + t.Fatal(err) + } + } + if err := administerAccountRecovery(t.Context(), cfg, user.Uuid.String(), "support-17", output, false); err != nil { + t.Fatal(err) + } + info, err := os.Stat(output) + if err != nil || info.Mode().Perm() != 0600 { + t.Fatalf("private output: %v, %v", info, err) + } + code, err := os.ReadFile(output) + if err != nil || !strings.HasPrefix(string(code), "dbr_") { + t.Fatalf("recovery file unavailable: %v", err) + } + var owner, revoked, lifetime, issuer int64 + var reference string + if err := db.QueryRow("SELECT user_id FROM owned_executors WHERE executor_id='node'").Scan(&owner); err != nil { + t.Fatal(err) + } + if err := db.QueryRow("SELECT revoked FROM sessions WHERE selector='old'").Scan(&revoked); err != nil { + t.Fatal(err) + } + if err := db.QueryRow("SELECT case_reference,expires_at-issued_at,issued_by_uid FROM account_recovery_audit").Scan(&reference, &lifetime, &issuer); err != nil { + t.Fatal(err) + } + got, err := database.New(db).GetUserByUUID(t.Context(), user.Uuid) + if err != nil || got != user || owner != user.ID || revoked != 1 || reference != "support-17" || lifetime != 86400 || issuer != int64(os.Geteuid()) { + t.Fatalf("identity/revocation/audit mismatch: user=%+v owner=%d revoked=%d reference=%q lifetime=%d uid=%d err=%v", got, owner, revoked, reference, lifetime, issuer, err) + } + if err := administerAccountRecovery(t.Context(), cfg, user.Uuid.String(), "support-18", output+".second", false); err == nil { + t.Fatal("duplicate recovery accepted") + } + if err := administerAccountRecovery(t.Context(), cfg, user.Uuid.String(), "lost-delivery", "", true); err != nil { + t.Fatal(err) + } + var credentials int + if err := db.QueryRow("SELECT COUNT(*) FROM user_credentials").Scan(&credentials); err != nil || credentials != 0 { + t.Fatalf("revoked recovery still usable: %d %v", credentials, err) + } + if err := administerAccountRecovery(t.Context(), cfg, user.Uuid.String(), "support-17", output+".reuse", false); err == nil { + t.Fatal("reused audit case accepted") + } + if err := administerAccountRecovery(t.Context(), cfg, user.Uuid.String(), "support-19", output+".retry", false); err != nil { + t.Fatal(err) + } +} + +func TestAdminRecoveryRefusesMappedAndUnknownAccounts(t *testing.T) { + for _, kind := range []string{"credential", "provider", "unknown"} { + t.Run(kind, func(t *testing.T) { + cfg, db, user, output := recoveryFixture(t) + var err error + switch kind { + case "credential": + _, err = db.Exec("INSERT INTO user_credentials VALUES (?,'account','existing',X'01',CURRENT_TIMESTAMP)", user.ID) + case "provider": + _, err = db.Exec("INSERT INTO oauth_identities VALUES ('github','https://github.com','subject',?,'login',CURRENT_TIMESTAMP,CURRENT_TIMESTAMP)", user.ID) + case "unknown": + user.Uuid = uuid.New() + } + if err != nil { + t.Fatal(err) + } + if err := administerAccountRecovery(t.Context(), cfg, user.Uuid.String(), "support", output, false); err == nil { + t.Fatal("mapped/unknown account accepted") + } + if _, err := os.Stat(output); !os.IsNotExist(err) { + t.Fatal("refused recovery created an output") + } + }) + } +} + +func TestAdminRecoveryOutputFailureRollsBack(t *testing.T) { + for _, kind := range []string{"existing", "symlink", "public-parent", "commit"} { + t.Run(kind, func(t *testing.T) { + cfg, db, user, output := recoveryFixture(t) + switch kind { + case "existing": + if err := os.WriteFile(output, []byte("keep"), 0600); err != nil { + t.Fatal(err) + } + case "symlink": + if err := os.Symlink("absent", output); err != nil { + t.Fatal(err) + } + case "public-parent": + if err := os.Chmod(filepath.Dir(output), 0755); err != nil { + t.Fatal(err) + } + case "commit": + // A deferred SQLite constraint fails at commit after file publication. + _, err := db.Exec("CREATE TABLE recovery_commit_failure(user_id INTEGER REFERENCES users(id) DEFERRABLE INITIALLY DEFERRED); CREATE TRIGGER recovery_fail AFTER INSERT ON account_recovery_audit BEGIN INSERT INTO recovery_commit_failure VALUES (-1); END") + if err != nil { + t.Fatal(err) + } + } + err := administerAccountRecovery(t.Context(), cfg, user.Uuid.String(), "support", output, false) + if err == nil { + t.Fatal("output/commit failure accepted") + } + var count int + if err := db.QueryRow("SELECT (SELECT COUNT(*) FROM user_credentials)+(SELECT COUNT(*) FROM account_recovery_audit)").Scan(&count); err != nil || count != 0 { + t.Fatalf("failed issuance persisted: %d %v", count, err) + } + if kind == "existing" { + b, _ := os.ReadFile(output) + if string(b) != "keep" { + t.Fatal("existing output overwritten") + } + } + if kind == "commit" && !strings.Contains(err.Error(), "private output retained") { + t.Fatalf("uncertain commit lacks recovery instruction: %v", err) + } + }) + } +} + +func TestAdminRecoveryConcurrentIssueAppliesOnce(t *testing.T) { + cfg, db, user, output := recoveryFixture(t) + start := make(chan struct{}) + results := make(chan error, 2) + var workers sync.WaitGroup + for _, suffix := range []string{"a", "b"} { + workers.Add(1) + go func() { + defer workers.Done() + <-start + results <- administerAccountRecovery(context.Background(), cfg, user.Uuid.String(), "case-"+suffix, output+suffix, false) + }() + } + close(start) + workers.Wait() + close(results) + success := 0 + for err := range results { + if err == nil { + success++ + } + } + var records int + if err := db.QueryRow("SELECT COUNT(*) FROM account_recovery_audit").Scan(&records); err != nil || success != 1 || records != 1 { + t.Fatalf("success=%d audit=%d err=%v", success, records, err) + } +} + +func TestRecoveryFlagBoundaries(t *testing.T) { + for _, extra := range []string{"version", "upgrade-database", "grant-operator"} { + fs := flag.NewFlagSet("dispatcher", flag.ContinueOnError) + fs.String(extra, "", "") + if err := fs.Parse([]string{"-" + extra, "x"}); err != nil { + t.Fatal(err) + } + if err := validateRecoveryFlags(fs, "uuid", "", "case", "/private/output"); err == nil { + t.Fatalf("accepted -%s", extra) + } + } + fs := flag.NewFlagSet("dispatcher", flag.ContinueOnError) + for _, values := range [][4]string{{"", "", "", ""}, {"uuid", "uuid", "case", "/file"}, {"uuid", "", "case", ""}, {"", "uuid", "case", "/file"}} { + if err := validateRecoveryFlags(fs, values[0], values[1], values[2], values[3]); err == nil { + t.Fatalf("invalid flags accepted: %v", values) + } + } +} diff --git a/cmd/dispatcher/account_recovery_unix.go b/cmd/dispatcher/account_recovery_unix.go new file mode 100644 index 00000000..4e700dd8 --- /dev/null +++ b/cmd/dispatcher/account_recovery_unix.go @@ -0,0 +1,21 @@ +//go:build linux || darwin + +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package main + +import ( + "errors" + "io/fs" + "os" + "syscall" +) + +func recoveryDirectoryOwned(info fs.FileInfo) error { + stat, ok := info.Sys().(*syscall.Stat_t) + if !ok || uint64(stat.Uid) != uint64(os.Geteuid()) { + return errors.New("recovery output parent must be owned by the current user") + } + return nil +} diff --git a/cmd/dispatcher/main.go b/cmd/dispatcher/main.go index 8c4d48dd..f2d4e54b 100644 --- a/cmd/dispatcher/main.go +++ b/cmd/dispatcher/main.go @@ -58,7 +58,24 @@ func main() { upgrade := flag.Bool("upgrade-database", false, "Apply the packaged migrations to the configured database, then exit. Stop the daemon and back the file up first") checkDatabase := flag.Bool("check-database", false, "Report whether the configured database is supported by this build, then exit; exit status 3 means it needs the upgrade, 4 that the upgrade drops recorded data") acceptDataLoss := flag.Bool("accept-data-loss", false, "With -upgrade-database, apply a migration that drops the recorded runs and their logs") + recoverAccount := flag.String("recover-unmapped-account", "", "Issue a one-time recovery code for an independently verified credentialless account UUID, then exit") + revokeRecovery := flag.String("revoke-account-recovery", "", "Revoke an unused administrator-issued recovery code for this account UUID, then exit") + recoveryCase := flag.String("recovery-case", "", "Private support-case reference recording the administrator's independent ownership verification") + recoveryOutput := flag.String("recovery-output", "", "Absent file in an owned mode-0700 directory for the one-time recovery code") flag.Parse() + recoveryRequested := false + flag.Visit(func(f *flag.Flag) { + switch f.Name { + case "recover-unmapped-account", "revoke-account-recovery", "recovery-case", "recovery-output": + recoveryRequested = true + } + }) + if recoveryRequested { + if err := validateRecoveryFlags(flag.CommandLine, *recoverAccount, *revokeRecovery, *recoveryCase, *recoveryOutput); err != nil { + fmt.Fprintf(os.Stderr, "dispatcher: %v\n", err) + os.Exit(1) + } + } initRequested, initOnly := false, true flag.Visit(func(f *flag.Flag) { if f.Name == "init-database" { @@ -105,6 +122,22 @@ func main() { if err != nil { panic(fmt.Sprintf("Failed to load dispatcher config: %v", err)) } + if recoveryRequested { + account := *recoverAccount + if account == "" { + account = *revokeRecovery + } + if err := administerAccountRecovery(context.Background(), cfg, account, *recoveryCase, *recoveryOutput, *revokeRecovery != ""); err != nil { + fmt.Fprintf(os.Stderr, "dispatcher: %v\n", err) + os.Exit(1) + } + if *revokeRecovery != "" { + fmt.Printf("unused administrator recovery for account %s revoked\n", account) + } else { + fmt.Printf("one-time account recovery code written to %s; expires in 24 hours\n", *recoveryOutput) + } + return + } // Checking a database only reads it, so it is safe while the daemon // serves it; the answer tells an upgrade whether there is work to do. diff --git a/docs/operations/auth-migration.md b/docs/operations/auth-migration.md index 03c7d570..4eece800 100644 --- a/docs/operations/auth-migration.md +++ b/docs/operations/auth-migration.md @@ -116,16 +116,80 @@ similar display name is not a successful migration. Keep unmapped accounts and their ownership records intact. Ask the operator to independently verify ownership through the deployment's support process; a UUID, -email address or knowledge of a measurement is not proof. There is currently no -product command for an administrator to claim or attach these historical -accounts. Until a reviewed recovery procedure exists, their access stays withheld. -Do not rewrite ownership rows, merge accounts by display name, or enable the local -development bypass to get past the problem. +email address or knowledge of a measurement is not proof. A trusted administrator +with access to the dispatcher host can restore access to an existing account +that has **neither credentials nor a linked provider identity**. This does not +merge accounts, transfer resources or adopt unowned runs. Until the independent +verification is complete, access stays withheld. + +Record the requester, the independent evidence and the approving administrator +in a private support case. The command records that case's reference and its +effective operating-system UID; it cannot decide whether the evidence proves +ownership. If several administrators use the same service account, the support +case must identify the person approving the recovery. Do not put personal +evidence or credentials in the case reference, shell arguments or logs. + +After taking the backup above, keep the dispatcher stopped and issue a code as +the database owner. Replace the example UUID and reference with the verified +account and a unique case reference: + +```sh +sudo install -d -m 700 -o debuglet -g debuglet /srv/debuglet-recovery +sudo -u debuglet debuglet-dispatcher \ + -config /etc/debuglet/dispatcher/dispatcher.toml \ + -recover-unmapped-account 01234567-89ab-cdef-0123-456789abcdef \ + -recovery-case SUPPORT-2026-42 \ + -recovery-output /srv/debuglet-recovery/SUPPORT-2026-42.txt +``` + +The output path must be absent and its real parent directory must be owned by +the invoking user with mode 0700. Use a trusted directory tree and keep it under +the administrator's exclusive control during the command. The complete code is +published in a mode-0600 file before the database transaction commits. It is never printed. Output +failure rolls the transaction back. If a commit cannot confirm success, the +command reports the uncertainty and retains the private file; inspect the audit +and explicitly revoke any pending grant before retrying. + +Issuance records the account, case reference, effective UID, issue time and expiry +in `account_recovery_audit`, and revokes every existing session of the account. +That also invalidates outstanding device approvals and pending identity links +bound to those sessions. The database contains only the code's verifier digest. +The code expires after 24 hours and works once through the existing +[`POST /auth/recover` procedure](../cli.md#recover-a-lost-account-key). Share the +file only with the independently verified requester through the deployment's +confidential support channel, then start the dispatcher. Successful recovery +records consumption and replaces the code with ordinary account credentials, +preserving the account's original UUID, role and resource ownership. The user can +then sign in and explicitly link an available provider identity. If that identity +already belongs to a different Debuglet account, linking is refused; continue +using the recovered account key and resolve the separate account conflict through +support. This command never moves provider identities between accounts. + +For a lost, expired or incorrectly delivered **unused** code, stop the service +and revoke it on the host: + +```sh +sudo -u debuglet debuglet-dispatcher \ + -config /etc/debuglet/dispatcher/dispatcher.toml \ + -revoke-account-recovery 01234567-89ab-cdef-0123-456789abcdef \ + -recovery-case SUPPORT-2026-42-REVOKE +``` + +Revocation records its time, UID and reference and removes only that pending +recovery credential. A replacement requires a new unique case reference and a +new absent output path. A consumed grant cannot be revoked or reused; the normal +account recovery rules apply after credentials have been issued. Inspect the +audit through a read-only database connection and retain the associated private +support record. Host administrators can modify the database, so this audit is an +operational record, not tamper-proof evidence against a compromised host. + +There is no public administrator recovery endpoint. Do not rewrite ownership +rows, merge accounts by display name, or enable the local development bypass. For an account that already has a recovery code, use the separate [account recovery procedure](../cli.md#recover-a-lost-account-key). It preserves that account's ownership while replacing its credentials and revoking sessions. -It cannot recover an unmapped account that never had such a code. +Knowledge of the account UUID cannot substitute for a genuine recovery code. ## Rollback without restoring UUID authentication diff --git a/internal/dispatcher/database/account_recovery.sql.go b/internal/dispatcher/database/account_recovery.sql.go new file mode 100644 index 00000000..93564f75 --- /dev/null +++ b/internal/dispatcher/database/account_recovery.sql.go @@ -0,0 +1,108 @@ +// Code generated by sqlc. DO NOT EDIT. +// versions: +// sqlc v1.31.1 +// source: account_recovery.sql + +package database + +import ( + "context" + "database/sql" + + "github.com/google/uuid" +) + +const consumeAdminAccountRecovery = `-- name: ConsumeAdminAccountRecovery :exec +UPDATE account_recovery_audit SET consumed_at = unixepoch() WHERE selector = ? +` + +func (q *Queries) ConsumeAdminAccountRecovery(ctx context.Context, selector string) error { + _, err := q.db.ExecContext(ctx, consumeAdminAccountRecovery, selector) + return err +} + +const deleteAdminRecoveryCredential = `-- name: DeleteAdminRecoveryCredential :exec +DELETE FROM user_credentials WHERE kind = 'recovery' AND selector = ? +` + +func (q *Queries) DeleteAdminRecoveryCredential(ctx context.Context, selector string) error { + _, err := q.db.ExecContext(ctx, deleteAdminRecoveryCredential, selector) + return err +} + +const getUnmappedAccountForRecovery = `-- name: GetUnmappedAccountForRecovery :one +SELECT users.id, users.uuid, users.name, users.role FROM users WHERE uuid = ? + AND NOT EXISTS (SELECT 1 FROM user_credentials WHERE user_id = users.id) + AND NOT EXISTS (SELECT 1 FROM oauth_identities WHERE user_id = users.id) + AND NOT EXISTS (SELECT 1 FROM account_recovery_audit WHERE user_id = users.id + AND consumed_at = 0 AND revoked_at = 0) +` + +func (q *Queries) GetUnmappedAccountForRecovery(ctx context.Context, argUuid uuid.UUID) (User, error) { + row := q.db.QueryRowContext(ctx, getUnmappedAccountForRecovery, argUuid) + var i User + err := row.Scan( + &i.ID, + &i.Uuid, + &i.Name, + &i.Role, + ) + return i, err +} + +const lockAccountForRecovery = `-- name: LockAccountForRecovery :execrows +UPDATE users SET name = name WHERE uuid = ? +` + +func (q *Queries) LockAccountForRecovery(ctx context.Context, argUuid uuid.UUID) (int64, error) { + result, err := q.db.ExecContext(ctx, lockAccountForRecovery, argUuid) + if err != nil { + return 0, err + } + return result.RowsAffected() +} + +const recordAdminAccountRecovery = `-- name: RecordAdminAccountRecovery :exec +INSERT INTO account_recovery_audit (selector, user_id, case_reference, issued_by_uid, issued_at, expires_at) +VALUES (?, ?, ?, ?, ?, ?) +` + +type RecordAdminAccountRecoveryParams struct { + Selector string + UserID int64 + CaseReference string + IssuedByUid int64 + IssuedAt int64 + ExpiresAt int64 +} + +func (q *Queries) RecordAdminAccountRecovery(ctx context.Context, arg RecordAdminAccountRecoveryParams) error { + _, err := q.db.ExecContext(ctx, recordAdminAccountRecovery, + arg.Selector, + arg.UserID, + arg.CaseReference, + arg.IssuedByUid, + arg.IssuedAt, + arg.ExpiresAt, + ) + return err +} + +const revokeAdminAccountRecovery = `-- name: RevokeAdminAccountRecovery :one +UPDATE account_recovery_audit SET revoked_at = unixepoch(), revoked_by_uid = ?, revocation_reference = ? +WHERE user_id = (SELECT id FROM users WHERE uuid = ?) AND consumed_at = 0 AND revoked_at = 0 +RETURNING selector +` + +type RevokeAdminAccountRecoveryParams struct { + RevokedByUid sql.NullInt64 + RevocationReference string + Uuid uuid.UUID +} + +func (q *Queries) RevokeAdminAccountRecovery(ctx context.Context, arg RevokeAdminAccountRecoveryParams) (string, error) { + row := q.db.QueryRowContext(ctx, revokeAdminAccountRecovery, arg.RevokedByUid, arg.RevocationReference, arg.Uuid) + var selector string + err := row.Scan(&selector) + return selector, err +} diff --git a/internal/dispatcher/database/auth.sql.go b/internal/dispatcher/database/auth.sql.go index 6f5743ae..38db70a8 100644 --- a/internal/dispatcher/database/auth.sql.go +++ b/internal/dispatcher/database/auth.sql.go @@ -135,6 +135,11 @@ FROM user_credentials INNER JOIN users ON users.id = user_credentials.user_id WHERE user_credentials.selector = ?1 AND user_credentials.kind = ?2 + AND NOT EXISTS ( + SELECT 1 FROM account_recovery_audit + WHERE account_recovery_audit.selector = user_credentials.selector + AND (expires_at <= unixepoch() OR consumed_at != 0 OR revoked_at != 0) + ) ` type GetUserCredentialParams struct { diff --git a/internal/dispatcher/database/migrations/00020_account_recovery.sql b/internal/dispatcher/database/migrations/00020_account_recovery.sql new file mode 100644 index 00000000..45b0b455 --- /dev/null +++ b/internal/dispatcher/database/migrations/00020_account_recovery.sql @@ -0,0 +1,21 @@ +-- +goose up +-- Host administrators may restore access to credentialless historical accounts. +-- Keep the approval reference and outcome, never the recovery code itself. +CREATE TABLE account_recovery_audit ( + selector TEXT PRIMARY KEY, + user_id INTEGER NOT NULL REFERENCES users(id), + case_reference TEXT NOT NULL UNIQUE, + issued_by_uid INTEGER NOT NULL, + issued_at INTEGER NOT NULL, + expires_at INTEGER NOT NULL, + consumed_at INTEGER NOT NULL DEFAULT 0, + revoked_at INTEGER NOT NULL DEFAULT 0, + revoked_by_uid INTEGER, + revocation_reference TEXT NOT NULL DEFAULT '' +); +CREATE UNIQUE INDEX account_recovery_pending ON account_recovery_audit(user_id) + WHERE consumed_at = 0 AND revoked_at = 0; + +-- +goose down +DELETE FROM user_credentials WHERE selector IN (SELECT selector FROM account_recovery_audit); +DROP TABLE account_recovery_audit; diff --git a/internal/dispatcher/database/models.go b/internal/dispatcher/database/models.go index 186e4ddb..b7e848f1 100644 --- a/internal/dispatcher/database/models.go +++ b/internal/dispatcher/database/models.go @@ -11,6 +11,19 @@ import ( "github.com/netsec-ethz/debuglet/internal/dispatcher/models" ) +type AccountRecoveryAudit struct { + Selector string + UserID int64 + CaseReference string + IssuedByUid int64 + IssuedAt int64 + ExpiresAt int64 + ConsumedAt int64 + RevokedAt int64 + RevokedByUid sql.NullInt64 + RevocationReference string +} + type AccountRunReservation struct { DebugletID int64 AccountID int64 diff --git a/internal/dispatcher/database/queries/account_recovery.sql b/internal/dispatcher/database/queries/account_recovery.sql new file mode 100644 index 00000000..003c3661 --- /dev/null +++ b/internal/dispatcher/database/queries/account_recovery.sql @@ -0,0 +1,24 @@ +-- name: LockAccountForRecovery :execrows +UPDATE users SET name = name WHERE uuid = ?; + +-- name: GetUnmappedAccountForRecovery :one +SELECT users.* FROM users WHERE uuid = ? + AND NOT EXISTS (SELECT 1 FROM user_credentials WHERE user_id = users.id) + AND NOT EXISTS (SELECT 1 FROM oauth_identities WHERE user_id = users.id) + AND NOT EXISTS (SELECT 1 FROM account_recovery_audit WHERE user_id = users.id + AND consumed_at = 0 AND revoked_at = 0); + +-- name: RecordAdminAccountRecovery :exec +INSERT INTO account_recovery_audit (selector, user_id, case_reference, issued_by_uid, issued_at, expires_at) +VALUES (?, ?, ?, ?, ?, ?); + +-- name: ConsumeAdminAccountRecovery :exec +UPDATE account_recovery_audit SET consumed_at = unixepoch() WHERE selector = ?; + +-- name: RevokeAdminAccountRecovery :one +UPDATE account_recovery_audit SET revoked_at = unixepoch(), revoked_by_uid = ?, revocation_reference = ? +WHERE user_id = (SELECT id FROM users WHERE uuid = ?) AND consumed_at = 0 AND revoked_at = 0 +RETURNING selector; + +-- name: DeleteAdminRecoveryCredential :exec +DELETE FROM user_credentials WHERE kind = 'recovery' AND selector = ?; diff --git a/internal/dispatcher/database/queries/auth.sql b/internal/dispatcher/database/queries/auth.sql index 362cede6..bbc92e1a 100644 --- a/internal/dispatcher/database/queries/auth.sql +++ b/internal/dispatcher/database/queries/auth.sql @@ -14,7 +14,12 @@ SELECT user_credentials.user_id, user_credentials.secret_hash, FROM user_credentials INNER JOIN users ON users.id = user_credentials.user_id WHERE user_credentials.selector = sqlc.arg(selector) - AND user_credentials.kind = sqlc.arg(kind); + AND user_credentials.kind = sqlc.arg(kind) + AND NOT EXISTS ( + SELECT 1 FROM account_recovery_audit + WHERE account_recovery_audit.selector = user_credentials.selector + AND (expires_at <= unixepoch() OR consumed_at != 0 OR revoked_at != 0) + ); /* diff --git a/internal/dispatcher/transport/api/admin_recovery_test.go b/internal/dispatcher/transport/api/admin_recovery_test.go new file mode 100644 index 00000000..6187f0e0 --- /dev/null +++ b/internal/dispatcher/transport/api/admin_recovery_test.go @@ -0,0 +1,112 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package api + +import ( + "encoding/json" + "net/http" + "testing" + "time" + + "github.com/google/uuid" + "github.com/netsec-ethz/debuglet/internal/dispatcher/database" + "github.com/netsec-ethz/debuglet/internal/dispatcher/models" +) + +func TestAdministratorRecoveryUsesExistingAccountAndConsumesOnce(t *testing.T) { + f := ccNewFixtureWith(t) + account, oldSession, _ := authAccount(t, f, "historical researcher") + other, _, _ := authAccount(t, f, "historical researcher") + user, err := database.New(f.db).GetUserByUUID(t.Context(), uuid.MustParse(account.ID)) + if err != nil { + t.Fatal(err) + } + if _, err := f.db.Exec("INSERT INTO owned_executors(executor_id,user_id,name,created_at) VALUES ('retained-node',?,'node',CURRENT_TIMESTAMP)", user.ID); err != nil { + t.Fatal(err) + } + code, selector, digest, err := NewRecoveryCredential() + if err != nil { + t.Fatal(err) + } + if _, err := f.db.Exec("DELETE FROM user_credentials WHERE user_id=?", user.ID); err != nil { + t.Fatal(err) + } + q := database.New(f.db) + if err := q.UpsertUserCredential(t.Context(), database.UpsertUserCredentialParams{UserID: user.ID, Kind: credentialRecovery, Selector: selector, SecretHash: digest, CreatedAt: models.NewUTCTime(time.Now())}); err != nil { + t.Fatal(err) + } + if err := q.RecordAdminAccountRecovery(t.Context(), database.RecordAdminAccountRecoveryParams{Selector: selector, UserID: user.ID, CaseReference: "verified-support-case", IssuedByUid: 1000, IssuedAt: time.Now().Unix(), ExpiresAt: time.Now().Add(time.Hour).Unix()}); err != nil { + t.Fatal(err) + } + if s, _ := authAs(t, f, code, http.MethodGet, "/me", nil); s != 401 { + t.Fatalf("recovery code used as session: %d", s) + } + status, _, body, _ := authRequest(t, f, http.MethodPost, "/auth/recover", credentialJSON(t, RecoverRequest{RecoveryCode: code}), nil) + if status != http.StatusOK { + t.Fatalf("recovery status=%d", status) + } + var recovered AccountResponse + if err := json.Unmarshal(body, &recovered); err != nil { + t.Fatal(err) + } + if recovered.ID != account.ID || recovered.Name != account.Name || recovered.Role != account.Role || recovered.AccountKey == "" || recovered.RecoveryCode == "" { + t.Fatal("recovery changed canonical account or issued no credentials") + } + if s, _ := authAs(t, f, oldSession, http.MethodGet, "/me", nil); s != 401 { + t.Fatalf("old session remains valid: %d", s) + } + if s, _ := authStatus(t, f, http.MethodPost, "/auth/recover", credentialJSON(t, RecoverRequest{RecoveryCode: code}), nil); s != 401 { + t.Fatalf("replayed code accepted: %d", s) + } + var owner, consumed int64 + if err := f.db.QueryRow("SELECT user_id FROM owned_executors WHERE executor_id='retained-node'").Scan(&owner); err != nil { + t.Fatal(err) + } + if err := f.db.QueryRow("SELECT consumed_at FROM account_recovery_audit WHERE selector=?", selector).Scan(&consumed); err != nil { + t.Fatal(err) + } + if owner != user.ID || consumed == 0 { + t.Fatalf("ownership/audit owner=%d consumed=%d", owner, consumed) + } + if other.ID == recovered.ID { + t.Fatal("display-name match joined accounts") + } + newSession := authLogin(t, f, recovered.AccountKey) + if s, _ := authAs(t, f, newSession, http.MethodGet, "/me", nil); s != 200 { + t.Fatalf("new credential unavailable: %d", s) + } +} + +func TestAdministratorRecoveryRejectsExpiredAndRevokedCodes(t *testing.T) { + for _, state := range []string{"expired", "revoked"} { + t.Run(state, func(t *testing.T) { + f := ccNewFixtureWith(t) + account, _, _ := authAccount(t, f, "account") + selector, _, ok := parseCredential(recoveryPrefix, account.RecoveryCode) + if !ok { + t.Fatal("fixture recovery code malformed") + } + user, err := database.New(f.db).GetUserByUUID(t.Context(), uuid.MustParse(account.ID)) + if err != nil { + t.Fatal(err) + } + expires, revoked := time.Now().Add(time.Hour).Unix(), int64(0) + if state == "expired" { + expires = 1 + } else { + revoked = time.Now().Unix() + } + if _, err := f.db.Exec("INSERT INTO account_recovery_audit(selector,user_id,case_reference,issued_by_uid,issued_at,expires_at,revoked_at) VALUES (?,?,'case',1000,1,?,?)", selector, user.ID, expires, revoked); err != nil { + t.Fatal(err) + } + if s, _ := authStatus(t, f, http.MethodPost, "/auth/recover", credentialJSON(t, RecoverRequest{RecoveryCode: account.RecoveryCode}), nil); s != 401 { + t.Fatalf("%s code accepted: %d", state, s) + } + var consumed int64 + if err := f.db.QueryRow("SELECT consumed_at FROM account_recovery_audit WHERE selector=?", selector).Scan(&consumed); err != nil || consumed != 0 { + t.Fatalf("refused code audit=%d err=%v", consumed, err) + } + }) + } +} diff --git a/internal/dispatcher/transport/api/auth.go b/internal/dispatcher/transport/api/auth.go index dc759a63..5d8ec091 100644 --- a/internal/dispatcher/transport/api/auth.go +++ b/internal/dispatcher/transport/api/auth.go @@ -154,6 +154,12 @@ func newCredential(prefix string) (token, selector string, digest []byte, err er return prefix + "_" + selector + "." + verifier, selector, digest, nil } +// NewRecoveryCredential creates the same recovery-code format used by account +// registration. Host administration stores its digest with a bounded lifetime. +func NewRecoveryCredential() (token, selector string, digest []byte, err error) { + return newCredential(recoveryPrefix) +} + // parseCredential splits a presented credential of the expected kind. A value // of another kind, a malformed one or an oversized one is rejected without // touching the database. diff --git a/internal/dispatcher/transport/api/handlers_auth.go b/internal/dispatcher/transport/api/handlers_auth.go index b1099138..bffa6e9c 100644 --- a/internal/dispatcher/transport/api/handlers_auth.go +++ b/internal/dispatcher/transport/api/handlers_auth.go @@ -149,6 +149,10 @@ func (h *Handler) PostRecover(c echo.Context) error { if !ok { return unauthorized() } + selector, _, _ := parseCredential(recoveryPrefix, strings.TrimSpace(req.RecoveryCode)) + if err := queries.ConsumeAdminAccountRecovery(ctx, selector); err != nil { + return apiErrorFrom(http.StatusInternalServerError, CodeInternal, "failed to recover the account", err) + } if err := queries.RevokeUserSessions(ctx, row.Uuid); err != nil { return apiErrorFrom(http.StatusInternalServerError, CodeInternal, "failed to revoke the account's sessions", err) } diff --git a/internal/storagecheck/init_test.go b/internal/storagecheck/init_test.go index 6506b58d..2e41ed9d 100644 --- a/internal/storagecheck/init_test.go +++ b/internal/storagecheck/init_test.go @@ -40,6 +40,7 @@ func TestBootstrapFresh(t *testing.T) { db := openSchemaDB(t, path) if role == Dispatcher { assertSchema(t, db, map[string]string{ + "account_recovery_audit": "selector user_id case_reference issued_by_uid issued_at expires_at consumed_at revoked_at revoked_by_uid revocation_reference", "attribution_chains": "executor_id chain_id anchor t0_ns interval_ns delay_epochs chain_length tag_spec first_seen_ns last_seen_ns", "attribution_keys": "executor_id chain_id epoch key disclosed_at_ns", "attribution_runs": "debuglet_id chain_id source_ip source_ip_observed active_from_ns active_to_ns", @@ -74,7 +75,7 @@ func TestBootstrapFresh(t *testing.T) { "oauth_login_attempts": "state_hash provider verifier nonce purpose session_selector expires_at", "pending_identity_links": "user_id provider issuer subject login session_selector expires_at", "device_logins": "selector verifier_hash user_code_hash audience scopes label expires_at next_poll_at poll_interval state approver_session user_id", - }, []string{"account_run_reservations_live", "attribution_runs_source_idx", "debuglet_logs_sequence_idx", "debuglets_uuid_idx", "device_logins_expiry", "executor_enrollment_tokens_executor_idx", "measurement_profiles_owner", "oauth_login_expiry", "owned_executors_user_idx", "sessions_user_idx", "users_uuid_idx"}, []int64{0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19}) + }, []string{"account_recovery_pending", "account_run_reservations_live", "attribution_runs_source_idx", "debuglet_logs_sequence_idx", "debuglets_uuid_idx", "device_logins_expiry", "executor_enrollment_tokens_executor_idx", "measurement_profiles_owner", "oauth_login_expiry", "owned_executors_user_idx", "sessions_user_idx", "users_uuid_idx"}, []int64{0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20}) dispatcherSchemaRoundTrip(t, db) } else { assertSchema(t, db, map[string]string{ diff --git a/internal/storagecheck/policy.go b/internal/storagecheck/policy.go index 467ecef0..217a53a4 100644 --- a/internal/storagecheck/policy.go +++ b/internal/storagecheck/policy.go @@ -31,7 +31,7 @@ const ( // an older database can then no longer answer them and must be refused instead // of failing later during service. const ( - MinimumDispatcherVersion int64 = 19 + MinimumDispatcherVersion int64 = 20 MinimumExecutorVersion int64 = 6 ) @@ -70,6 +70,7 @@ func PolicyFor(role Role) (Policy, error) { "transaction_states": nil, "transactions": nil, }, Tables: map[string][]string{ + "account_recovery_audit": {"selector", "user_id", "case_reference", "issued_by_uid", "issued_at", "expires_at", "consumed_at", "revoked_at", "revoked_by_uid", "revocation_reference"}, "allocation_reclamations": {"debuglet_id", "reclaimed_at"}, "measurement_profiles": {"id", "user_id", "document"}, "measurement_requests": {"debuglet_id", "document"}, From 2eab300a601f520650be478dfcc5d28270862d4e Mon Sep 17 00:00:00 2001 From: TheodorAdrienIsaak Mattli Date: Fri, 2 Oct 2026 15:10:52 +0200 Subject: [PATCH 2/8] Handle CILogon outages through the sign-in flow --- .../transport/api/cilogon_oidc_test.go | 14 +- .../transport/api/handlers_oauth.go | 3 + .../transport/api/provider_lifecycle_test.go | 127 ++++++++++++++++++ 3 files changed, 141 insertions(+), 3 deletions(-) create mode 100644 internal/dispatcher/transport/api/provider_lifecycle_test.go diff --git a/internal/dispatcher/transport/api/cilogon_oidc_test.go b/internal/dispatcher/transport/api/cilogon_oidc_test.go index a553c3ba..e0a723b7 100644 --- a/internal/dispatcher/transport/api/cilogon_oidc_test.go +++ b/internal/dispatcher/transport/api/cilogon_oidc_test.go @@ -24,6 +24,7 @@ type cilogonStub struct { mu sync.Mutex key, signingKey *rsa.PrivateKey kid, nonce, challenge string + failPath string claims map[string]any exchanges, keyRequests int } @@ -34,6 +35,10 @@ func newCILogonStub(t *testing.T, key *rsa.PrivateKey) *cilogonStub { p.server = httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { p.mu.Lock() defer p.mu.Unlock() + if r.URL.Path == p.failPath { + http.Error(w, "private provider diagnostic", http.StatusServiceUnavailable) + return + } w.Header().Set("Content-Type", "application/json") switch r.URL.Path { case "/.well-known/openid-configuration": @@ -97,9 +102,9 @@ func newCILogonStub(t *testing.T, key *rsa.PrivateKey) *cilogonStub { return p } -func (p *cilogonStub) fixture(t *testing.T) *ccFixture { +func (p *cilogonStub) fixture(t *testing.T, options ...Option) *ccFixture { t.Helper() - return ccNewFixtureWith(t, CookieSecure(true), CILogon(CILogonConfig{Enabled: true, Issuer: p.server.URL, ClientID: "test-id", ClientSecret: "test-secret", CallbackURL: "https://example.test/auth/cilogon/callback", SuccessURL: "https://example.test/console/"})) + return ccNewFixtureWith(t, append([]Option{CookieSecure(true), CILogon(CILogonConfig{Enabled: true, Issuer: p.server.URL, ClientID: "test-id", ClientSecret: "test-secret", CallbackURL: "https://example.test/auth/cilogon/callback", SuccessURL: "https://example.test/console/"})}, options...)...) } func cilogonResponse(t *testing.T, request *http.Request) *http.Response { @@ -113,12 +118,15 @@ func cilogonResponse(t *testing.T, request *http.Request) *http.Response { return response } -func (p *cilogonStub) begin(t *testing.T, f *ccFixture) *http.Request { +func (p *cilogonStub) begin(t *testing.T, f *ccFixture, cookies ...*http.Cookie) *http.Request { t.Helper() request, err := http.NewRequest(http.MethodGet, f.root.URL+"/auth/cilogon", nil) if err != nil { t.Fatal(err) } + for _, cookie := range cookies { + request.AddCookie(cookie) + } response := cilogonResponse(t, request) location, err := url.Parse(response.Header.Get("Location")) if err != nil { diff --git a/internal/dispatcher/transport/api/handlers_oauth.go b/internal/dispatcher/transport/api/handlers_oauth.go index 451c0460..38441d25 100644 --- a/internal/dispatcher/transport/api/handlers_oauth.go +++ b/internal/dispatcher/transport/api/handlers_oauth.go @@ -96,6 +96,9 @@ func (h *Handler) startProviderLogin(c echo.Context, provider, purpose, session } else { discovery, err := h.cilogonProvider(c.Request().Context()) if err != nil { + if purpose == "login" { + return h.oauthFailure(c, provider, "provider_unavailable") + } return apiError(http.StatusBadGateway, CodeInternal, "CILogon is temporarily unavailable; try again later") } cfg := h.cilogonClient(discovery) diff --git a/internal/dispatcher/transport/api/provider_lifecycle_test.go b/internal/dispatcher/transport/api/provider_lifecycle_test.go new file mode 100644 index 00000000..5fd20bec --- /dev/null +++ b/internal/dispatcher/transport/api/provider_lifecycle_test.go @@ -0,0 +1,127 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package api + +import ( + "crypto/rand" + "crypto/rsa" + "net/http" + "testing" + "time" +) + +func cilogonSessionCookie(t *testing.T, response *http.Response) *http.Cookie { + t.Helper() + if response.StatusCode != http.StatusFound || response.Header.Get("Location") != "https://example.test/console/" { + t.Fatalf("login response = %d %q", response.StatusCode, response.Header.Get("Location")) + } + for _, cookie := range response.Cookies() { + if cookie.Name == sessionCookieName && cookie.Value != "" { + return cookie + } + } + t.Fatal("login did not issue a session") + return nil +} + +func TestCILogonOutagesRecoverWithoutRestart(t *testing.T) { + key, err := rsa.GenerateKey(rand.Reader, 2048) + if err != nil { + t.Fatal(err) + } + for _, test := range []struct { + name, path string + expireDiscovery bool + }{ + {"discovery", "/.well-known/openid-configuration", false}, + {"expired-discovery", "/.well-known/openid-configuration", true}, + {"token", "/token", false}, + {"signing-keys", "/keys", false}, + } { + t.Run(test.name, func(t *testing.T) { + p := newCILogonStub(t, key) + var handler *Handler + f := p.fixture(t, func(h *Handler) { handler = h }) + if test.expireDiscovery { + p.begin(t, f) + handler.cilogonDiscovery.Lock() + handler.cilogonDiscovery.expires = time.Time{} + handler.cilogonDiscovery.Unlock() + } + p.mu.Lock() + p.failPath = test.path + p.mu.Unlock() + var response *http.Response + if test.path == "/.well-known/openid-configuration" { + request, err := http.NewRequest(http.MethodGet, f.root.URL+"/auth/cilogon", nil) + if err != nil { + t.Fatal(err) + } + response = cilogonResponse(t, request) + } else { + response = cilogonResponse(t, p.begin(t, f)) + } + if response.StatusCode != http.StatusFound || response.Header.Get("Location") != "https://example.test/console/?auth_error=provider_unavailable" { + t.Fatalf("outage response = %d %q", response.StatusCode, response.Header.Get("Location")) + } + var accounts, sessions int + if err := f.db.QueryRow("SELECT (SELECT COUNT(*) FROM users), (SELECT COUNT(*) FROM sessions)").Scan(&accounts, &sessions); err != nil { + t.Fatal(err) + } + if accounts != 0 || sessions != 0 { + t.Fatalf("outage created accounts=%d sessions=%d", accounts, sessions) + } + p.mu.Lock() + p.failPath = "" + p.mu.Unlock() + cilogonSessionCookie(t, cilogonResponse(t, p.begin(t, f))) + }) + } +} + +func TestCILogonReauthenticationReplacesOnlyAfterSuccessfulExchange(t *testing.T) { + key, err := rsa.GenerateKey(rand.Reader, 2048) + if err != nil { + t.Fatal(err) + } + p := newCILogonStub(t, key) + f := p.fixture(t) + oldCookie := cilogonSessionCookie(t, cilogonResponse(t, p.begin(t, f))) + oldClient, err := f.client(f.root.URL, false).WithCredential(oldCookie.Value) + if err != nil { + t.Fatal(err) + } + before, err := oldClient.Whoami(t.Context()) + if err != nil { + t.Fatal(err) + } + p.mu.Lock() + p.failPath = "/token" + p.mu.Unlock() + failed := cilogonResponse(t, p.begin(t, f, oldCookie)) + if failed.Header.Get("Location") != "https://example.test/console/?auth_error=provider_unavailable" { + t.Fatal("failed reauthentication did not report provider unavailability") + } + if _, err := oldClient.Whoami(t.Context()); err != nil { + t.Fatalf("failed reauthentication revoked existing session: %v", err) + } + p.mu.Lock() + p.failPath = "" + p.mu.Unlock() + newCookie := cilogonSessionCookie(t, cilogonResponse(t, p.begin(t, f, oldCookie))) + if newCookie.Value == oldCookie.Value { + t.Fatal("reauthentication reused the existing credential") + } + if _, err := oldClient.Whoami(t.Context()); !authIsUnauthorized(err) { + t.Fatalf("previous session survived replacement: %v", err) + } + newClient, err := f.client(f.root.URL, false).WithCredential(newCookie.Value) + if err != nil { + t.Fatal(err) + } + after, err := newClient.Whoami(t.Context()) + if err != nil || after.ID != before.ID { + t.Fatalf("reauthentication changed the account: %+v: %v", after, err) + } +} From 5b4c1711a41a049f6cb2ebf2d767fc65622f5dbe Mon Sep 17 00:00:00 2001 From: TheodorAdrienIsaak Mattli Date: Fri, 2 Oct 2026 15:14:19 +0200 Subject: [PATCH 3/8] Wire optional identity providers into managed deployments --- deploy/README.md | 35 +++++++++ deploy/ansible/cilogon-oidc.env.example | 4 ++ deploy/ansible/group_vars/dispatcher.yml | 11 +++ deploy/ansible/preflight-variables.yml | 32 +++++++++ .../ansible/roles/dispatcher/tasks/main.yml | 11 +++ .../templates/dispatcher.service.j2 | 3 + .../dispatcher/templates/dispatcher.toml.j2 | 14 ++++ deploy/ansible/update-config.yml | 26 ++++++- deploy/test/ansible-render.sh | 71 +++++++++++++++++++ 9 files changed, 205 insertions(+), 2 deletions(-) create mode 100644 deploy/ansible/cilogon-oidc.env.example diff --git a/deploy/README.md b/deploy/README.md index 37e7342a..571f5204 100644 --- a/deploy/README.md +++ b/deploy/README.md @@ -321,6 +321,41 @@ applications' callback URLs as the selected file to the dispatcher with mode 0600 and systemd reads it as an environment file; neither the secret nor the real file belongs in Git. +CILogon and browser-approved CLI credentials are opt-in. First obtain separate +approved CILogon registrations for staging and production, using the exact HTTPS +`/api/auth/cilogon/callback` URLs. Copy `ansible/cilogon-oidc.env.example` to +`ansible/secrets//cilogon-oidc.env`, fill in that environment's credentials, +and set mode 0600. No deployment or test creates a provider registration. + +Add these nonsecret settings to the chosen environment's variables, substituting +its actual public origin: + +```yaml +dispatcher_cilogon_oidc_enabled: true +dispatcher_cilogon_oidc_issuer: https://cilogon.org +dispatcher_authentication_public_url: https://dispatcher.example/api +dispatcher_authentication_device_verification_url: https://dispatcher.example/console/device +``` + +The CILogon callback and success URLs default to the configured +`dispatcher_base_url`. Use `https://test.cilogon.org` only with a separately +approved test client. Leave CILogon disabled until registration and real staging +sign-in have been verified. Both authentication URLs default empty; set both to +enable CLI approval, which also works with GitHub alone. The matching console +must serve `/console/device`. + +The dispatcher role installs the CILogon environment file with mode 0600 and +`no_log`; generated TOML and units contain no client secret. `update-config.yml` +also copies changed credentials, refreshes the service's environment-file list, +reloads systemd when needed and restarts the dispatcher. To rotate a secret, +replace the private source file with the provider-approved value and run the +normal configuration update in staging first. To stop new CILogon logins, disable +`dispatcher_cilogon_oidc_enabled` and update configuration; retain another usable +sign-in method. Disabling the provider does not revoke existing local sessions. +See [authentication operations](../docs/operations/authentication.md) for session +revocation and provider-failure handling. Offline render/provider fixtures do not +establish real CILogon or production acceptance. + The selected vars file supplies the official public API origin. Set these inputs for any other deployment: diff --git a/deploy/ansible/cilogon-oidc.env.example b/deploy/ansible/cilogon-oidc.env.example new file mode 100644 index 00000000..902a337a --- /dev/null +++ b/deploy/ansible/cilogon-oidc.env.example @@ -0,0 +1,4 @@ +# Copy to secrets/dev/cilogon-oidc.env or secrets/prod/cilogon-oidc.env. +# Use the matching approved client and chmod the real file 600. Never commit it. +CILOGON_CLIENT_ID=replace-with-approved-cilogon-client-id +CILOGON_CLIENT_SECRET=replace-with-approved-cilogon-client-secret diff --git a/deploy/ansible/group_vars/dispatcher.yml b/deploy/ansible/group_vars/dispatcher.yml index c0e8914a..8ec443ec 100644 --- a/deploy/ansible/group_vars/dispatcher.yml +++ b/deploy/ansible/group_vars/dispatcher.yml @@ -43,6 +43,17 @@ dispatcher_github_oauth_env_file: "{{ playbook_dir }}/secrets/{{ debuglet_env }} dispatcher_github_oauth_callback_url: "https://{{ dispatcher_base_url }}/api/auth/github/callback" dispatcher_github_oauth_success_url: "https://{{ dispatcher_base_url }}/console/" +# Enable only after separate staging/production CILogon clients are approved. +dispatcher_cilogon_oidc_enabled: false +dispatcher_cilogon_oidc_issuer: "https://cilogon.org" +dispatcher_cilogon_oidc_callback_url: "https://{{ dispatcher_base_url }}/api/auth/cilogon/callback" +dispatcher_cilogon_oidc_success_url: "https://{{ dispatcher_base_url }}/console/" +dispatcher_cilogon_oidc_env_file: "{{ playbook_dir }}/secrets/{{ debuglet_env }}/cilogon-oidc.env" + +# Set both URLs to enable browser-approved CLI credentials. +dispatcher_authentication_public_url: "" +dispatcher_authentication_device_verification_url: "" + # Whether the dispatcher requires a client certificate on its own listeners. # Only meaningful when dispatcher_disable_tls is false, and off by default: # turning it on refuses every executor that does not yet present a client diff --git a/deploy/ansible/preflight-variables.yml b/deploy/ansible/preflight-variables.yml index d5067707..938d1ff4 100644 --- a/deploy/ansible/preflight-variables.yml +++ b/deploy/ansible/preflight-variables.yml @@ -142,6 +142,38 @@ quiet: true when: dispatcher_github_oauth_enabled | bool + - name: Require complete browser credential URLs + ansible.builtin.assert: + that: + - (dispatcher_authentication_public_url | length > 0) == (dispatcher_authentication_device_verification_url | length > 0) + fail_msg: Set both dispatcher_authentication_public_url and dispatcher_authentication_device_verification_url, or leave both empty. + quiet: true + + - name: Require a supported CILogon issuer + ansible.builtin.assert: + that: + - dispatcher_cilogon_oidc_issuer in ['https://cilogon.org', 'https://test.cilogon.org'] + fail_msg: dispatcher_cilogon_oidc_issuer must be an approved CILogon production or test issuer. + quiet: true + when: dispatcher_cilogon_oidc_enabled | bool + + - name: Inspect local CILogon credentials + ansible.builtin.stat: + path: "{{ dispatcher_cilogon_oidc_env_file }}" + delegate_to: localhost + register: cilogon_oidc_credentials + when: dispatcher_cilogon_oidc_enabled | bool + + - name: Require private CILogon credentials + ansible.builtin.assert: + that: + - cilogon_oidc_credentials.stat.exists + - cilogon_oidc_credentials.stat.isreg + - cilogon_oidc_credentials.stat.mode in ['0600', '0400'] + fail_msg: Create the selected cilogon-oidc.env from cilogon-oidc.env.example and chmod it 600. Never commit this file. + quiet: true + when: dispatcher_cilogon_oidc_enabled | bool + - name: Require an authority for client certificates ansible.builtin.assert: that: diff --git a/deploy/ansible/roles/dispatcher/tasks/main.yml b/deploy/ansible/roles/dispatcher/tasks/main.yml index 5dce49ab..d7f80b55 100644 --- a/deploy/ansible/roles/dispatcher/tasks/main.yml +++ b/deploy/ansible/roles/dispatcher/tasks/main.yml @@ -66,6 +66,17 @@ when: dispatcher_github_oauth_enabled | bool notify: Restart dispatcher +- name: Deploy CILogon credentials + ansible.builtin.copy: + src: "{{ dispatcher_cilogon_oidc_env_file }}" + dest: "{{ config_dir }}/dispatcher/cilogon-oidc.env" + owner: "{{ debuglet_user }}" + group: "{{ debuglet_group }}" + mode: "0600" + no_log: true + when: dispatcher_cilogon_oidc_enabled | bool + notify: Restart dispatcher + - name: Install dispatcher systemd unit ansible.builtin.template: src: dispatcher.service.j2 diff --git a/deploy/ansible/roles/dispatcher/templates/dispatcher.service.j2 b/deploy/ansible/roles/dispatcher/templates/dispatcher.service.j2 index 7d921f3c..32561710 100644 --- a/deploy/ansible/roles/dispatcher/templates/dispatcher.service.j2 +++ b/deploy/ansible/roles/dispatcher/templates/dispatcher.service.j2 @@ -10,6 +10,9 @@ Group={{ debuglet_group }} {% if dispatcher_github_oauth_enabled | bool %} EnvironmentFile={{ config_dir }}/dispatcher/github-oauth.env {% endif %} +{% if dispatcher_cilogon_oidc_enabled | bool %} +EnvironmentFile={{ config_dir }}/dispatcher/cilogon-oidc.env +{% endif %} ExecStart={{ payload_prefix }}/bin/debuglet-dispatcher \ -config {{ config_dir }}/dispatcher/dispatcher.toml Restart=on-failure diff --git a/deploy/ansible/roles/dispatcher/templates/dispatcher.toml.j2 b/deploy/ansible/roles/dispatcher/templates/dispatcher.toml.j2 index 8a4456cd..d236df3d 100644 --- a/deploy/ansible/roles/dispatcher/templates/dispatcher.toml.j2 +++ b/deploy/ansible/roles/dispatcher/templates/dispatcher.toml.j2 @@ -65,3 +65,17 @@ allowed_origins = {{ dispatcher_cors_allowed_origins | to_json }} enabled = {{ dispatcher_github_oauth_enabled | bool | lower }} callback_url = "{{ dispatcher_github_oauth_callback_url }}" success_url = "{{ dispatcher_github_oauth_success_url }}" + +{% if dispatcher_cilogon_oidc_enabled | bool %} +[cilogon_oidc] +enabled = true +issuer = {{ dispatcher_cilogon_oidc_issuer | to_json }} +callback_url = {{ dispatcher_cilogon_oidc_callback_url | to_json }} +success_url = {{ dispatcher_cilogon_oidc_success_url | to_json }} +{% endif %} + +{% if dispatcher_authentication_public_url | length > 0 %} +[authentication] +public_url = {{ dispatcher_authentication_public_url | to_json }} +device_verification_url = {{ dispatcher_authentication_device_verification_url | to_json }} +{% endif %} diff --git a/deploy/ansible/update-config.yml b/deploy/ansible/update-config.yml index 8242d4d7..2f5d7ca2 100644 --- a/deploy/ansible/update-config.yml +++ b/deploy/ansible/update-config.yml @@ -44,14 +44,36 @@ register: dispatcher_github_oauth_credentials when: dispatcher_github_oauth_enabled | bool + - name: Update CILogon credentials + ansible.builtin.copy: + src: "{{ dispatcher_cilogon_oidc_env_file }}" + dest: "{{ config_dir }}/dispatcher/cilogon-oidc.env" + owner: "{{ debuglet_user }}" + group: "{{ debuglet_group }}" + mode: "0600" + no_log: true + register: dispatcher_cilogon_oidc_credentials + when: dispatcher_cilogon_oidc_enabled | bool + + - name: Update dispatcher systemd unit + ansible.builtin.template: + src: "{{ playbook_dir }}/roles/dispatcher/templates/dispatcher.service.j2" + dest: "{{ systemd_unit_dir }}/debuglet-dispatcher.service" + owner: root + group: root + mode: "0644" + register: dispatcher_unit + - name: Restart dispatcher if config changed ansible.builtin.systemd: name: debuglet-dispatcher state: restarted + daemon_reload: "{{ dispatcher_unit.changed }}" when: >- debuglet_manage_services | bool and - (dispatcher_config.changed or - (dispatcher_github_oauth_credentials.changed | default(false))) + (dispatcher_config.changed or dispatcher_unit.changed or + (dispatcher_github_oauth_credentials.changed | default(false)) or + (dispatcher_cilogon_oidc_credentials.changed | default(false))) - name: Update executor config hosts: executors diff --git a/deploy/test/ansible-render.sh b/deploy/test/ansible-render.sh index 4cf75e7b..31eccf98 100755 --- a/deploy/test/ansible-render.sh +++ b/deploy/test/ansible-render.sh @@ -119,6 +119,15 @@ printf '%s\n' 'dispatcher.fixture.invalid ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF printf '%s\n' 'GITHUB_OAUTH_CLIENT_ID=fixture-client' \ 'GITHUB_OAUTH_CLIENT_SECRET=fixture-secret' >"$work/github-oauth.env" chmod 0600 "$work/github-oauth.env" +printf '%s\n' 'CILOGON_CLIENT_ID=cilogon-fixture-client' \ + 'CILOGON_CLIENT_SECRET=cilogon-fixture-secret' >"$work/cilogon-oidc.env" +chmod 0600 "$work/cilogon-oidc.env" +cat >"$work/cilogon.yml" <&2 fi +# CILogon activation, secret rotation and disablement also use config updates. +if run "$work/cilogon-enable.log" update-config.yml --limit dispatcher \ + -e "deploy_version=$release_version" -e "@$work/cilogon.yml"; then + check 'CILogon activates through the configuration update' pass +else + check 'CILogon activates through the configuration update' fail + tail -20 "$work/cilogon-enable.log" >&2 +fi +expect 'the CILogon issuer is rendered' "$dispatcher_toml" 'issuer = "https://cilogon.org"' +expect 'browser CLI approval uses the configured audience' "$dispatcher_toml" 'public_url = "https://api.fixture.invalid/api"' +expect 'browser CLI approval uses the configured console' "$dispatcher_toml" 'device_verification_url = "https://api.fixture.invalid/console/device"' +expect 'the updated unit loads CILogon credentials' \ + "$host/etc/systemd/system/debuglet-dispatcher.service" \ + "EnvironmentFile=$host/etc/debuglet/dispatcher/cilogon-oidc.env" +expect 'the updated unit retains GitHub credentials' \ + "$host/etc/systemd/system/debuglet-dispatcher.service" \ + "EnvironmentFile=$host/etc/debuglet/dispatcher/github-oauth.env" +if cmp -s "$work/cilogon-oidc.env" "$host/etc/debuglet/dispatcher/cilogon-oidc.env" && + [ "$(stat -c %a "$host/etc/debuglet/dispatcher/cilogon-oidc.env")" = 600 ]; then + check 'CILogon credentials are installed privately' pass +else + check 'CILogon credentials are installed privately' fail +fi +for file in "$dispatcher_toml" "$host/etc/systemd/system/debuglet-dispatcher.service" "$work/cilogon-enable.log"; do + refute 'the CILogon client secret is excluded from rendered config and logs' "$file" 'cilogon-fixture-secret' +done +printf '%s\n' 'CILOGON_CLIENT_ID=cilogon-fixture-client' \ + 'CILOGON_CLIENT_SECRET=cilogon-fixture-rotated' >"$work/cilogon-oidc.env" +if run "$work/cilogon-rotate.log" update-config.yml --limit dispatcher \ + -e "deploy_version=$release_version" -e "@$work/cilogon.yml" && + cmp -s "$work/cilogon-oidc.env" "$host/etc/debuglet/dispatcher/cilogon-oidc.env"; then + check 'a configuration update replaces CILogon credentials' pass +else + check 'a configuration update replaces CILogon credentials' fail + tail -20 "$work/cilogon-rotate.log" >&2 +fi +refute 'rotation keeps the new secret out of deployment logs' "$work/cilogon-rotate.log" 'cilogon-fixture-rotated' +if run "$work/cilogon-disable.log" update-config.yml --limit dispatcher \ + -e "deploy_version=$release_version"; then + check 'CILogon can be disabled through a configuration update' pass +else + check 'CILogon can be disabled through a configuration update' fail + tail -20 "$work/cilogon-disable.log" >&2 +fi +refute 'disabled CILogon is removed from daemon configuration' "$dispatcher_toml" '[cilogon_oidc]' +refute 'disabled CILogon is not loaded by systemd' \ + "$host/etc/systemd/system/debuglet-dispatcher.service" 'cilogon-oidc.env' + # -------------------------------------------------- shared executor host --- # Snapshot prod, including links, before applying dev to the same temporary # host. The two environments must not share their active executable either. From cc4285a1b891af1b01c31026a6ff6876b43f394b Mon Sep 17 00:00:00 2001 From: TheodorAdrienIsaak Mattli Date: Mon, 5 Oct 2026 10:22:22 +0200 Subject: [PATCH 4/8] Record each order's settlement once and deliver it after a failed credit The payment decision of a terminal run was applied by an order-state write without a previous-state check and nothing recorded which run settled which order; when the write after the terminal report failed, the order stayed outstanding for good. Dispatcher schema 21 adds order_settlements, one immutable row per settled order (credit or refund, amount, currency, executor and run), and the pricing_rule column of transactions. The decision now lives in one place: the order moves from outstanding only through a conditional write, the settlement row and the earnings credit or chain refund commit with it, and a repeated or concurrent delivery leaves a settled order as it is. The maintenance loop settles terminal runs with a recorded exit code whose inline settlement failed, a bounded number per pass. A failed TEST run is refunded locally, moving nothing; TEST intents are still never refunded as a whole. Every intent records the name of the rule that priced it, and the API guide states that a USDC intent is a local record created without a chain call. GitHub issues #76, #77 and #78. --- docs/api.md | 2 + docs/operations/configuration.md | 4 +- docs/versions.md | 2 + internal/dispatcher/account_limits_test.go | 2 +- .../dispatcher/allocation_rejection_test.go | 9 +- .../dispatcher/cancel_persistence_test.go | 2 +- .../migrations/00021_order_settlements.sql | 38 ++++ internal/dispatcher/database/models.go | 28 ++- .../database/queries/transactions.sql | 29 +++ .../dispatcher/database/transactions.sql.go | 166 ++++++++++++++- .../dispatcher/dead_binding_cancel_test.go | 2 +- internal/dispatcher/executor_registry.go | 3 +- internal/dispatcher/output_failure_test.go | 2 +- .../payments/credit_concurrency_test.go | 32 +-- internal/dispatcher/payments/payments.go | 192 ++++++++++++------ internal/dispatcher/payments/payments_test.go | 65 ++++-- .../dispatcher/payments/settlement_test.go | 177 ++++++++++++++++ internal/dispatcher/rpc_handlers.go | 23 +-- internal/dispatcher/settlement_sweep.go | 44 ++++ internal/dispatcher/settlement_sweep_test.go | 173 ++++++++++++++++ internal/dispatcher/terminal_results_test.go | 18 +- .../transport/api/handlers_payment.go | 10 + .../transport/api/intent_pricing_test.go | 18 +- .../transport/api/payment_mode_test.go | 6 +- internal/storagecheck/init_test.go | 5 +- internal/storagecheck/policy.go | 5 +- 26 files changed, 902 insertions(+), 155 deletions(-) create mode 100644 internal/dispatcher/database/migrations/00021_order_settlements.sql create mode 100644 internal/dispatcher/payments/settlement_test.go create mode 100644 internal/dispatcher/settlement_sweep.go create mode 100644 internal/dispatcher/settlement_sweep_test.go diff --git a/docs/api.md b/docs/api.md index 9e5d92dc..22f5aecd 100644 --- a/docs/api.md +++ b/docs/api.md @@ -32,6 +32,8 @@ An order is priced from its executor's `price_per_bw`, the price per bit per sec A `TEST` intent has no payment backend: its transaction row is the intent, written in one database transaction together with its orders and, when the caller is an account, its owner, and it counts as paid on creation. The transaction records the total of its batch as its price and `TEST` as its currency, and every order records its own price and `TEST`; these amounts are bookkeeping only and move no funds. A `TEST` transaction recorded by a version older than 0.2.0-rc.2 carries the price 0 and an empty currency: it remains spendable as before, its amount can be read as the sum of its order rows, and nothing on the `TEST` path reads those two fields. `USDC` is the only chain method the HTTP API admits, and it is refused with `payments_disabled` while blockchain payments are disabled; this section describes `TEST`. +Every intent records the name of the rule that priced it in the `pricing_rule` column of its transaction; the rule above is `bw-s-ceil-ms-v1`, and a transaction written before the column existed carries an empty name and was priced by the rule of the release that wrote it. A `USDC` intent is a local record of the price, the auth key and the addresses the payer uses, created without any chain call, so an intent that fails leaves nothing external to reconcile. + ## Executor listing API 1.9 also adds `admission`, operator `display` metadata, the executor-reported `scion_isd_as` and `listeners` to `GET /executors`. Each value carries a source label; see [executor discovery](operations/executor-discovery.md#vantage-point-metadata). It also adds the executor's host probes: `capabilities.icmp`, `capabilities.enforcement_reason` and `clock`. Host platform detail is operator-only and is never listed; it appears only in result provenance ([host probes](operations/executor-discovery.md#host-probes)). diff --git a/docs/operations/configuration.md b/docs/operations/configuration.md index ee72df3c..824e17a8 100644 --- a/docs/operations/configuration.md +++ b/docs/operations/configuration.md @@ -98,7 +98,7 @@ binaries are installed; it does not change the state's contents or retention. | Location | Retained data and lifetime | | --- | --- | -| Dispatcher `database.path` | Accounts, hashed credentials and sessions, OAuth identities, executor enrollment/ownership, transaction/order records, saved profiles, batch and retry identities, submitted configuration, account reservations, result provenance, cancellation intent, and retained output/finality. Payload expiry is disabled by default; configured expiry or owner deletion retains identity, accounting and verification references. Announced TESLA chains, verified disclosed keys and run intervals follow the separate attribution retention period. | +| Dispatcher `database.path` | Accounts, hashed credentials and sessions, OAuth identities, executor enrollment/ownership, transaction/order records with the name of the pricing rule of each transaction, one immutable settlement record per settled order (`order_settlements`: credit or refund, amount, currency, executor and run), saved profiles, batch and retry identities, submitted configuration, account reservations, result provenance, cancellation intent, and retained output/finality. Payload expiry is disabled by default; configured expiry or owner deletion retains identity, accounting and verification references. Announced TESLA chains, verified disclosed keys and run intervals follow the separate attribution retention period. | | Executor `database.path` | Queued workload bytes and policy, original run bindings, retained terminal reports, TESLA chain descriptors and the durable output spool. Completed execution rows can be removed by normal cleanup; interrupted prior-binding rows remain quarantined for inspection and are never automatically resumed. Acknowledged output payload is released according to the output protocol. | | Role configuration and enrollment directory | Executor identity, configured inline secrets and paths to external TLS credentials. The current TESLA private chain is generated in memory on startup; persisted chain descriptors contain public anchors/schedules, not a recoverable history of private keys. | | Foreground state directory | Generated configuration, role/package identity, SQLite databases, readiness/shutdown records and rotated daemon logs. Use the same package/source revision; editing recorded metadata is not an upgrade. | @@ -117,7 +117,7 @@ OAuth, external TLS and SCION state need the deployment's complete backup plan; a database snapshot alone does not include every required credential or config. Never start original and restored copies with the same identity simultaneously. -Dispatcher schema 16 and executor schema 6 are the current schema boundaries. +Dispatcher schema 21 and executor schema 6 are the current schema boundaries. Recognized older databases require the explicit upgrade below. Dispatcher schemas below 3 and executor schemas below 2 lose recorded `debuglets` and `debuglet_logs` on upgrade and require explicit acceptance. Preserved paid rows diff --git a/docs/versions.md b/docs/versions.md index e588708a..f0546c09 100644 --- a/docs/versions.md +++ b/docs/versions.md @@ -95,3 +95,5 @@ API 1.10 adds optional [account-owned executor enrollment](operations/executor-o API 1.11 adds the public attribution lookups `GET /attribution/candidates` and `GET /attribution/keys` and deprecates `GET /executors/by-ip` and `GET /executors/{id}/tesla`, which keep working within API major 1. Dispatcher schema 14 stores the attribution history they answer from; upgrade explicitly before starting this build. The control protocol gains the optional `tesla_chain_length` (hello) and `tesla_key_anchor` (heartbeat) fields without a version change; an older peer leaves them empty. API 1.12 adds measurement profiles, batch details, explicit retry lineage, listener readiness and owner payload deletion. Retry clients require 1.12 so a dispatcher that only supports attribution cannot silently accept a request without retaining its retry identity. Dispatcher schema 15 stores the workflow metadata; schema 16 adds account reservations and payload tombstones. + +Dispatcher schema 21 records one settlement per order and the pricing rule of each transaction; this build refuses an older dispatcher database, so upgrade it explicitly before starting this build. diff --git a/internal/dispatcher/account_limits_test.go b/internal/dispatcher/account_limits_test.go index f3416414..3b808c7f 100644 --- a/internal/dispatcher/account_limits_test.go +++ b/internal/dispatcher/account_limits_test.go @@ -313,7 +313,7 @@ func TestPopulatedUpgradePreservesUnknownWorkAndFiniteAllowance(t *testing.T) { } history = append(history, row) } - if _, err := sqlitedb.Migrate(f.ctx, f.db, database.MigrationFS(), 16); err != nil { + if _, err := sqlitedb.Migrate(f.ctx, f.db, database.MigrationFS(), sqlitedb.Latest); err != nil { t.Fatal(err) } f.ph = payments.NewPaymentHandler(db, &config.DispatcherConfig{Sui: config.SuiConfig{Disabled: true}}, zap.NewNop()) diff --git a/internal/dispatcher/allocation_rejection_test.go b/internal/dispatcher/allocation_rejection_test.go index 01d99359..b5b16ead 100644 --- a/internal/dispatcher/allocation_rejection_test.go +++ b/internal/dispatcher/allocation_rejection_test.go @@ -135,7 +135,8 @@ func TestAllocationRejectionUnwindsThroughExit(t *testing.T) { t.Fatal("rejected allocation retained a destination allocation") } // Observe the existing terminal/effect path after executor unwind. - // TEST refund failure remains the current behavior. + // The failed run refunds its TEST order locally. A run whose + // transaction was replaced names no order and settles nothing. message := "allocation rejected: " + reason exit := &pb.DebugletExitRequest{DebugletId: deb.id.String(), ExitCode: 1, ErrorMessage: &message} if _, err := client.DebugletExit(ctx, exit); err != nil { @@ -146,7 +147,11 @@ func TestAllocationRejectionUnwindsThroughExit(t *testing.T) { if f.d.destinations.Len() != 0 { t.Fatal("existing exit path retained partial destination allocation") } - tgAssertOrder(t, f, deb, models.Outstanding) + if reason == "payment lookup" { + tgAssertOrder(t, f, deb, models.Outstanding) + } else { + tgAssertOrder(t, f, deb, models.Refunded) + } tgAssertEarnings(t, f, 0) after := f.snapshot(t) if _, err := client.DebugletExit(ctx, exit); err != nil { diff --git a/internal/dispatcher/cancel_persistence_test.go b/internal/dispatcher/cancel_persistence_test.go index a923f077..9c1d6d8a 100644 --- a/internal/dispatcher/cancel_persistence_test.go +++ b/internal/dispatcher/cancel_persistence_test.go @@ -47,7 +47,7 @@ func TestCancellationResultThatIsNotRecordedIsReported(t *testing.T) { t.Fatalf("abort once the write succeeds: %v", err) } tgAssertRow(t, f.row(t, a.id), models.RunStateExited, tgText("operator abort")) - tgAssertOrder(t, f, a, models.Outstanding) + tgAssertOrder(t, f, a, models.Refunded) tgAssertReserved(t, f, a, tgFloorB) after := f.snapshot(t) diff --git a/internal/dispatcher/database/migrations/00021_order_settlements.sql b/internal/dispatcher/database/migrations/00021_order_settlements.sql new file mode 100644 index 00000000..6103d074 --- /dev/null +++ b/internal/dispatcher/database/migrations/00021_order_settlements.sql @@ -0,0 +1,38 @@ +-- +goose up +-- One row per settled order: the local decision to credit the executor or to +-- refund the buyer, taken once from the run's terminal exit code. Whether money +-- moved on chain is not recorded here. Rows are never changed or removed. +CREATE TABLE order_settlements ( + transaction_id TEXT NOT NULL, + order_id INTEGER NOT NULL, + kind TEXT NOT NULL CHECK (kind IN ('credit', 'refund')), + amount INTEGER NOT NULL CHECK (amount >= 0), + currency TEXT NOT NULL, + executor_id TEXT NOT NULL, + debuglet_id INTEGER, + recorded_at TIMESTAMP NOT NULL, + PRIMARY KEY (transaction_id, order_id), + FOREIGN KEY (transaction_id, order_id) REFERENCES debuglet_order(transaction_id, order_id) +); +-- +goose StatementBegin +CREATE TRIGGER order_settlements_immutable BEFORE UPDATE ON order_settlements +BEGIN + SELECT RAISE(ABORT, 'order settlement is immutable'); +END; +-- +goose StatementEnd +-- +goose StatementBegin +CREATE TRIGGER order_settlements_retained BEFORE DELETE ON order_settlements +BEGIN + SELECT RAISE(ABORT, 'order settlement is immutable'); +END; +-- +goose StatementEnd + +-- The name of the rule that priced the intent. Rows written before this +-- column carry '' and were priced by the rule of the release that wrote them. +ALTER TABLE transactions ADD COLUMN pricing_rule TEXT NOT NULL DEFAULT ''; + +-- +goose down +ALTER TABLE transactions DROP COLUMN pricing_rule; +DROP TRIGGER order_settlements_retained; +DROP TRIGGER order_settlements_immutable; +DROP TABLE order_settlements; diff --git a/internal/dispatcher/database/models.go b/internal/dispatcher/database/models.go index b7e848f1..5010f126 100644 --- a/internal/dispatcher/database/models.go +++ b/internal/dispatcher/database/models.go @@ -227,6 +227,17 @@ type OauthLoginAttempt struct { ExpiresAt models.UTCTime } +type OrderSettlement struct { + TransactionID string + OrderID int64 + Kind string + Amount int64 + Currency string + ExecutorID string + DebugletID sql.NullInt64 + RecordedAt models.UTCTime +} + type OutputAccountUsage struct { AccountID int64 ChargedBytes int64 @@ -290,14 +301,15 @@ type Session struct { } type Transaction struct { - ID string - AuthKey string - Price int64 - Method string - ExpiresAt models.UTCTime - Hash string - Currency string - Status int64 + ID string + AuthKey string + Price int64 + Method string + ExpiresAt models.UTCTime + Hash string + Currency string + Status int64 + PricingRule string } type TransactionState struct { diff --git a/internal/dispatcher/database/queries/transactions.sql b/internal/dispatcher/database/queries/transactions.sql index 68a2fe37..7e7f92fa 100644 --- a/internal/dispatcher/database/queries/transactions.sql +++ b/internal/dispatcher/database/queries/transactions.sql @@ -7,6 +7,11 @@ INSERT INTO transactions (id, auth_key, price, currency, method, expires_at, sta VALUES (?, ?, ?, ?, ?, ?, ?, ?) RETURNING *; +-- name: SetTransactionPricingRule :exec +UPDATE transactions +SET pricing_rule = ? +WHERE id = ?; + -- name: UpdateTransactionStatus :exec UPDATE transactions SET status = ? @@ -55,6 +60,30 @@ SET state = ? WHERE transaction_id = ? AND order_id = ? RETURNING *; +-- name: TransitionDebugletOrder :execrows +UPDATE debuglet_order +SET state = sqlc.arg(to_state) +WHERE transaction_id = sqlc.arg(transaction_id) AND order_id = sqlc.arg(order_id) + AND state = sqlc.arg(from_state); + +-- name: InsertOrderSettlement :exec +INSERT INTO order_settlements (transaction_id, order_id, kind, amount, currency, executor_id, debuglet_id, recorded_at) +VALUES (?, ?, ?, ?, ?, ?, ?, ?); + +-- name: GetOrderSettlement :one +SELECT * FROM order_settlements +WHERE transaction_id = ? AND order_id = ?; + +-- name: ListPendingSettlements :many +SELECT sqlc.embed(d), e.exit_code FROM debuglet_order o +JOIN debuglets d ON d.id = o.debuglet_id + AND d.transaction_id = o.transaction_id AND d.order_id = o.order_id +JOIN measurement_execution e ON e.debuglet_id = d.id +WHERE o.state = sqlc.arg(outstanding_state) AND d.state = sqlc.arg(exited_state) + AND e.exit_code IS NOT NULL +ORDER BY d.id +LIMIT sqlc.arg(row_limit); + -- name: ClaimDebugletOrder :execrows UPDATE debuglet_order SET debuglet_id = sqlc.narg(debuglet_id) diff --git a/internal/dispatcher/database/transactions.sql.go b/internal/dispatcher/database/transactions.sql.go index 492c4d51..813f5b47 100644 --- a/internal/dispatcher/database/transactions.sql.go +++ b/internal/dispatcher/database/transactions.sql.go @@ -133,7 +133,7 @@ func (q *Queries) CreateEarnings(ctx context.Context, arg CreateEarningsParams) const createTransaction = `-- name: CreateTransaction :one INSERT INTO transactions (id, auth_key, price, currency, method, expires_at, status, hash) VALUES (?, ?, ?, ?, ?, ?, ?, ?) -RETURNING id, auth_key, price, method, expires_at, hash, currency, status +RETURNING id, auth_key, price, method, expires_at, hash, currency, status, pricing_rule ` type CreateTransactionParams struct { @@ -168,6 +168,7 @@ func (q *Queries) CreateTransaction(ctx context.Context, arg CreateTransactionPa &i.Hash, &i.Currency, &i.Status, + &i.PricingRule, ) return i, err } @@ -335,8 +336,34 @@ func (q *Queries) GetEarningsOf(ctx context.Context, executorID string) ([]Earni return items, nil } +const getOrderSettlement = `-- name: GetOrderSettlement :one +SELECT transaction_id, order_id, kind, amount, currency, executor_id, debuglet_id, recorded_at FROM order_settlements +WHERE transaction_id = ? AND order_id = ? +` + +type GetOrderSettlementParams struct { + TransactionID string + OrderID int64 +} + +func (q *Queries) GetOrderSettlement(ctx context.Context, arg GetOrderSettlementParams) (OrderSettlement, error) { + row := q.db.QueryRowContext(ctx, getOrderSettlement, arg.TransactionID, arg.OrderID) + var i OrderSettlement + err := row.Scan( + &i.TransactionID, + &i.OrderID, + &i.Kind, + &i.Amount, + &i.Currency, + &i.ExecutorID, + &i.DebugletID, + &i.RecordedAt, + ) + return i, err +} + const getTransactionByID = `-- name: GetTransactionByID :one -SELECT id, auth_key, price, method, expires_at, hash, currency, status FROM transactions +SELECT id, auth_key, price, method, expires_at, hash, currency, status, pricing_rule FROM transactions WHERE id = ? ` @@ -352,6 +379,7 @@ func (q *Queries) GetTransactionByID(ctx context.Context, id string) (Transactio &i.Hash, &i.Currency, &i.Status, + &i.PricingRule, ) return i, err } @@ -405,6 +433,97 @@ func (q *Queries) GetTransactionState(ctx context.Context, key string) (Transact return i, err } +const insertOrderSettlement = `-- name: InsertOrderSettlement :exec +INSERT INTO order_settlements (transaction_id, order_id, kind, amount, currency, executor_id, debuglet_id, recorded_at) +VALUES (?, ?, ?, ?, ?, ?, ?, ?) +` + +type InsertOrderSettlementParams struct { + TransactionID string + OrderID int64 + Kind string + Amount int64 + Currency string + ExecutorID string + DebugletID sql.NullInt64 + RecordedAt models.UTCTime +} + +func (q *Queries) InsertOrderSettlement(ctx context.Context, arg InsertOrderSettlementParams) error { + _, err := q.db.ExecContext(ctx, insertOrderSettlement, + arg.TransactionID, + arg.OrderID, + arg.Kind, + arg.Amount, + arg.Currency, + arg.ExecutorID, + arg.DebugletID, + arg.RecordedAt, + ) + return err +} + +const listPendingSettlements = `-- name: ListPendingSettlements :many +SELECT d.id, d.uuid, d.start_time, d.end_time, d.usage, d.ceil_bw, d.executor_id, d.addresses, d.state, d.error, d.transaction_id, d.order_id, d.dispatcher_incarnation, d.session_id, e.exit_code FROM debuglet_order o +JOIN debuglets d ON d.id = o.debuglet_id + AND d.transaction_id = o.transaction_id AND d.order_id = o.order_id +JOIN measurement_execution e ON e.debuglet_id = d.id +WHERE o.state = ?1 AND d.state = ?2 + AND e.exit_code IS NOT NULL +ORDER BY d.id +LIMIT ?3 +` + +type ListPendingSettlementsParams struct { + OutstandingState int64 + ExitedState models.DebugletRunState + RowLimit int64 +} + +type ListPendingSettlementsRow struct { + Debuglet Debuglet + ExitCode sql.NullInt64 +} + +func (q *Queries) ListPendingSettlements(ctx context.Context, arg ListPendingSettlementsParams) ([]ListPendingSettlementsRow, error) { + rows, err := q.db.QueryContext(ctx, listPendingSettlements, arg.OutstandingState, arg.ExitedState, arg.RowLimit) + if err != nil { + return nil, err + } + defer rows.Close() + var items []ListPendingSettlementsRow + for rows.Next() { + var i ListPendingSettlementsRow + if err := rows.Scan( + &i.Debuglet.ID, + &i.Debuglet.Uuid, + &i.Debuglet.StartTime, + &i.Debuglet.EndTime, + &i.Debuglet.Usage, + &i.Debuglet.CeilBw, + &i.Debuglet.ExecutorID, + &i.Debuglet.Addresses, + &i.Debuglet.State, + &i.Debuglet.Error, + &i.Debuglet.TransactionID, + &i.Debuglet.OrderID, + &i.Debuglet.DispatcherIncarnation, + &i.Debuglet.SessionID, + &i.ExitCode, + ); err != nil { + return nil, err + } + items = append(items, i) + } + if err := rows.Close(); err != nil { + return nil, err + } + if err := rows.Err(); err != nil { + return nil, err + } + return items, nil +} + const refundUnadmittedTransaction = `-- name: RefundUnadmittedTransaction :execrows UPDATE transactions SET status = ?1 @@ -446,6 +565,22 @@ func (q *Queries) SetRefundAddress(ctx context.Context, arg SetRefundAddressPara return err } +const setTransactionPricingRule = `-- name: SetTransactionPricingRule :exec +UPDATE transactions +SET pricing_rule = ? +WHERE id = ? +` + +type SetTransactionPricingRuleParams struct { + PricingRule string + ID string +} + +func (q *Queries) SetTransactionPricingRule(ctx context.Context, arg SetTransactionPricingRuleParams) error { + _, err := q.db.ExecContext(ctx, setTransactionPricingRule, arg.PricingRule, arg.ID) + return err +} + const settleEarning = `-- name: SettleEarning :exec UPDATE earnings SET current_balance = 0 @@ -462,6 +597,33 @@ func (q *Queries) SettleEarning(ctx context.Context, arg SettleEarningParams) er return err } +const transitionDebugletOrder = `-- name: TransitionDebugletOrder :execrows +UPDATE debuglet_order +SET state = ?1 +WHERE transaction_id = ?2 AND order_id = ?3 + AND state = ?4 +` + +type TransitionDebugletOrderParams struct { + ToState int64 + TransactionID string + OrderID int64 + FromState int64 +} + +func (q *Queries) TransitionDebugletOrder(ctx context.Context, arg TransitionDebugletOrderParams) (int64, error) { + result, err := q.db.ExecContext(ctx, transitionDebugletOrder, + arg.ToState, + arg.TransactionID, + arg.OrderID, + arg.FromState, + ) + if err != nil { + return 0, err + } + return result.RowsAffected() +} + const updateDebugletOrderState = `-- name: UpdateDebugletOrderState :one UPDATE debuglet_order SET state = ? diff --git a/internal/dispatcher/dead_binding_cancel_test.go b/internal/dispatcher/dead_binding_cancel_test.go index 9f97a9c1..4ddbfd0c 100644 --- a/internal/dispatcher/dead_binding_cancel_test.go +++ b/internal/dispatcher/dead_binding_cancel_test.go @@ -34,7 +34,7 @@ func assertCancelledWithoutSession(t *testing.T, f *tgFixture, run tgDebuglet) { t.Helper() tgAssertRow(t, f.row(t, run.id), models.RunStateExited, tgText(deadCancelError)) tgAssertReserved(t, f, run, 0) - tgAssertOrder(t, f, run, models.Outstanding) + tgAssertOrder(t, f, run, models.Refunded) request, err := f.d.Cancellation(f.ctx, run.id) if err != nil || request.Disposition != "unresolved" || request.Reason != "original_binding_unavailable" || request.AcknowledgedAt != nil || request.AttemptedAt != nil { t.Fatalf("local terminal claimed remote evidence: %+v, %v", request, err) diff --git a/internal/dispatcher/executor_registry.go b/internal/dispatcher/executor_registry.go index 34dadb26..3cb90eac 100644 --- a/internal/dispatcher/executor_registry.go +++ b/internal/dispatcher/executor_registry.go @@ -407,7 +407,7 @@ func (d *Dispatcher) runExpiry(done chan struct{}) { defer close(done) ticker := d.newExpiryTicker(d.leaseTiming.WatchdogInterval) defer ticker.Stop() - var lastSweep, lastRetention, lastPrune time.Time + var lastSweep, lastSettlement, lastRetention, lastPrune time.Time for { select { case <-d.expiryStop: @@ -417,6 +417,7 @@ func (d *Dispatcher) runExpiry(done chan struct{}) { d.expireOwner(owner) } lastSweep = d.sweepEndedWindows(lastSweep) + lastSettlement = d.sweepPendingSettlements(lastSettlement) if now := d.now(); lastRetention.IsZero() || now.Sub(lastRetention) >= 10*time.Second { d.sweepPayloadRetention() lastRetention = now diff --git a/internal/dispatcher/output_failure_test.go b/internal/dispatcher/output_failure_test.go index 0e0b7e33..89c84a5e 100644 --- a/internal/dispatcher/output_failure_test.go +++ b/internal/dispatcher/output_failure_test.go @@ -80,7 +80,7 @@ func TestOutputStreamFailureIsNoTerminalResult(t *testing.T) { t.Fatalf("real exit after the failed stream: %v", err) } tgAssertRow(t, f.row(t, run.id), models.RunStateExited, tgText("guest crashed")) - tgAssertOrder(t, f, run, models.Outstanding) + tgAssertOrder(t, f, run, models.Refunded) tgAssertReserved(t, f, run, tgFloorB) after := f.snapshot(t) if err := f.exit(t, run.id, 0, nil); err != nil { diff --git a/internal/dispatcher/payments/credit_concurrency_test.go b/internal/dispatcher/payments/credit_concurrency_test.go index b6c031c6..f73761e1 100644 --- a/internal/dispatcher/payments/credit_concurrency_test.go +++ b/internal/dispatcher/payments/credit_concurrency_test.go @@ -72,16 +72,16 @@ func TestConcurrentCompletionsCreditOnce(t *testing.T) { } } assertCreditedOnce(t, db) + assertSettledOnce(t, db, settlementCredit) if calls := rec.chain.Calls(); len(calls) != 0 { t.Fatalf("TEST completion reached the chain backend: %v", calls) } } -// A refund of a TEST order racing its completion never takes the order from -// the credit. TEST has no refund, so every refund fails and rolls back its -// state change whether it runs before or after the credit; the completion -// credits once. -func TestConcurrentCompletionAndTESTRefundCreditOnce(t *testing.T) { +// A failed-run refund of a TEST order racing its completion: exactly one of +// them settles the order, every call returns nil, and the order carries one +// settlement row that agrees with its state and the executor's income. +func TestConcurrentCompletionAndTESTRefundSettleOnce(t *testing.T) { db := newRefundDatabase(t) h, rec := newDisabledHandler(t, db, true, true) seedTESTOrder(t, db, models.Outstanding) @@ -89,22 +89,20 @@ func TestConcurrentCompletionAndTESTRefundCreditOnce(t *testing.T) { var calls []func() error for range creditCallers / 2 { calls = append(calls, - func() error { return h.SetDebugletOrderComplete(testDebuglet(), t.Context()) }, - func() error { return h.RefundDebugletOrder(testDebuglet(), testRefund, t.Context()) }, + func() error { return h.SettleTerminalOrder(t.Context(), testDebuglet(), 0) }, + func() error { return h.SettleTerminalOrder(t.Context(), testDebuglet(), 1) }, ) } for i, err := range raceCalls(calls) { - if i%2 == 0 { - if err != nil { - t.Fatalf("completion %d: %v", i, err) - } - continue - } - if err == nil || !strings.Contains(err.Error(), "Refunds not supported for currency TEST") { - t.Fatalf("TEST refund %d = %v, want it refused", i, err) + if err != nil { + t.Fatalf("settlement %d: %v", i, err) } } - assertCreditedOnce(t, db) + n, row := settlementOf(t, db) + if n != 1 { + t.Fatalf("%d settlement rows, want 1", n) + } + assertSettledOnce(t, db, row.Kind) if calls := rec.chain.Calls(); len(calls) != 0 { t.Fatalf("TEST completion or refund reached the chain backend: %v", calls) } @@ -156,8 +154,10 @@ func TestCompletionsOnTwoHandlesCreditOnce(t *testing.T) { } t.Logf("%d completions returned nil, %d lost the lock", succeeded, busy) assertCreditedOnce(t, db) + assertSettledOnce(t, db, settlementCredit) if err := second.SetDebugletOrderComplete(testDebuglet(), t.Context()); err != nil { t.Fatalf("completion after the race: %v", err) } assertCreditedOnce(t, other) + assertSettledOnce(t, other, settlementCredit) } diff --git a/internal/dispatcher/payments/payments.go b/internal/dispatcher/payments/payments.go index 8eb1a6d9..3d2d1182 100644 --- a/internal/dispatcher/payments/payments.go +++ b/internal/dispatcher/payments/payments.go @@ -255,7 +255,44 @@ func (p *PaymentHandler) CompleteTransaction(transactionId string, ctx context.C } } +// Settlement kinds recorded in order_settlements. +const ( + settlementCredit = "credit" + settlementRefund = "refund" +) + +// SettleTerminalOrder applies the payment decision for the order of a run that +// reached its terminal state: exit code 0 credits the executor, any other exit +// refunds the buyer. A USDC order is refunded on chain; a TEST order moves no +// funds and is only recorded as refunded. The decision is taken once per order: +// an order that is already credited or refunded is left as it is and nil is +// returned, so the terminal path and the settlement sweep may both deliver it. +func (p *PaymentHandler) SettleTerminalOrder(ctx context.Context, deb *database.Debuglet, exitCode int32) error { + if exitCode == 0 { + return p.settleOrder(ctx, deb, settlementCredit, "", false) + } + return p.settleOrder(ctx, deb, settlementRefund, "", false) +} + +// SetDebugletOrderComplete credits the executor with the price of the run's +// order. It is the credit leg of SettleTerminalOrder. func (p *PaymentHandler) SetDebugletOrderComplete(debuglet *database.Debuglet, ctx context.Context) error { + return p.settleOrder(ctx, debuglet, settlementCredit, "", false) +} + +// RefundDebugletOrder returns the price of the run's order to its buyer on +// chain. TEST orders hold no funds and are refused; SettleTerminalOrder records +// their refund locally instead. +func (p *PaymentHandler) RefundDebugletOrder(debuglet *database.Debuglet, refundAddress string, ctx context.Context) error { + return p.settleOrder(ctx, debuglet, settlementRefund, refundAddress, true) +} + +// settleOrder moves an Outstanding order to Credited or Refunded and records +// the decision in order_settlements in the same SQL transaction, together with +// the earnings credit or the chain refund. The conditional state write is the +// cheap guard against a second settlement, the settlement row's primary key the +// durable one; any failure rolls back all of it. +func (p *PaymentHandler) settleOrder(ctx context.Context, debuglet *database.Debuglet, kind string, refundAddress string, chainOnly bool) error { tx, err := p.db.BeginTx(ctx, nil) if err != nil { return fmt.Errorf("failed to begin transaction: %w", err) @@ -263,91 +300,112 @@ func (p *PaymentHandler) SetDebugletOrderComplete(debuglet *database.Debuglet, c defer tx.Rollback() queries := database.New(p.db).WithTx(tx) - p.logger.Debug("Update", zap.String("transactionId", debuglet.TransactionID), zap.Int64("orderId", debuglet.OrderID)) - // Read the order first: its currency decides whether crediting is allowed - // before any state is changed. - current, err := queries.GetDebugletOrder(ctx, database.GetDebugletOrderParams{ - TransactionID: debuglet.TransactionID, - OrderID: debuglet.OrderID, - }) + key := database.GetDebugletOrderParams{TransactionID: debuglet.TransactionID, OrderID: debuglet.OrderID} + // Read the order first: its currency decides whether the settlement is + // allowed before any state is changed. + order, err := queries.GetDebugletOrder(ctx, key) if err != nil { return fmt.Errorf("Failed to find debuglet order of %s: %w", debuglet.Uuid.String(), err) } - if err := p.requireChain(current.Currency, "credit order"); err != nil { + to := models.Credited + if kind == settlementRefund { + to = models.Refunded + if err := p.requireChain(order.Currency, "refund order"); err != nil { + return err + } + if order.Currency != "USDC" && (chainOnly || order.Currency != "TEST") { + return fmt.Errorf("Refunds not supported for currency %s", order.Currency) + } + } else if err := p.requireChain(order.Currency, "credit order"); err != nil { return err } - // Only an outstanding order is credited. A credited order is already - // included in the executor's earnings; a refunded order is not credited. - switch models.TransactionState(current.State) { - case models.Outstanding: - case models.Credited, models.Refunded: - return nil - default: - return fmt.Errorf("cannot credit order of %s in state %v", debuglet.Uuid.String(), models.TransactionState(current.State)) - } - order, err := queries.UpdateDebugletOrderState(ctx, database.UpdateDebugletOrderStateParams{ - State: int64(models.Credited), - TransactionID: debuglet.TransactionID, - OrderID: debuglet.OrderID, + + changed, err := queries.TransitionDebugletOrder(ctx, database.TransitionDebugletOrderParams{ + ToState: int64(to), TransactionID: key.TransactionID, OrderID: key.OrderID, FromState: int64(models.Outstanding), }) if err != nil { - return fmt.Errorf("Failed to update state of %s: %s", debuglet.Uuid.String(), err.Error()) + return fmt.Errorf("failed to update state of order of %s: %w", debuglet.Uuid.String(), err) } - if err := p.CreateEarningsIfNotExists(debuglet.ExecutorID, order.Currency, "", queries, ctx); err != nil { - return fmt.Errorf("failed to create earnings of %s: %w", debuglet.ExecutorID, err) + if changed == 0 { + // Only an outstanding order is settled. A credited order is already + // included in the executor's earnings; a refunded order is not credited. + current, err := queries.GetDebugletOrder(ctx, key) + if err != nil { + return fmt.Errorf("Failed to find debuglet order of %s: %w", debuglet.Uuid.String(), err) + } + switch models.TransactionState(current.State) { + case models.Credited, models.Refunded: + return nil + default: + return fmt.Errorf("cannot settle order of %s in state %v", debuglet.Uuid.String(), models.TransactionState(current.State)) + } } - if err := queries.AddEarnings(ctx, database.AddEarningsParams{ - Amount: order.Price, - ExecutorID: debuglet.ExecutorID, - Currency: order.Currency, + order.State = int64(to) + if err := queries.InsertOrderSettlement(ctx, database.InsertOrderSettlementParams{ + TransactionID: order.TransactionID, + OrderID: order.OrderID, + Kind: kind, + Amount: order.Price, + Currency: order.Currency, + ExecutorID: debuglet.ExecutorID, + DebugletID: order.DebugletID, + RecordedAt: models.NewUTCTime(time.Now()), }); err != nil { - return fmt.Errorf("failed to credit earnings of %s: %w", debuglet.ExecutorID, err) + return fmt.Errorf("failed to record settlement of order of %s: %w", debuglet.Uuid.String(), err) } - p.logger.Debug("Credited Executor", zap.String("ID", debuglet.ExecutorID), zap.String("currency", order.Currency), zap.Int64("amount", order.Price)) - return tx.Commit() -} -func (p *PaymentHandler) RefundDebugletOrder(debuglet *database.Debuglet, refundAddress string, ctx context.Context) error { - tx, err := p.db.BeginTx(ctx, nil) - if err != nil { - return fmt.Errorf("failed to begin transaction: %w", err) - } - defer tx.Rollback() - - queries := database.New(p.db).WithTx(tx) - order, err := queries.GetDebugletOrder(ctx, database.GetDebugletOrderParams{ - TransactionID: debuglet.TransactionID, - OrderID: debuglet.OrderID, - }) - if err != nil { - return fmt.Errorf("Failed to find debuglet order: %w", err) - } - if order.State == int64(models.Refunded) { - return fmt.Errorf("Debuglet has already been refunded") - } - if err := p.requireChain(order.Currency, "refund order"); err != nil { - return err + switch { + case kind == settlementCredit: + if err := p.CreateEarningsIfNotExists(debuglet.ExecutorID, order.Currency, "", queries, ctx); err != nil { + return fmt.Errorf("failed to create earnings of %s: %w", debuglet.ExecutorID, err) + } + if err := queries.AddEarnings(ctx, database.AddEarningsParams{ + Amount: order.Price, + ExecutorID: debuglet.ExecutorID, + Currency: order.Currency, + }); err != nil { + return fmt.Errorf("failed to credit earnings of %s: %w", debuglet.ExecutorID, err) + } + p.logger.Debug("Credited Executor", zap.String("ID", debuglet.ExecutorID), zap.String("currency", order.Currency), zap.Int64("amount", order.Price)) + case order.Currency == "USDC": + if err := p.sui.RefundDebuglet(&order, refundAddress, ctx); err != nil { + return err + } } + return tx.Commit() +} - order, err = queries.UpdateDebugletOrderState(ctx, database.UpdateDebugletOrderStateParams{ - TransactionID: debuglet.TransactionID, - OrderID: debuglet.OrderID, - State: int64(models.Refunded), +// SettlePendingOrders applies SettleTerminalOrder to at most limit Outstanding +// orders whose run is terminal with a recorded exit code, in run order. A run +// without a recorded exit code is not settled: nothing infers its outcome. An +// order that fails stays Outstanding for a later pass and the others are still +// settled; the numbers of settled and failed orders are returned with the +// first failure. +func (p *PaymentHandler) SettlePendingOrders(ctx context.Context, limit int) (settled, failed int, err error) { + pending, err := database.New(p.db).ListPendingSettlements(ctx, database.ListPendingSettlementsParams{ + OutstandingState: int64(models.Outstanding), ExitedState: models.RunStateExited, RowLimit: int64(limit), }) - if err != nil { - return err - } - switch order.Currency { - case "USDC": - err = p.sui.RefundDebuglet(&order, refundAddress, ctx) - default: - err = fmt.Errorf("Refunds not supported for currency %s", order.Currency) + return 0, 0, fmt.Errorf("failed to list pending settlements: %w", err) } - if err != nil { - return err + var first error + for _, row := range pending { + if ctx.Err() != nil { + break + } + run := row.Debuglet + if err := p.SettleTerminalOrder(ctx, &run, int32(row.ExitCode.Int64)); err != nil { + p.logger.Debug("Order settlement remains pending", zap.String("debugletID", run.Uuid.String())) + failed++ + if first == nil { + first = err + } + continue + } + settled++ + p.logger.Info("Settled order of terminal run", zap.String("debugletID", run.Uuid.String()), zap.Int64("exitCode", row.ExitCode.Int64)) } - return tx.Commit() + return settled, failed, first } // RefundTransaction retains transaction-wide refunds, including claimed orders. diff --git a/internal/dispatcher/payments/payments_test.go b/internal/dispatcher/payments/payments_test.go index c2baef1c..88272a7d 100644 --- a/internal/dispatcher/payments/payments_test.go +++ b/internal/dispatcher/payments/payments_test.go @@ -36,12 +36,12 @@ const waitBound = 2 * time.Second // the GetTransactionOrders pattern is anchored to avoid matching the longer // GetDebugletOrder statement. var ( - transactionColumns = []string{"id", "auth_key", "price", "method", "expires_at", "hash", "currency", "status"} + transactionColumns = []string{"id", "auth_key", "price", "method", "expires_at", "hash", "currency", "status", "pricing_rule"} orderColumns = []string{"transaction_id", "order_id", "executor_id", "price", "currency", "state", "refund_address", "debuglet_id"} earningsColumns = []string{"executor_id", "currency", "total_income", "current_balance", "sui_wallet_address"} getTransactionByIDQuery = regexp.QuoteMeta( - "SELECT id, auth_key, price, method, expires_at, hash, currency, status FROM transactions\nWHERE id = ?", + "SELECT id, auth_key, price, method, expires_at, hash, currency, status, pricing_rule FROM transactions\nWHERE id = ?", ) updateTransactionStatusQuery = regexp.QuoteMeta( "UPDATE transactions\nSET status = ?\nWHERE id = ?", @@ -55,6 +55,9 @@ var ( updateDebugletOrderStateQuery = regexp.QuoteMeta( "UPDATE debuglet_order\nSET state = ? \nWHERE transaction_id = ? AND order_id = ?\nRETURNING transaction_id, order_id, executor_id, price, currency, state, refund_address, debuglet_id", ) + transitionDebugletOrderQuery = regexp.QuoteMeta( + "UPDATE debuglet_order\nSET state = ?1\nWHERE transaction_id = ?2 AND order_id = ?3\n AND state = ?4", + ) ) const ( @@ -309,7 +312,7 @@ func waitErr(t *testing.T, ch <-chan error, what string) error { func transactionRow(method string, status models.TransactionState) *sqlmock.Rows { return sqlmock.NewRows(transactionColumns).AddRow( - testTxID, "", testPrice, method, time.Now().Add(5*time.Minute), testHash, method, int64(status), + testTxID, "", testPrice, method, time.Now().Add(5*time.Minute), testHash, method, int64(status), "", ) } @@ -697,21 +700,18 @@ func TestDisabledChainGuards(t *testing.T) { } // TestDisabledTESTPaths checks the database-only TEST behaviour in disabled -// mode: refunds keep failing with the existing unsupported-currency errors and -// never commit. Crediting a completed TEST order is covered on a real database -// by TestSetDebugletOrderCompleteCreditsOnce. +// mode: chain refunds keep failing with the existing unsupported-currency +// errors and never commit. Crediting a completed TEST order and refunding a +// failed TEST run locally are covered on a real database by +// TestSetDebugletOrderCompleteCreditsOnce and settlement_test.go. func TestDisabledTESTPaths(t *testing.T) { t.Run("RefundDebugletOrder TEST order is unsupported", func(t *testing.T) { db, mock := newMockDB(t) h, rec := newDisabledHandler(t, db, true, true) - // Existing behaviour: the state update happens inside the transaction - // and is rolled back with the unsupported-currency error. + // The currency is refused before any state is written. mock.ExpectBegin() expectOrderRead(mock, "TEST", models.Paid) - mock.ExpectQuery(updateDebugletOrderStateQuery). - WithArgs(int64(models.Refunded), testTxID, testOrderID). - WillReturnRows(orderRow("TEST", models.Refunded)) mock.ExpectRollback() err := h.RefundDebugletOrder(testDebuglet(), testRefund, context.Background()) @@ -727,16 +727,24 @@ func TestDisabledTESTPaths(t *testing.T) { assertMet(t, mock) }) - t.Run("RefundDebugletOrder already refunded order", func(t *testing.T) { + t.Run("SettleTerminalOrder already refunded TEST order", func(t *testing.T) { db, mock := newMockDB(t) - h, _ := newDisabledHandler(t, db, true, true) + h, rec := newDisabledHandler(t, db, true, true) + // The conditional transition finds no Outstanding order; the order + // is read again, found settled, and nothing is written. mock.ExpectBegin() - expectOrderRead(mock, "USDC", models.Refunded) + expectOrderRead(mock, "TEST", models.Refunded) + mock.ExpectExec(transitionDebugletOrderQuery). + WithArgs(int64(models.Refunded), testTxID, testOrderID, int64(models.Outstanding)). + WillReturnResult(sqlmock.NewResult(0, 0)) + expectOrderRead(mock, "TEST", models.Refunded) mock.ExpectRollback() - err := h.RefundDebugletOrder(testDebuglet(), testRefund, context.Background()) - if err == nil || err.Error() != "Debuglet has already been refunded" { - t.Fatalf("RefundDebugletOrder(refunded) = %v", err) + if err := h.SettleTerminalOrder(context.Background(), testDebuglet(), 1); err != nil { + t.Fatalf("SettleTerminalOrder(refunded) = %v", err) + } + if calls := rec.chain.Calls(); len(calls) != 0 { + t.Fatalf("settled order reached the chain backend: %v", calls) } assertMet(t, mock) }) @@ -887,10 +895,13 @@ func TestEnabledChainMethodsForwardToBackend(t *testing.T) { db, mock := newMockDB(t) h, rec := newEnabledHandler(t, db, enabledConfig(t)) mock.ExpectBegin() - expectOrderRead(mock, "USDC", models.Paid) - mock.ExpectQuery(updateDebugletOrderStateQuery). - WithArgs(int64(models.Refunded), testTxID, testOrderID). - WillReturnRows(orderRow("USDC", models.Refunded)) + expectOrderRead(mock, "USDC", models.Outstanding) + mock.ExpectExec(transitionDebugletOrderQuery). + WithArgs(int64(models.Refunded), testTxID, testOrderID, int64(models.Outstanding)). + WillReturnResult(sqlmock.NewResult(0, 1)) + mock.ExpectExec("INSERT INTO order_settlements"). + WithArgs(testTxID, testOrderID, "refund", testPrice, "USDC", testExecutor, nil, sqlmock.AnyArg()). + WillReturnResult(sqlmock.NewResult(0, 1)) mock.ExpectCommit() if err := h.RefundDebugletOrder(testDebuglet(), testRefund, context.Background()); err != nil { @@ -1228,6 +1239,7 @@ func TestSetDebugletOrderCompleteCreditsOnce(t *testing.T) { if got := totalIncome(t, db); got != testPrice { t.Fatalf("total income %d after two completions, want the order price %d once", got, testPrice) } + assertSettledOnce(t, db, settlementCredit) if calls := rec.chain.Calls(); len(calls) != 0 { t.Fatalf("TEST completion reached the chain backend: %v", calls) } @@ -1254,6 +1266,9 @@ BEGIN SELECT RAISE(ABORT, 'earnings update refused'); END;`); err != nil { if got := totalIncome(t, db); got != 0 { t.Fatalf("total income %d after a failed earnings write", got) } + if n, _ := settlementOf(t, db); n != 0 { + t.Fatalf("%d settlement rows after a failed earnings write", n) + } } // A refunded order is never credited. @@ -1271,6 +1286,9 @@ func TestSetDebugletOrderCompleteLeavesRefundedOrder(t *testing.T) { if got := totalIncome(t, db); got != 0 { t.Fatalf("a refunded order earned %d", got) } + if n, _ := settlementOf(t, db); n != 0 { + t.Fatalf("%d settlement rows written for an order refunded elsewhere", n) + } } // A TEST intent is a Paid TEST transaction that records what was locked (its @@ -1310,6 +1328,11 @@ func TestCreatePaymentIntentTESTStoresPriceAndCurrency(t *testing.T) { t.Fatalf("stored TEST transaction price=%d currency=%q method=%q, want %d %q %q", stored.Price, stored.Currency, stored.Method, testPrice, "TEST", "TEST") } + // The pricing rule is named by the API layer that priced the + // intent; this layer stores none. + if stored.PricingRule != "" { + t.Fatalf("stored TEST transaction pricing rule %q, want none", stored.PricingRule) + } if stored.Status != int64(models.Paid) || stored.AuthKey != "" || stored.Hash != testHash { t.Fatalf("stored TEST transaction status=%d auth_key=%q hash=%q, want %d %q %q", stored.Status, stored.AuthKey, stored.Hash, models.Paid, "", testHash) diff --git a/internal/dispatcher/payments/settlement_test.go b/internal/dispatcher/payments/settlement_test.go new file mode 100644 index 00000000..5c3262f0 --- /dev/null +++ b/internal/dispatcher/payments/settlement_test.go @@ -0,0 +1,177 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package payments + +import ( + "database/sql" + "strings" + "testing" + + "github.com/netsec-ethz/debuglet/internal/dispatcher/database" + "github.com/netsec-ethz/debuglet/internal/dispatcher/models" +) + +// settlementOf returns the number of settlement rows of the test order and, +// when there is one, the row itself. +func settlementOf(t *testing.T, db *sql.DB) (int, database.OrderSettlement) { + t.Helper() + var n int + if err := db.QueryRow("SELECT COUNT(*) FROM order_settlements").Scan(&n); err != nil { + t.Fatal(err) + } + if n == 0 { + return 0, database.OrderSettlement{} + } + row, err := database.New(db).GetOrderSettlement(t.Context(), database.GetOrderSettlementParams{ + TransactionID: testTxID, OrderID: testOrderID, + }) + if err != nil { + t.Fatal(err) + } + return n, row +} + +// assertSettledOnce checks the single settlement row of the test order and +// that the order state and the executor's income agree with it. +func assertSettledOnce(t *testing.T, db *sql.DB, kind string) { + t.Helper() + n, row := settlementOf(t, db) + if n != 1 || row.Kind != kind || row.Amount != testPrice || row.Currency != "TEST" || row.ExecutorID != testExecutor { + t.Fatalf("%d settlement rows, first %+v; want one %s of %d TEST to %s", n, row, kind, testPrice, testExecutor) + } + wantState, wantIncome := models.Credited, testPrice + if kind == settlementRefund { + wantState, wantIncome = models.Refunded, 0 + } + if got := orderState(t, db); got != wantState { + t.Fatalf("order state %v after a %s, want %v", got, kind, wantState) + } + if got := totalIncome(t, db); got != wantIncome { + t.Fatalf("total income %d after a %s, want %d", got, kind, wantIncome) + } +} + +// A successful run credits its order once and records one credit settlement; +// delivering the same decision again changes nothing. +func TestSettleTerminalOrderCreditsOnceWithOneSettlement(t *testing.T) { + db := newRefundDatabase(t) + h, rec := newDisabledHandler(t, db, true, true) + seedTESTOrder(t, db, models.Outstanding) + + for i := range 2 { + if err := h.SettleTerminalOrder(t.Context(), testDebuglet(), 0); err != nil { + t.Fatalf("settlement %d: %v", i+1, err) + } + } + assertSettledOnce(t, db, settlementCredit) + if calls := rec.chain.Calls(); len(calls) != 0 { + t.Fatalf("TEST settlement reached the chain backend: %v", calls) + } +} + +// A failed TEST run refunds its order locally: the order becomes Refunded with +// one refund settlement, nothing is credited and no chain call is made. A later +// success report for the same order does not credit it. +func TestSettleTerminalOrderRefundsFailedTESTRunLocally(t *testing.T) { + db := newRefundDatabase(t) + h, rec := newDisabledHandler(t, db, true, true) + seedTESTOrder(t, db, models.Outstanding) + + if err := h.SettleTerminalOrder(t.Context(), testDebuglet(), 3); err != nil { + t.Fatalf("refund of a failed TEST run: %v", err) + } + if err := h.SettleTerminalOrder(t.Context(), testDebuglet(), 0); err != nil { + t.Fatalf("credit after the refund: %v", err) + } + assertSettledOnce(t, db, settlementRefund) + if calls := rec.chain.Calls(); len(calls) != 0 { + t.Fatalf("TEST refund reached the chain backend: %v", calls) + } +} + +// A refused settlement row rolls back the state transition and the earnings +// credit, and the error is returned; once the row can be written the same +// decision settles the order. +func TestSettleTerminalOrderRollsBackWhenTheSettlementIsRefused(t *testing.T) { + for _, tc := range []struct { + name string + exitCode int32 + kind string + }{ + {"credit", 0, settlementCredit}, + {"TEST refund", 1, settlementRefund}, + } { + t.Run(tc.name, func(t *testing.T) { + db := newRefundDatabase(t) + h, _ := newDisabledHandler(t, db, true, true) + seedTESTOrder(t, db, models.Outstanding) + if _, err := db.ExecContext(t.Context(), `CREATE TRIGGER refuse_settlement BEFORE INSERT ON order_settlements +BEGIN SELECT RAISE(ABORT, 'settlement refused'); END;`); err != nil { + t.Fatal(err) + } + + err := h.SettleTerminalOrder(t.Context(), testDebuglet(), tc.exitCode) + if err == nil || !strings.Contains(err.Error(), "settlement refused") { + t.Fatalf("SettleTerminalOrder = %v, want the refused settlement", err) + } + if got := orderState(t, db); got != models.Outstanding { + t.Fatalf("order state %v after a refused settlement, want %v", got, models.Outstanding) + } + if got := totalIncome(t, db); got != 0 { + t.Fatalf("total income %d after a refused settlement", got) + } + var earnings int + if err := db.QueryRow("SELECT COUNT(*) FROM earnings").Scan(&earnings); err != nil || earnings != 0 { + t.Fatalf("%d earnings rows after a refused settlement (%v)", earnings, err) + } + if n, _ := settlementOf(t, db); n != 0 { + t.Fatalf("%d settlement rows after a refused settlement", n) + } + + if _, err := db.ExecContext(t.Context(), "DROP TRIGGER refuse_settlement"); err != nil { + t.Fatal(err) + } + if err := h.SettleTerminalOrder(t.Context(), testDebuglet(), tc.exitCode); err != nil { + t.Fatalf("settlement after the refusal ended: %v", err) + } + assertSettledOnce(t, db, tc.kind) + }) + } +} + +// A settlement row is never changed or removed. +func TestOrderSettlementIsImmutable(t *testing.T) { + db := newRefundDatabase(t) + h, _ := newDisabledHandler(t, db, true, true) + seedTESTOrder(t, db, models.Outstanding) + if err := h.SettleTerminalOrder(t.Context(), testDebuglet(), 0); err != nil { + t.Fatal(err) + } + for _, statement := range []string{ + "UPDATE order_settlements SET kind = 'refund'", + "UPDATE order_settlements SET amount = 0", + "DELETE FROM order_settlements", + } { + if _, err := db.ExecContext(t.Context(), statement); err == nil || !strings.Contains(err.Error(), "order settlement is immutable") { + t.Fatalf("%s = %v, want it refused", statement, err) + } + } + assertSettledOnce(t, db, settlementCredit) +} + +// An order in a state other than Outstanding, Credited or Refunded is not +// settled and the state is reported. +func TestSettleTerminalOrderRefusesAnUnsettleableState(t *testing.T) { + db := newRefundDatabase(t) + h, _ := newDisabledHandler(t, db, true, true) + seedTESTOrder(t, db, models.Aborted) + + err := h.SettleTerminalOrder(t.Context(), testDebuglet(), 0) + if err == nil || !strings.Contains(err.Error(), "cannot settle order") { + t.Fatalf("SettleTerminalOrder(aborted order) = %v", err) + } + if n, _ := settlementOf(t, db); n != 0 || orderState(t, db) != models.Aborted || totalIncome(t, db) != 0 { + t.Fatalf("an aborted order was settled: %d rows, state %v", n, orderState(t, db)) + } +} diff --git a/internal/dispatcher/rpc_handlers.go b/internal/dispatcher/rpc_handlers.go index 90c26833..7199867a 100644 --- a/internal/dispatcher/rpc_handlers.go +++ b/internal/dispatcher/rpc_handlers.go @@ -821,22 +821,15 @@ func (d *Dispatcher) sendFairshare(ctx context.Context, origin *rpc.Mutation, de } // settleTerminalPayment preserves the winner's exit-code-based payment decision. -// Resource release is separate and never retries payment effects. +// Resource release is separate and never retries payment effects. A failure is +// logged here; the settlement sweep delivers the decision later. func (d *Dispatcher) settleTerminalPayment(ctx context.Context, deb *database.Debuglet, exitCode int32) { - switch exitCode { - case 0: - //credit executor - d.logger.Debug("Debuglet Completed. Credit executor") - if err := d.Payment.SetDebugletOrderComplete(deb, ctx); err != nil { - d.logger.Warn("Failed to credit executor for debuglet", zap.String("debugletID", deb.Uuid.String())) - d.logger.Debug("Private runtime diagnostic", zap.String("debugletID", deb.Uuid.String()), zap.String("operation", "Failed to credit executor for debuglet"), zap.String("error", daemonlog.Diagnostic(err))) - } - default: - //refund - d.logger.Debug("Debuglet Aborted. Refund Buyer") - if err := d.Payment.RefundDebugletOrder(deb, "", ctx); err != nil { - d.logger.Warn("Failed to refund debuglet order", zap.String("debugletID", deb.Uuid.String())) - d.logger.Debug("Private runtime diagnostic", zap.String("debugletID", deb.Uuid.String()), zap.String("operation", "Failed to refund debuglet order"), zap.String("error", daemonlog.Diagnostic(err))) + if err := d.Payment.SettleTerminalOrder(ctx, deb, exitCode); err != nil { + operation := "Failed to credit executor for debuglet" + if exitCode != 0 { + operation = "Failed to refund debuglet order" } + d.logger.Warn(operation, zap.String("debugletID", deb.Uuid.String())) + d.logger.Debug("Private runtime diagnostic", zap.String("debugletID", deb.Uuid.String()), zap.String("operation", operation), zap.String("error", daemonlog.Diagnostic(err))) } } diff --git a/internal/dispatcher/settlement_sweep.go b/internal/dispatcher/settlement_sweep.go new file mode 100644 index 00000000..3ba11658 --- /dev/null +++ b/internal/dispatcher/settlement_sweep.go @@ -0,0 +1,44 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package dispatcher + +import ( + "context" + "time" + + "github.com/netsec-ethz/debuglet/internal/daemonlog" + "go.uber.org/zap" +) + +const ( + settlementSweepInterval = 30 * time.Second + settlementSweepBound = 5 * time.Second + settlementSweepLimit = 32 +) + +// sweepPendingSettlements delivers the payment decision of terminal runs whose +// order is still Outstanding, for example because the settlement after the +// terminal report failed. The terminal row and its recorded exit code are the +// request and settlement is idempotent per order, so an order settled by the +// terminal path meanwhile is left as it is. Each pass settles at most +// settlementSweepLimit orders. +func (d *Dispatcher) sweepPendingSettlements(last time.Time) time.Time { + now := d.now() + if !last.IsZero() && now.Sub(last) < settlementSweepInterval { + return last + } + d.mu.RLock() + closed := d.closed + d.mu.RUnlock() + if closed || d.Payment == nil { + return last + } + ctx, cancel := context.WithTimeout(context.Background(), settlementSweepBound) + defer cancel() + if settled, failed, err := d.Payment.SettlePendingOrders(ctx, settlementSweepLimit); err != nil { + d.logger.Warn("Pending order settlements remain", zap.Int("settled", settled), zap.Int("failed", failed)) + d.logger.Debug("Private runtime diagnostic", zap.String("error", daemonlog.Diagnostic(err))) + } + return now +} diff --git a/internal/dispatcher/settlement_sweep_test.go b/internal/dispatcher/settlement_sweep_test.go new file mode 100644 index 00000000..9f5da7d8 --- /dev/null +++ b/internal/dispatcher/settlement_sweep_test.go @@ -0,0 +1,173 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package dispatcher + +import ( + "testing" + "time" + + "github.com/netsec-ethz/debuglet/internal/dispatcher/models" +) + +// ssSettlements counts the recorded order settlements of kind. +func ssSettlements(t *testing.T, f *tgFixture, kind string) int { + t.Helper() + var n int + if err := f.db.QueryRowContext(f.ctx, "SELECT COUNT(*) FROM order_settlements WHERE kind = ?", kind).Scan(&n); err != nil { + t.Fatal(err) + } + return n +} + +// ssRefuseSettlements makes every settlement write fail until +// ssAllowSettlements is called. +func ssRefuseSettlements(t *testing.T, f *tgFixture) { + t.Helper() + if _, err := f.db.ExecContext(f.ctx, `CREATE TRIGGER ss_refuse_settlement BEFORE INSERT ON order_settlements +BEGIN SELECT RAISE(ABORT, 'settlement refused'); END;`); err != nil { + t.Fatal(err) + } +} + +func ssAllowSettlements(t *testing.T, f *tgFixture) { + t.Helper() + if _, err := f.db.ExecContext(f.ctx, "DROP TRIGGER ss_refuse_settlement"); err != nil { + t.Fatal(err) + } +} + +// ssClaim records run as the run of its order, as admission does; seedDirect +// creates the run without that claim. +func ssClaim(t *testing.T, f *tgFixture, run tgDebuglet) { + t.Helper() + if _, err := f.db.ExecContext(f.ctx, "UPDATE debuglet_order SET debuglet_id = (SELECT id FROM debuglets WHERE uuid = ?) WHERE transaction_id = ? AND order_id = ?", + run.id, run.txID, run.orderID); err != nil { + t.Fatal(err) + } +} + +// ssExit is one exit report of a run. +type ssExit struct { + run tgDebuglet + code int32 +} + +// ssExitRefused reports the exits of runs while settlement is refused, so the +// terminal path leaves their orders Outstanding, and then reopens the database +// in a dispatcher whose maintenance loop has not started; prepare runs on it +// first. Settlement is allowed again in the reopened database. +func ssExitRefused(t *testing.T, f *tgFixture, exits []ssExit, prepare ...func(*Dispatcher)) *tgFixture { + t.Helper() + ssRefuseSettlements(t, f) + for _, exit := range exits { + ssClaim(t, f, exit.run) + if err := f.exit(t, exit.run.id, exit.code, nil); err != nil { + t.Fatalf("exit %d of %s: %v", exit.code, exit.run.id, err) + } + if row := f.row(t, exit.run.id); row.State != models.RunStateExited { + t.Fatalf("run %s is %s after its exit", exit.run.id, row.State) + } + tgAssertOrder(t, f, exit.run, models.Outstanding) + } + tgAssertEarnings(t, f, 0) + // While the settlement is still refused a pass settles nothing and + // reports the failure. + if settled, failed, err := f.ph.SettlePendingOrders(f.ctx, settlementSweepLimit); settled != 0 || failed != len(exits) || err == nil { + t.Fatalf("pass while refused settled %d, failed %d, error %v", settled, failed, err) + } + g := reopenTG(t, f, prepare...) + ssAllowSettlements(t, g) + return g +} + +// A terminal run whose settlement failed after the terminal report is settled +// by the next pass of the maintenance loop, also after a restart, once: the +// successful run is credited and the failed TEST run refunded locally. A +// second pass finds nothing to settle. +func TestSettlementSweepDeliversFailedInlineSettlements(t *testing.T) { + f := newTGFixture(t, nil) + succeeded, failed := f.seedDirect(t, tgFloorA), f.seedDirect(t, tgFloorB) + loop := newWELoop() + g := ssExitRefused(t, f, []ssExit{{succeeded, 0}, {failed, 3}}, loop.install) + if err := g.d.RestoreScheduler(g.ctx); err != nil { + t.Fatalf("restore: %v", err) + } + loop.tick(t) + tgAssertOrder(t, g, succeeded, models.Credited) + tgAssertOrder(t, g, failed, models.Refunded) + tgAssertEarnings(t, g, tgOrderPrice(tgFloorA)) + if credits, refunds := ssSettlements(t, g, "credit"), ssSettlements(t, g, "refund"); credits != 1 || refunds != 1 { + t.Fatalf("%d credit and %d refund settlements, want one each", credits, refunds) + } + + if settled, failed, err := g.ph.SettlePendingOrders(g.ctx, settlementSweepLimit); settled != 0 || failed != 0 || err != nil { + t.Fatalf("second pass settled %d, failed %d, error %v", settled, failed, err) + } + loop.set(time.Now().Add(time.Hour)) + loop.tick(t) + tgAssertEarnings(t, g, tgOrderPrice(tgFloorA)) + if n := ssSettlements(t, g, "credit") + ssSettlements(t, g, "refund"); n != 2 { + t.Fatalf("%d settlements after a second pass, want 2", n) + } +} + +// Only an order whose run is terminal with a recorded exit code is settled. A +// run that is not terminal, and a terminal run without a recorded exit code, +// keep their order Outstanding: nothing infers an outcome. +func TestSettlementSweepSkipsRunsWithoutATerminalExitCode(t *testing.T) { + f := newTGFixture(t, nil) + running, unknown := f.seedDirect(t, tgFloorA), f.seedDirect(t, tgFloorB) + ssClaim(t, f, running) + ssClaim(t, f, unknown) + // The run that is not terminal has an exit code recorded, so only its + // state keeps it from being settled. + if _, err := f.db.ExecContext(f.ctx, "INSERT INTO measurement_execution (debuglet_id, exit_code) SELECT id, 0 FROM debuglets WHERE uuid = ?", running.id); err != nil { + t.Fatal(err) + } + if _, err := f.db.ExecContext(f.ctx, "UPDATE debuglets SET state = ? WHERE uuid = ?", models.RunStateExited, unknown.id); err != nil { + t.Fatal(err) + } + + if settled, failed, err := f.ph.SettlePendingOrders(f.ctx, settlementSweepLimit); settled != 0 || failed != 0 || err != nil { + t.Fatalf("pass settled %d, failed %d, error %v", settled, failed, err) + } + f.d.sweepPendingSettlements(time.Time{}) + tgAssertOrder(t, f, running, models.Outstanding) + tgAssertOrder(t, f, unknown, models.Outstanding) + tgAssertEarnings(t, f, 0) + if n := ssSettlements(t, f, "credit") + ssSettlements(t, f, "refund"); n != 0 { + t.Fatalf("%d settlements recorded for unsettleable runs", n) + } +} + +// A pass settles at most its limit, in run order; the rest waits for the next. +func TestSettlementSweepIsBoundedByItsLimit(t *testing.T) { + f := newTGFixture(t, nil) + first, second := f.seedDirect(t, tgFloorA), f.seedDirect(t, tgFloorB) + g := ssExitRefused(t, f, []ssExit{{first, 0}, {second, 0}}) + + if settled, failed, err := g.ph.SettlePendingOrders(g.ctx, 1); settled != 1 || failed != 0 || err != nil { + t.Fatalf("bounded pass settled %d, failed %d, error %v", settled, failed, err) + } + tgAssertOrder(t, g, first, models.Credited) + tgAssertOrder(t, g, second, models.Outstanding) + if settled, failed, err := g.ph.SettlePendingOrders(g.ctx, 1); settled != 1 || failed != 0 || err != nil { + t.Fatalf("next pass settled %d, failed %d, error %v", settled, failed, err) + } + tgAssertOrder(t, g, second, models.Credited) + tgAssertEarnings(t, g, tgOrderPrice(tgFloorA)+tgOrderPrice(tgFloorB)) +} + +// A closed dispatcher does not sweep. +func TestSettlementSweepSkipsAClosedDispatcher(t *testing.T) { + f := newTGFixture(t, nil) + run := f.seedDirect(t, tgFloorA) + g := ssExitRefused(t, f, []ssExit{{run, 0}}) + g.d.Close() + last := time.Unix(1, 0) + if got := g.d.sweepPendingSettlements(last); !got.Equal(last) { + t.Fatalf("closed sweep returned %v, want %v", got, last) + } + tgAssertOrder(t, g, run, models.Outstanding) +} diff --git a/internal/dispatcher/terminal_results_test.go b/internal/dispatcher/terminal_results_test.go index 3696a35e..0e1ba231 100644 --- a/internal/dispatcher/terminal_results_test.go +++ b/internal/dispatcher/terminal_results_test.go @@ -594,13 +594,13 @@ func TestTerminalResultGuards(t *testing.T) { tgAssertRow(t, f.row(t, deb.id), models.RunStateExited, tc.want) tgAssertReserved(t, f, deb, 0) // The payment decision stays exit-code based, also for a zero - // exit with an error message; TEST refunds are unsupported and - // leave the order Outstanding. + // exit with an error message; a failed TEST run is refunded + // locally. if tc.credited { tgAssertOrder(t, f, deb, models.Credited) tgAssertEarnings(t, f, income+tgOrderPrice(tgFloorA)) } else { - tgAssertOrder(t, f, deb, models.Outstanding) + tgAssertOrder(t, f, deb, models.Refunded) tgAssertEarnings(t, f, income) } }) @@ -641,8 +641,8 @@ func TestTerminalResultGuards(t *testing.T) { t.Fatalf("first exit: %v", err) } tgAssertRow(t, f.row(t, b.id), models.RunStateExited, tgText("debuglet exited with code 2")) - // The refund attempt fails for TEST and rolls back: order unchanged. - tgAssertOrder(t, f, b, models.Outstanding) + // The failed TEST run is refunded locally, moving nothing. + tgAssertOrder(t, f, b, models.Refunded) tgAssertEarnings(t, f, 0) tgAssertReserved(t, f, b, tgFloorA) after := f.snapshot(t) @@ -651,7 +651,7 @@ func TestTerminalResultGuards(t *testing.T) { t.Fatalf("duplicate exit: %v", err) } tgAssertRow(t, f.row(t, b.id), models.RunStateExited, tgText("debuglet exited with code 2")) - tgAssertOrder(t, f, b, models.Outstanding) + tgAssertOrder(t, f, b, models.Refunded) tgAssertEarnings(t, f, 0) tgAssertSnapshot(t, f, after, "duplicate exit") tgAssertReserved(t, f, b, tgFloorA) @@ -705,7 +705,7 @@ func TestTerminalResultGuards(t *testing.T) { tgAssertEarnings(t, f, tgOrderPrice(tgFloorA)) case tgText("concurrent failure"): tgAssertRow(t, row, models.RunStateExited, tgText("concurrent failure")) - tgAssertOrder(t, f, a, models.Outstanding) + tgAssertOrder(t, f, a, models.Refunded) tgAssertEarnings(t, f, 0) default: t.Fatalf("row error %+v belongs to no caller", row.Error) @@ -1020,7 +1020,7 @@ func TestTerminalResultGuards(t *testing.T) { t.Fatalf("SubmitDebuglets after an early failure: %v", err) } tgAssertRow(t, deb.row, models.RunStateExited, tgText("crash")) - tgAssertOrder(t, f, deb, models.Outstanding) + tgAssertOrder(t, f, deb, models.Refunded) tgAssertEarnings(t, f, 0) tgAssertReserved(t, f, deb, 0) }) @@ -1051,7 +1051,7 @@ func TestTerminalResultGuards(t *testing.T) { t.Fatalf("abort A: %v", err) } tgAssertRow(t, f.row(t, a.id), models.RunStateExited, tgText("operator abort")) - tgAssertOrder(t, f, a, models.Outstanding) + tgAssertOrder(t, f, a, models.Refunded) tgAssertReserved(t, f, a, tgFloorB) after := f.snapshot(t) if err := f.abort(t, a.id, "second abort"); err != nil { diff --git a/internal/dispatcher/transport/api/handlers_payment.go b/internal/dispatcher/transport/api/handlers_payment.go index 4fc74485..b91833a6 100644 --- a/internal/dispatcher/transport/api/handlers_payment.go +++ b/internal/dispatcher/transport/api/handlers_payment.go @@ -40,6 +40,11 @@ func (h *Handler) LockPrice(request PaymentIntentRequest, transactionId string, return total, nil } +// PricingRule names the rule priceIntent applies and is recorded on every +// intent it prices: an order costs price_per_bw_s x floor_bw x timeout_ms / 1000 +// in base units, computed exactly and rounded up to the next whole unit. +const PricingRule = "bw-s-ceil-ms-v1" + // priceIntent validates and prices every debuglet of an intent without // writing anything, returning each order's price and the total. The // payment-mode preflight runs first so that a disabled chain method never @@ -204,6 +209,11 @@ func (h *Handler) PutPaymentIntent(c echo.Context) error { h.logger.Info("INTENT", zap.String("hash", hash)) return apiErrorFrom(http.StatusInternalServerError, CodeInternal, "failed to create the payment intent", err) } + if err := queries.SetTransactionPricingRule(ctx, database.SetTransactionPricingRuleParams{ + PricingRule: PricingRule, ID: transactionId, + }); err != nil { + return apiErrorFrom(http.StatusInternalServerError, CodeInternal, "failed to record the pricing rule", err) + } if err := h.storeOrders(ctx, queries, req, transactionId, req.RefundAddress, prices); err != nil { return err } diff --git a/internal/dispatcher/transport/api/intent_pricing_test.go b/internal/dispatcher/transport/api/intent_pricing_test.go index d2460de2..ec735c1f 100644 --- a/internal/dispatcher/transport/api/intent_pricing_test.go +++ b/internal/dispatcher/transport/api/intent_pricing_test.go @@ -166,6 +166,19 @@ func ipStored(t *testing.T, db *sql.DB, txID string) (price int64, currency, met return price, currency, method, status, orders } +// ipAssertPricingRule checks that the stored transaction of an intent names +// the rule that priced it. +func ipAssertPricingRule(t *testing.T, db *sql.DB, txID string) { + t.Helper() + var rule string + if err := db.QueryRow("SELECT pricing_rule FROM transactions WHERE id = ?", txID).Scan(&rule); err != nil { + t.Fatalf("stored pricing rule of %s: %v", txID, err) + } + if rule != PricingRule { + t.Fatalf("stored pricing rule %q, want %q", rule, PricingRule) + } +} + // TestIpIntentPricesAtTheLimitsOnSQLite drives PUT /payment/intent against a // real database at the edges of the pricing rule. The executor charges one // unit per bit per second and second. A price, of one order or of the batch, @@ -245,7 +258,9 @@ func TestIpIntentPricesAtTheLimitsOnSQLite(t *testing.T) { for _, price := range tc.prices { total += price } - price, _, _, _, orders := ipStored(t, iaReopen(t, f), txID) + reopened := iaReopen(t, f) + price, _, _, _, orders := ipStored(t, reopened, txID) + ipAssertPricingRule(t, reopened, txID) if price != total || total != maximum { t.Fatalf("stored total %d, want %d", price, maximum) } @@ -300,6 +315,7 @@ func TestIpTESTIntentTotalsSurviveReopen(t *testing.T) { if fmt.Sprint(orders) != fmt.Sprint(want) { t.Fatalf("%s: orders %v, want %v", source.name, orders, want) } + ipAssertPricingRule(t, source.db, txID) } }) } diff --git a/internal/dispatcher/transport/api/payment_mode_test.go b/internal/dispatcher/transport/api/payment_mode_test.go index 58fcf1a5..6b9d2232 100644 --- a/internal/dispatcher/transport/api/payment_mode_test.go +++ b/internal/dispatcher/transport/api/payment_mode_test.go @@ -67,7 +67,7 @@ var ( "INSERT INTO debuglet_order (transaction_id, order_id, executor_id, price, currency, refund_address, state ) VALUES (?,?,?,?,?,?,?) RETURNING transaction_id, order_id, executor_id, price, currency, state, refund_address, debuglet_id", ) modeGetTransactionQuery = regexp.QuoteMeta( - "SELECT id, auth_key, price, method, expires_at, hash, currency, status FROM transactions WHERE id = ?", + "SELECT id, auth_key, price, method, expires_at, hash, currency, status, pricing_rule FROM transactions WHERE id = ?", ) modeGetTransactionOrdersQuery = regexp.QuoteMeta( "SELECT transaction_id, order_id, executor_id, price, currency, state, refund_address, debuglet_id FROM debuglet_order WHERE transaction_id = ?", @@ -81,7 +81,7 @@ var ( modeEarningsColumns = []string{"executor_id", "currency", "total_income", "current_balance", "sui_wallet_address"} modeOrderColumns = []string{"transaction_id", "order_id", "executor_id", "price", "currency", "state", "refund_address", "debuglet_id"} - modeTransactionColumns = []string{"id", "auth_key", "price", "method", "expires_at", "hash", "currency", "status"} + modeTransactionColumns = []string{"id", "auth_key", "price", "method", "expires_at", "hash", "currency", "status", "pricing_rule"} ) type modeFixture struct { @@ -249,7 +249,7 @@ func modeRequestHash(t *testing.T, debuglets []DebugletRequest) string { // CreateTransaction return it. func modeTransactionRows(id, authKey, method, currency, hash string, status models.TransactionState) *sqlmock.Rows { return sqlmock.NewRows(modeTransactionColumns).AddRow( - id, authKey, modeOrderPrice, method, time.Now().Add(5*time.Minute).UTC(), hash, currency, int64(status), + id, authKey, modeOrderPrice, method, time.Now().Add(5*time.Minute).UTC(), hash, currency, int64(status), "", ) } diff --git a/internal/storagecheck/init_test.go b/internal/storagecheck/init_test.go index 2e41ed9d..956f8b7e 100644 --- a/internal/storagecheck/init_test.go +++ b/internal/storagecheck/init_test.go @@ -57,9 +57,10 @@ func TestBootstrapFresh(t *testing.T) { "debuglet_output": "debuglet_id output_version owner_fingerprint account_id committed_sequence byte_count frame_count last_log_id final_sequence final_cursor status reason", "debuglet_cancellations": "debuglet_id request_id reason requested_at attempted_at acknowledged_at failure", "debuglet_provenance": "debuglet_id document", + "order_settlements": "transaction_id order_id kind amount currency executor_id debuglet_id recorded_at", "output_account_usage": "account_id charged_bytes frame_count", "output_node_usage": "singleton charged_bytes frame_count", - "transactions": "id auth_key price method expires_at hash currency status", + "transactions": "id auth_key price method expires_at hash currency status pricing_rule", "transaction_states": "key value", "earnings": "executor_id currency total_income current_balance sui_wallet_address", "debuglet_order": "transaction_id order_id executor_id price currency state refund_address debuglet_id", @@ -75,7 +76,7 @@ func TestBootstrapFresh(t *testing.T) { "oauth_login_attempts": "state_hash provider verifier nonce purpose session_selector expires_at", "pending_identity_links": "user_id provider issuer subject login session_selector expires_at", "device_logins": "selector verifier_hash user_code_hash audience scopes label expires_at next_poll_at poll_interval state approver_session user_id", - }, []string{"account_recovery_pending", "account_run_reservations_live", "attribution_runs_source_idx", "debuglet_logs_sequence_idx", "debuglets_uuid_idx", "device_logins_expiry", "executor_enrollment_tokens_executor_idx", "measurement_profiles_owner", "oauth_login_expiry", "owned_executors_user_idx", "sessions_user_idx", "users_uuid_idx"}, []int64{0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20}) + }, []string{"account_recovery_pending", "account_run_reservations_live", "attribution_runs_source_idx", "debuglet_logs_sequence_idx", "debuglets_uuid_idx", "device_logins_expiry", "executor_enrollment_tokens_executor_idx", "measurement_profiles_owner", "oauth_login_expiry", "owned_executors_user_idx", "sessions_user_idx", "users_uuid_idx"}, []int64{0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21}) dispatcherSchemaRoundTrip(t, db) } else { assertSchema(t, db, map[string]string{ diff --git a/internal/storagecheck/policy.go b/internal/storagecheck/policy.go index 217a53a4..c9d0257f 100644 --- a/internal/storagecheck/policy.go +++ b/internal/storagecheck/policy.go @@ -31,7 +31,7 @@ const ( // an older database can then no longer answer them and must be refused instead // of failing later during service. const ( - MinimumDispatcherVersion int64 = 20 + MinimumDispatcherVersion int64 = 21 MinimumExecutorVersion int64 = 6 ) @@ -87,6 +87,7 @@ func PolicyFor(role Role) (Policy, error) { "debuglet_logs": {"debuglet_id", "output", "source_sequence"}, "debuglet_provenance": {"debuglet_id", "document"}, "debuglet_output": {"debuglet_id", "output_version", "owner_fingerprint", "account_id", "committed_sequence", "final_sequence", "final_cursor", "status", "reason"}, + "order_settlements": {"transaction_id", "order_id", "kind", "amount"}, "output_account_usage": {"account_id", "charged_bytes", "frame_count"}, "output_node_usage": {"singleton", "charged_bytes", "frame_count"}, "debuglet_order": {"transaction_id", "state", "refund_address", "debuglet_id"}, @@ -101,7 +102,7 @@ func PolicyFor(role Role) (Policy, error) { "device_logins": {"selector", "verifier_hash", "user_code_hash", "audience", "scopes", "label", "expires_at", "next_poll_at", "poll_interval", "state", "approver_session", "user_id"}, "sessions": {"selector", "verifier_hash", "csrf_hash", "user_id", "expires_at", "revoked", "kind", "audience", "scopes", "label", "authenticated_at"}, "transaction_users": {"transaction_id", "user_id"}, - "transactions": {"currency", "status"}, + "transactions": {"currency", "status", "pricing_rule"}, "user_credentials": {"user_id", "kind", "selector", "secret_hash"}, "users": {"uuid", "name", "role"}, }}, nil From 12e39f2d563b8d421ab9b054919bd9688374be5a Mon Sep 17 00:00:00 2001 From: TheodorAdrienIsaak Mattli Date: Mon, 5 Oct 2026 10:32:44 +0200 Subject: [PATCH 5/8] Record chain payment receipts durably before acknowledging them The receipt listener applied each receipt through a void callback whose write failures were only logged, advanced its checkpoint cursor whatever happened, converted the chain amount to a signed integer unchecked, only warned about a receipt for a non-chain method and reset an invalid stored cursor silently; its expiry check never fired because the decoder read nothing into the timestamp. Dispatcher schema 22 adds payment_receipts, one row per receipt addressed to this dispatcher keyed by chain digest and nonce with its disposition, and chain_transfers, the record of outbound payouts and refunds with the signed transaction persisted before anything is broadcast. A receipt is validated strictly, applied by a conditional write on an outstanding transaction and recorded in the same local transaction, so a receipt read again after a restart is recognized instead of applied twice; the cursor moves only after every receipt of a range is recorded, a gap between the catch-up and the first streamed checkpoint is read through the indexer first, an invalid stored cursor is a startup error, and a first start persists the chain tip it begins at. GitHub issue #79. --- docs/operations/configuration.md | 9 + docs/versions.md | 2 + .../database/migrations/00022_settlement.sql | 47 ++ internal/dispatcher/database/models.go | 30 + .../database/queries/settlement.sql | 17 + .../dispatcher/database/settlement.sql.go | 131 +++++ internal/dispatcher/payments/payments.go | 24 - internal/dispatcher/payments/payments_test.go | 127 ++-- internal/dispatcher/payments/receipts.go | 153 +++++ internal/dispatcher/payments/receipts_test.go | 178 ++++++ .../payments/refund_admission_test.go | 5 +- .../dispatcher/payments/sui/export_test.go | 32 + internal/dispatcher/payments/sui/listener.go | 275 +++++---- .../dispatcher/payments/sui/listener_test.go | 546 ++++++++++++++++++ .../transport/api/wallet_free_test.go | 7 +- internal/storagecheck/init_test.go | 4 +- internal/storagecheck/policy.go | 6 +- 17 files changed, 1375 insertions(+), 218 deletions(-) create mode 100644 internal/dispatcher/database/migrations/00022_settlement.sql create mode 100644 internal/dispatcher/database/queries/settlement.sql create mode 100644 internal/dispatcher/database/settlement.sql.go create mode 100644 internal/dispatcher/payments/receipts.go create mode 100644 internal/dispatcher/payments/receipts_test.go create mode 100644 internal/dispatcher/payments/sui/export_test.go create mode 100644 internal/dispatcher/payments/sui/listener_test.go diff --git a/docs/operations/configuration.md b/docs/operations/configuration.md index 824e17a8..00c47641 100644 --- a/docs/operations/configuration.md +++ b/docs/operations/configuration.md @@ -125,6 +125,15 @@ are not reconciled payment state: migration 4 leaves old earnings without a payout wallet, and re-registration does not repair it. Keep payments disabled and retain paid databases and backups for operator reconciliation. +From dispatcher schema 22, the dispatcher database also keeps `payment_receipts`, +one row per chain payment receipt addressed to the dispatcher (chain +transaction digest, nonce, amount, coin type, receiver and whether it was +applied, a duplicate, a mismatch, expired or for an unknown intent), and +`chain_transfers`, the outbound payout and refund transfers and their states, +including each signed transaction and its signature, stored before broadcast. +Both are kept indefinitely for reconciliation; they stay empty while chain +payments are disabled. + ## State and upgrades Daemons never migrate a database at startup. Back up the dispatcher database, use the release's explicit migration process, and deploy a single reviewed version across the service. An interrupted executor run is not resumed after restart. diff --git a/docs/versions.md b/docs/versions.md index f0546c09..98245e73 100644 --- a/docs/versions.md +++ b/docs/versions.md @@ -97,3 +97,5 @@ API 1.11 adds the public attribution lookups `GET /attribution/candidates` and ` API 1.12 adds measurement profiles, batch details, explicit retry lineage, listener readiness and owner payload deletion. Retry clients require 1.12 so a dispatcher that only supports attribution cannot silently accept a request without retaining its retry identity. Dispatcher schema 15 stores the workflow metadata; schema 16 adds account reservations and payload tombstones. Dispatcher schema 21 records one settlement per order and the pricing rule of each transaction; this build refuses an older dispatcher database, so upgrade it explicitly before starting this build. + +Dispatcher schema 22 records chain payment receipts and outbound chain transfers. The receipt listener and the transfer code depend on it, so this build requires schema 22; upgrade explicitly before starting it. The HTTP API is unchanged. diff --git a/internal/dispatcher/database/migrations/00022_settlement.sql b/internal/dispatcher/database/migrations/00022_settlement.sql new file mode 100644 index 00000000..d8ac11b2 --- /dev/null +++ b/internal/dispatcher/database/migrations/00022_settlement.sql @@ -0,0 +1,47 @@ +-- +goose up +-- Every chain payment receipt addressed to this dispatcher, keyed by the chain +-- transaction digest and the receipt nonce (our transaction id). The row is +-- written in the same SQL transaction as the payment's effect, so a receipt +-- read again after a restart is recognized instead of applied twice. The +-- amount is decimal text so that a chain amount beyond INTEGER is kept exactly. +CREATE TABLE payment_receipts ( + tx_digest TEXT NOT NULL, + nonce TEXT NOT NULL, + disposition TEXT NOT NULL CHECK (disposition IN ('applied', 'duplicate', 'mismatch', 'unknown_intent', 'expired')), + amount TEXT NOT NULL, + coin_type TEXT NOT NULL, + receiver TEXT NOT NULL, + checkpoint INTEGER, + observed_at TIMESTAMP NOT NULL, + detail TEXT NOT NULL DEFAULT '', + PRIMARY KEY (tx_digest, nonce) +); + +-- Outbound chain transfers (executor payouts and refunds). A row is reserved +-- before the chain call and records what is known about it afterwards. The +-- signed transaction and its signature are stored before broadcast, so a +-- transfer whose outcome is unknown after a crash can be looked up or sent +-- again unchanged rather than paid a second time. +CREATE TABLE chain_transfers ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + kind TEXT NOT NULL CHECK (kind IN ('payout', 'refund')), + executor_id TEXT NOT NULL DEFAULT '', + transaction_id TEXT NOT NULL DEFAULT '', + order_id INTEGER, + amount INTEGER NOT NULL CHECK (amount > 0), + currency TEXT NOT NULL, + receiver TEXT NOT NULL, + state TEXT NOT NULL CHECK (state IN ('reserved', 'sent', 'confirmed', 'failed', 'unknown')), + digest TEXT NOT NULL DEFAULT '', + signed_transaction BLOB NOT NULL DEFAULT X'', + signature TEXT NOT NULL DEFAULT '', + detail TEXT NOT NULL DEFAULT '', + created_at TIMESTAMP NOT NULL, + updated_at TIMESTAMP NOT NULL +); +CREATE INDEX chain_transfers_executor_idx ON chain_transfers(executor_id, currency, state); + +-- +goose down +DROP INDEX chain_transfers_executor_idx; +DROP TABLE chain_transfers; +DROP TABLE payment_receipts; diff --git a/internal/dispatcher/database/models.go b/internal/dispatcher/database/models.go index 5010f126..0386eb00 100644 --- a/internal/dispatcher/database/models.go +++ b/internal/dispatcher/database/models.go @@ -72,6 +72,24 @@ type AttributionRun struct { ActiveToNs int64 } +type ChainTransfer struct { + ID int64 + Kind string + ExecutorID string + TransactionID string + OrderID sql.NullInt64 + Amount int64 + Currency string + Receiver string + State string + Digest string + SignedTransaction []byte + Signature string + Detail string + CreatedAt models.UTCTime + UpdatedAt models.UTCTime +} + type Debuglet struct { ID int64 Uuid uuid.UUID @@ -265,6 +283,18 @@ type PayloadTombstone struct { CertificateSha256 sql.NullString } +type PaymentReceipt struct { + TxDigest string + Nonce string + Disposition string + Amount string + CoinType string + Receiver string + Checkpoint sql.NullInt64 + ObservedAt models.UTCTime + Detail string +} + type PendingIdentityLink struct { UserID int64 Provider string diff --git a/internal/dispatcher/database/queries/settlement.sql b/internal/dispatcher/database/queries/settlement.sql new file mode 100644 index 00000000..dc6d4ffc --- /dev/null +++ b/internal/dispatcher/database/queries/settlement.sql @@ -0,0 +1,17 @@ +-- name: InsertPaymentReceipt :exec +INSERT INTO payment_receipts (tx_digest, nonce, disposition, amount, coin_type, receiver, checkpoint, observed_at, detail) +VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?); + +-- name: GetPaymentReceipt :one +SELECT * FROM payment_receipts +WHERE tx_digest = ? AND nonce = ?; + +-- name: ListPaymentReceiptsByNonce :many +SELECT * FROM payment_receipts +WHERE nonce = ? +ORDER BY observed_at, tx_digest; + +-- name: MarkTransactionPaid :execrows +UPDATE transactions +SET status = sqlc.arg(paid) +WHERE id = sqlc.arg(id) AND status = sqlc.arg(outstanding); diff --git a/internal/dispatcher/database/settlement.sql.go b/internal/dispatcher/database/settlement.sql.go new file mode 100644 index 00000000..14282ab8 --- /dev/null +++ b/internal/dispatcher/database/settlement.sql.go @@ -0,0 +1,131 @@ +// Code generated by sqlc. DO NOT EDIT. +// versions: +// sqlc v1.31.1 +// source: settlement.sql + +package database + +import ( + "context" + "database/sql" + + "github.com/netsec-ethz/debuglet/internal/dispatcher/models" +) + +const getPaymentReceipt = `-- name: GetPaymentReceipt :one +SELECT tx_digest, nonce, disposition, amount, coin_type, receiver, checkpoint, observed_at, detail FROM payment_receipts +WHERE tx_digest = ? AND nonce = ? +` + +type GetPaymentReceiptParams struct { + TxDigest string + Nonce string +} + +func (q *Queries) GetPaymentReceipt(ctx context.Context, arg GetPaymentReceiptParams) (PaymentReceipt, error) { + row := q.db.QueryRowContext(ctx, getPaymentReceipt, arg.TxDigest, arg.Nonce) + var i PaymentReceipt + err := row.Scan( + &i.TxDigest, + &i.Nonce, + &i.Disposition, + &i.Amount, + &i.CoinType, + &i.Receiver, + &i.Checkpoint, + &i.ObservedAt, + &i.Detail, + ) + return i, err +} + +const insertPaymentReceipt = `-- name: InsertPaymentReceipt :exec +INSERT INTO payment_receipts (tx_digest, nonce, disposition, amount, coin_type, receiver, checkpoint, observed_at, detail) +VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?) +` + +type InsertPaymentReceiptParams struct { + TxDigest string + Nonce string + Disposition string + Amount string + CoinType string + Receiver string + Checkpoint sql.NullInt64 + ObservedAt models.UTCTime + Detail string +} + +func (q *Queries) InsertPaymentReceipt(ctx context.Context, arg InsertPaymentReceiptParams) error { + _, err := q.db.ExecContext(ctx, insertPaymentReceipt, + arg.TxDigest, + arg.Nonce, + arg.Disposition, + arg.Amount, + arg.CoinType, + arg.Receiver, + arg.Checkpoint, + arg.ObservedAt, + arg.Detail, + ) + return err +} + +const listPaymentReceiptsByNonce = `-- name: ListPaymentReceiptsByNonce :many +SELECT tx_digest, nonce, disposition, amount, coin_type, receiver, checkpoint, observed_at, detail FROM payment_receipts +WHERE nonce = ? +ORDER BY observed_at, tx_digest +` + +func (q *Queries) ListPaymentReceiptsByNonce(ctx context.Context, nonce string) ([]PaymentReceipt, error) { + rows, err := q.db.QueryContext(ctx, listPaymentReceiptsByNonce, nonce) + if err != nil { + return nil, err + } + defer rows.Close() + var items []PaymentReceipt + for rows.Next() { + var i PaymentReceipt + if err := rows.Scan( + &i.TxDigest, + &i.Nonce, + &i.Disposition, + &i.Amount, + &i.CoinType, + &i.Receiver, + &i.Checkpoint, + &i.ObservedAt, + &i.Detail, + ); err != nil { + return nil, err + } + items = append(items, i) + } + if err := rows.Close(); err != nil { + return nil, err + } + if err := rows.Err(); err != nil { + return nil, err + } + return items, nil +} + +const markTransactionPaid = `-- name: MarkTransactionPaid :execrows +UPDATE transactions +SET status = ?1 +WHERE id = ?2 AND status = ?3 +` + +type MarkTransactionPaidParams struct { + Paid int64 + ID string + Outstanding int64 +} + +func (q *Queries) MarkTransactionPaid(ctx context.Context, arg MarkTransactionPaidParams) (int64, error) { + result, err := q.db.ExecContext(ctx, markTransactionPaid, arg.Paid, arg.ID, arg.Outstanding) + if err != nil { + return 0, err + } + return result.RowsAffected() +} diff --git a/internal/dispatcher/payments/payments.go b/internal/dispatcher/payments/payments.go index 3d2d1182..346b5eef 100644 --- a/internal/dispatcher/payments/payments.go +++ b/internal/dispatcher/payments/payments.go @@ -231,30 +231,6 @@ func (p *PaymentHandler) createDummyIntent(db database.DBTX, transactionId strin } } -// CompleteTransaction marks a transaction as paid. It is the -// sui.TransactionFulfiller callback of the chain listener, so it keeps its -// void signature: a failed lookup, or a chain transaction while blockchain -// payments are disabled, is logged and leaves the row untouched. -func (p *PaymentHandler) CompleteTransaction(transactionId string, ctx context.Context) { - queries := database.New(p.db) - transaction, err := queries.GetTransactionByID(ctx, transactionId) - if err != nil { - p.logger.Error("failed to look up transaction to settle", zap.String("id", transactionId), zap.Error(err)) - return - } - if err := p.requireChain(transaction.Method, "settle transaction"); err != nil { - p.logger.Warn("not settling transaction", zap.String("id", transactionId), zap.String("method", transaction.Method), zap.Error(err)) - return - } - p.logger.Info("settling transaction", zap.String("id", transactionId)) - if err := queries.UpdateTransactionStatus(ctx, database.UpdateTransactionStatusParams{ - Status: int64(models.Paid), - ID: transactionId, - }); err != nil { - p.logger.Error("failed to settle transaction", zap.String("id", transactionId), zap.Error(err)) - } -} - // Settlement kinds recorded in order_settlements. const ( settlementCredit = "credit" diff --git a/internal/dispatcher/payments/payments_test.go b/internal/dispatcher/payments/payments_test.go index 88272a7d..e9450628 100644 --- a/internal/dispatcher/payments/payments_test.go +++ b/internal/dispatcher/payments/payments_test.go @@ -978,93 +978,59 @@ func TestEnabledChainMethodsForwardToBackend(t *testing.T) { }) } -// ---- CompleteTransaction (void TransactionFulfiller callback) ---- +// ---- ApplyPaymentReceipt (the chain listener's TransactionFulfiller) ---- -// Log messages emitted by CompleteTransaction. The callback is void and -// swallows database errors into these lines, so the log is the only place an -// attempted write can be observed: sqlmock answers an unexpected UPDATE with an -// error, which surfaces as logFailedSettle rather than as a test failure. -const ( - logLookupFailed = "failed to look up transaction to settle" - logNotSettling = "not settling transaction" - logSettling = "settling transaction" - logFailedSettle = "failed to settle transaction" +var ( + getPaymentReceiptQuery = regexp.QuoteMeta("FROM payment_receipts\nWHERE tx_digest = ? AND nonce = ?") + markTransactionPaidQuery = regexp.QuoteMeta("UPDATE transactions\nSET status = ?1\nWHERE id = ?2 AND status = ?3") ) -var allCompleteLogs = []string{logLookupFailed, logNotSettling, logSettling, logFailedSettle} - -func TestCompleteTransaction(t *testing.T) { - expectUpdate := func(mock sqlmock.Sqlmock) { - mock.ExpectExec(updateTransactionStatusQuery).WithArgs(int64(models.Paid), testTxID).WillReturnResult(sqlmock.NewResult(0, 1)) +// Every failure of ApplyPaymentReceipt is returned, never logged as consumed, +// and leaves nothing written: the listener then keeps its cursor and processes +// the receipt again. Disabled mode refuses before touching the database. +func TestApplyPaymentReceiptModes(t *testing.T) { + receipt := sui.PaymentReceipt{ + Digest: "digest-1", Nonce: testTxID, Amount: uint64(testPrice), + CoinType: sui.GetCoinType("USDC", "testnet"), Receiver: "0xdead", Timestamp: time.Now(), + } + expectBeginAndReceiptMiss := func(mock sqlmock.Sqlmock) { + mock.ExpectBegin() + mock.ExpectQuery(getPaymentReceiptQuery).WithArgs(receipt.Digest, testTxID).WillReturnError(sql.ErrNoRows) } cases := []struct { name string disabled bool expect func(mock sqlmock.Sqlmock) - wantLogs []string // exactly these CompleteTransaction messages, in order + want error }{ + {name: "disabled: refused without a read", disabled: true, expect: func(sqlmock.Sqlmock) {}, want: ErrPaymentsDisabled}, { - name: "disabled SUI: lookup only", disabled: true, - expect: func(mock sqlmock.Sqlmock) { expectTransactionRead(mock, "SUI", models.Outstanding) }, - wantLogs: []string{logNotSettling}, - }, - { - name: "disabled USDC: lookup only", disabled: true, - expect: func(mock sqlmock.Sqlmock) { expectTransactionRead(mock, "USDC", models.Outstanding) }, - wantLogs: []string{logNotSettling}, - }, - { - name: "disabled TEST: lookup then update", disabled: true, + name: "enabled receipt lookup error: rolled back", expect: func(mock sqlmock.Sqlmock) { - expectTransactionRead(mock, "TEST", models.Outstanding) - expectUpdate(mock) + mock.ExpectBegin() + mock.ExpectQuery(getPaymentReceiptQuery).WithArgs(receipt.Digest, testTxID).WillReturnError(errScripted) + mock.ExpectRollback() }, - wantLogs: []string{logSettling}, + want: errScripted, }, { - name: "disabled lookup error: no update", disabled: true, + name: "enabled transaction lookup error: rolled back", expect: func(mock sqlmock.Sqlmock) { + expectBeginAndReceiptMiss(mock) mock.ExpectQuery(getTransactionByIDQuery).WithArgs(testTxID).WillReturnError(errScripted) + mock.ExpectRollback() }, - wantLogs: []string{logLookupFailed}, - }, - { - name: "disabled unknown id: no update", disabled: true, - expect: func(mock sqlmock.Sqlmock) { - mock.ExpectQuery(getTransactionByIDQuery).WithArgs(testTxID).WillReturnError(sql.ErrNoRows) - }, - wantLogs: []string{logLookupFailed}, - }, - { - name: "enabled SUI: lookup then update", disabled: false, - expect: func(mock sqlmock.Sqlmock) { - expectTransactionRead(mock, "SUI", models.Outstanding) - expectUpdate(mock) - }, - wantLogs: []string{logSettling}, + want: errScripted, }, { - name: "enabled USDC: lookup then update", disabled: false, + name: "enabled paid write error: no receipt recorded", expect: func(mock sqlmock.Sqlmock) { + expectBeginAndReceiptMiss(mock) expectTransactionRead(mock, "USDC", models.Outstanding) - expectUpdate(mock) - }, - wantLogs: []string{logSettling}, - }, - { - name: "enabled TEST: lookup then update", disabled: false, - expect: func(mock sqlmock.Sqlmock) { - expectTransactionRead(mock, "TEST", models.Outstanding) - expectUpdate(mock) - }, - wantLogs: []string{logSettling}, - }, - { - name: "enabled lookup error: no update", disabled: false, - expect: func(mock sqlmock.Sqlmock) { - mock.ExpectQuery(getTransactionByIDQuery).WithArgs(testTxID).WillReturnError(errScripted) + mock.ExpectExec(markTransactionPaidQuery).WithArgs(int64(models.Paid), testTxID, int64(models.Outstanding)).WillReturnError(errScripted) + mock.ExpectRollback() }, - wantLogs: []string{logLookupFailed}, + want: errScripted, }, } for _, tc := range cases { @@ -1082,30 +1048,19 @@ func TestCompleteTransaction(t *testing.T) { tc.expect(mock) var tf sui.TransactionFulfiller = h - tf.CompleteTransaction(testTxID, context.Background()) - + disposition, err := tf.ApplyPaymentReceipt(context.Background(), receipt) + if !errors.Is(err, tc.want) || disposition != "" { + t.Fatalf("ApplyPaymentReceipt = %q, %v; want error %v", disposition, err, tc.want) + } if calls := rec.chain.Calls(); len(calls) != 0 { - t.Fatalf("CompleteTransaction reached the chain backend: %v", calls) + t.Fatalf("ApplyPaymentReceipt reached the chain backend: %v", calls) } - // ExpectationsWereMet proves the expected reads/updates happened; the - // log proves nothing else was attempted (an unexpected UPDATE would - // have been answered with an error and logged as logFailedSettle). + // ExpectationsWereMet proves the scripted statements ran and the + // transaction was rolled back; an unexpected INSERT would have + // failed the call with a different error. assertMet(t, mock) - var got []string - for _, entry := range logs.All() { - for _, known := range allCompleteLogs { - if entry.Message == known { - got = append(got, entry.Message) - } - } - } - if strings.Join(got, "|") != strings.Join(tc.wantLogs, "|") { - t.Fatalf("CompleteTransaction log messages %q, want %q (all entries: %v)", got, tc.wantLogs, logs.All()) - } - if tc.wantLogs[0] == logSettling { - if n := logs.FilterMessage(logSettling).Len(); n != 1 { - t.Fatalf("settling logged %d times", n) - } + if logs.Len() != 0 { + t.Fatalf("ApplyPaymentReceipt logged %v", logs.All()) } }) } diff --git a/internal/dispatcher/payments/receipts.go b/internal/dispatcher/payments/receipts.go new file mode 100644 index 00000000..b268907b --- /dev/null +++ b/internal/dispatcher/payments/receipts.go @@ -0,0 +1,153 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package payments + +import ( + "context" + "database/sql" + "errors" + "fmt" + "math" + "strconv" + "strings" + "time" + + "github.com/netsec-ethz/debuglet/internal/dispatcher/database" + "github.com/netsec-ethz/debuglet/internal/dispatcher/models" + "github.com/netsec-ethz/debuglet/internal/dispatcher/payments/sui" +) + +// ApplyPaymentReceipt is the sui.TransactionFulfiller of the chain listener. +// In one SQL transaction it validates a chain payment receipt against the +// transaction its nonce names, marks an outstanding transaction paid when the +// receipt pays it exactly, and records the receipt with its disposition. A +// receipt that was recorded before is not applied again: an applied one is +// reported as duplicate, any other with its recorded disposition. A receipt +// to another address whose nonce names no local transaction is not ours and +// is not recorded (empty disposition). A database error is returned with +// nothing recorded, so the caller can process the receipt again. Chain mode +// must be enabled. +func (p *PaymentHandler) ApplyPaymentReceipt(ctx context.Context, r sui.PaymentReceipt) (sui.ReceiptDisposition, error) { + if p.chainDisabled() { + return "", fmt.Errorf("apply payment receipt: %w", ErrPaymentsDisabled) + } + tx, err := p.db.BeginTx(ctx, nil) + if err != nil { + return "", fmt.Errorf("begin payment receipt: %w", err) + } + defer tx.Rollback() + queries := database.New(tx) + + stored, err := queries.GetPaymentReceipt(ctx, database.GetPaymentReceiptParams{TxDigest: r.Digest, Nonce: r.Nonce}) + if err == nil { + if disposition := sui.ReceiptDisposition(stored.Disposition); disposition != sui.ReceiptApplied { + return disposition, nil + } + return sui.ReceiptDuplicate, nil + } + if !errors.Is(err, sql.ErrNoRows) { + return "", fmt.Errorf("read payment receipt: %w", err) + } + + disposition, detail, err := p.settleReceipt(ctx, queries, r) + if err != nil || disposition == "" { + return "", err + } + var checkpoint sql.NullInt64 + if r.Checkpoint != 0 && r.Checkpoint <= math.MaxInt64 { + checkpoint = sql.NullInt64{Int64: int64(r.Checkpoint), Valid: true} + } + if err := queries.InsertPaymentReceipt(ctx, database.InsertPaymentReceiptParams{ + TxDigest: r.Digest, + Nonce: r.Nonce, + Disposition: string(disposition), + Amount: strconv.FormatUint(r.Amount, 10), + CoinType: r.CoinType, + Receiver: r.Receiver, + Checkpoint: checkpoint, + ObservedAt: models.NewUTCTime(time.Now()), + Detail: detail, + }); err != nil { + return "", fmt.Errorf("record payment receipt: %w", err) + } + if err := tx.Commit(); err != nil { + return "", fmt.Errorf("commit payment receipt: %w", err) + } + return disposition, nil +} + +// settleReceipt decides a receipt that has not been recorded and, when it pays +// its transaction, marks the transaction paid through queries. detail names +// the field that did not match. +func (p *PaymentHandler) settleReceipt(ctx context.Context, queries *database.Queries, r sui.PaymentReceipt) (sui.ReceiptDisposition, string, error) { + toUs := sameSuiAddress(r.Receiver, p.cfg.Sui.Address) + transaction, err := queries.GetTransactionByID(ctx, r.Nonce) + if errors.Is(err, sql.ErrNoRows) { + if !toUs { + return "", "", nil + } + return sui.ReceiptUnknownIntent, "", nil + } + if err != nil { + return "", "", fmt.Errorf("read transaction: %w", err) + } + switch { + case !isChainCurrency(transaction.Method): + return sui.ReceiptMismatch, "method", nil + case !sameCoinType(r.CoinType, sui.GetCoinType(transaction.Currency, p.cfg.Sui.Network)): + return sui.ReceiptMismatch, "coin type", nil + case !toUs: + return sui.ReceiptMismatch, "receiver", nil + case r.Amount > math.MaxInt64 || int64(r.Amount) != transaction.Price: + return sui.ReceiptMismatch, "amount", nil + case r.Timestamp.After(transaction.ExpiresAt.Time): + return sui.ReceiptExpired, "", nil + } + + paid, err := queries.MarkTransactionPaid(ctx, database.MarkTransactionPaidParams{ + Paid: int64(models.Paid), ID: transaction.ID, Outstanding: int64(models.Outstanding), + }) + if err != nil { + return "", "", fmt.Errorf("mark transaction paid: %w", err) + } + if paid == 1 { + return sui.ReceiptApplied, "", nil + } + // The same receipt was answered above from its own row, so an applied + // receipt for this nonce is a second payment by another chain transaction. + recorded, err := queries.ListPaymentReceiptsByNonce(ctx, r.Nonce) + if err != nil { + return "", "", fmt.Errorf("read payment receipts: %w", err) + } + for _, other := range recorded { + if other.Disposition == string(sui.ReceiptApplied) { + return sui.ReceiptMismatch, "already paid by " + other.TxDigest, nil + } + } + return sui.ReceiptMismatch, "transaction not outstanding", nil +} + +// sameSuiAddress compares two Sui addresses in any letter case, with or +// without 0x and leading zeros. +func sameSuiAddress(a, b string) bool { + na, nb := normalizeSuiAddress(a), normalizeSuiAddress(b) + return na != "" && na == nb +} + +// sameCoinType compares two coin types whose package addresses may be written +// in either form sameSuiAddress accepts. An empty type matches nothing. +func sameCoinType(a, b string) bool { + addrA, restA, okA := strings.Cut(a, "::") + addrB, restB, okB := strings.Cut(b, "::") + return okA && okB && strings.EqualFold(restA, restB) && sameSuiAddress(addrA, addrB) +} + +func normalizeSuiAddress(a string) string { + a = strings.ToLower(a) + a = strings.TrimPrefix(a, "0x") + if a == "" || len(a) > 64 || strings.Trim(a, "0123456789abcdef") != "" { + return "" + } + return strings.Repeat("0", 64-len(a)) + a +} diff --git a/internal/dispatcher/payments/receipts_test.go b/internal/dispatcher/payments/receipts_test.go new file mode 100644 index 00000000..b0c243e5 --- /dev/null +++ b/internal/dispatcher/payments/receipts_test.go @@ -0,0 +1,178 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package payments + +import ( + "context" + "database/sql" + "errors" + "math" + "testing" + "time" + + "github.com/netsec-ethz/debuglet/internal/dispatcher/database" + "github.com/netsec-ethz/debuglet/internal/dispatcher/models" + "github.com/netsec-ethz/debuglet/internal/dispatcher/payments/sui" +) + +// receiptFixture is a real database with one outstanding USDC transaction of +// testPrice, payable to enabledConfig's address "0xdead". +func receiptFixture(t *testing.T, method string, status models.TransactionState) (*sql.DB, *PaymentHandler) { + t.Helper() + db := newRefundDatabase(t) + h, _ := newEnabledHandler(t, db, enabledConfig(t)) + if _, err := database.New(db).CreateTransaction(t.Context(), database.CreateTransactionParams{ + ID: testTxID, AuthKey: "key", Price: testPrice, Currency: method, Method: method, + ExpiresAt: models.NewUTCTime(time.Now().Add(time.Hour)), Status: int64(status), Hash: testHash, + }); err != nil { + t.Fatal(err) + } + return db, h +} + +// validReceipt pays testTxID exactly, written as the chain reports it: the +// coin type's package address without 0x and the receiver at full length. +func validReceipt(digest string) sui.PaymentReceipt { + return sui.PaymentReceipt{ + Digest: digest, + Nonce: testTxID, + Amount: uint64(testPrice), + CoinType: sui.GetCoinType("USDC", "testnet")[2:], + Receiver: "0x000000000000000000000000000000000000000000000000000000000000DEAD", + Timestamp: time.Now(), + Checkpoint: 12, + } +} + +func applyReceipt(t *testing.T, h *PaymentHandler, r sui.PaymentReceipt) sui.ReceiptDisposition { + t.Helper() + disposition, err := h.ApplyPaymentReceipt(t.Context(), r) + if err != nil { + t.Fatalf("ApplyPaymentReceipt(%s): %v", r.Digest, err) + } + return disposition +} + +func transactionStatus(t *testing.T, db *sql.DB) models.TransactionState { + t.Helper() + transaction, err := database.New(db).GetTransactionByID(t.Context(), testTxID) + if err != nil { + t.Fatal(err) + } + return models.TransactionState(transaction.Status) +} + +func storedReceipt(t *testing.T, db *sql.DB, digest, nonce string) database.PaymentReceipt { + t.Helper() + row, err := database.New(db).GetPaymentReceipt(t.Context(), database.GetPaymentReceiptParams{TxDigest: digest, Nonce: nonce}) + if err != nil { + t.Fatalf("receipt %s/%s: %v", digest, nonce, err) + } + return row +} + +func TestApplyPaymentReceiptPaysOnce(t *testing.T) { + db, h := receiptFixture(t, "USDC", models.Outstanding) + + if got := applyReceipt(t, h, validReceipt("d1")); got != sui.ReceiptApplied { + t.Fatalf("first receipt %q", got) + } + if transactionStatus(t, db) != models.Paid { + t.Fatal("applied receipt left the transaction unpaid") + } + row := storedReceipt(t, db, "d1", testTxID) + if row.Disposition != "applied" || row.Amount != "7" || row.Checkpoint != (sql.NullInt64{Int64: 12, Valid: true}) || row.ObservedAt.IsZero() { + t.Fatalf("applied row %+v", row) + } + // The same receipt again, as after a restart: recognized, not reapplied. + if got := applyReceipt(t, h, validReceipt("d1")); got != sui.ReceiptDuplicate { + t.Fatalf("repeated receipt %q", got) + } + // A second payment by another chain transaction does not pay twice. + if got := applyReceipt(t, h, validReceipt("d2")); got != sui.ReceiptMismatch { + t.Fatalf("second payment %q", got) + } + if row := storedReceipt(t, db, "d2", testTxID); row.Disposition != "mismatch" || row.Detail != "already paid by d1" { + t.Fatalf("second payment row %+v", row) + } + // A recorded mismatch keeps its disposition when seen again. + if got := applyReceipt(t, h, validReceipt("d2")); got != sui.ReceiptMismatch { + t.Fatalf("repeated mismatch %q", got) + } + rows, err := database.New(db).ListPaymentReceiptsByNonce(t.Context(), testTxID) + if err != nil || len(rows) != 2 { + t.Fatalf("receipt rows %+v, %v", rows, err) + } +} + +func TestApplyPaymentReceiptRecordsRejections(t *testing.T) { + expired := validReceipt("d1") + expired.Timestamp = time.Now().Add(2 * time.Hour) + cases := []struct { + name string + method string + status models.TransactionState + edit func(r *sui.PaymentReceipt) + disposition sui.ReceiptDisposition + detail string + amount string + }{ + {"amount", "USDC", models.Outstanding, func(r *sui.PaymentReceipt) { r.Amount++ }, sui.ReceiptMismatch, "amount", "8"}, + {"amount beyond int64", "USDC", models.Outstanding, func(r *sui.PaymentReceipt) { r.Amount = math.MaxUint64 }, sui.ReceiptMismatch, "amount", "18446744073709551615"}, + {"coin type", "USDC", models.Outstanding, func(r *sui.PaymentReceipt) { r.CoinType = "0x2::sui::SUI" }, sui.ReceiptMismatch, "coin type", "7"}, + {"receiver", "USDC", models.Outstanding, func(r *sui.PaymentReceipt) { r.Receiver = "0xbeef" }, sui.ReceiptMismatch, "receiver", "7"}, + {"expired", "USDC", models.Outstanding, func(r *sui.PaymentReceipt) { *r = expired }, sui.ReceiptExpired, "", "7"}, + {"TEST method", "TEST", models.Outstanding, func(*sui.PaymentReceipt) {}, sui.ReceiptMismatch, "method", "7"}, + {"refunded transaction", "USDC", models.Refunded, func(*sui.PaymentReceipt) {}, sui.ReceiptMismatch, "transaction not outstanding", "7"}, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + db, h := receiptFixture(t, tc.method, tc.status) + r := validReceipt("d1") + tc.edit(&r) + if got := applyReceipt(t, h, r); got != tc.disposition { + t.Fatalf("disposition %q, want %q", got, tc.disposition) + } + if transactionStatus(t, db) != tc.status { + t.Fatal("rejected receipt changed the transaction") + } + row := storedReceipt(t, db, "d1", testTxID) + if row.Disposition != string(tc.disposition) || row.Detail != tc.detail || row.Amount != tc.amount { + t.Fatalf("row %+v", row) + } + }) + } +} + +func TestApplyPaymentReceiptUnknownNonce(t *testing.T) { + db, h := receiptFixture(t, "USDC", models.Outstanding) + r := validReceipt("d1") + r.Nonce = "unknown" + if got := applyReceipt(t, h, r); got != sui.ReceiptUnknownIntent { + t.Fatalf("unknown nonce to our address %q", got) + } + storedReceipt(t, db, "d1", "unknown") + + // Another payee's receipt is not ours and is not recorded. + r.Digest, r.Receiver = "d2", "0xbeef" + if got := applyReceipt(t, h, r); got != "" { + t.Fatalf("receipt to another address %q", got) + } + if _, err := database.New(db).GetPaymentReceipt(t.Context(), database.GetPaymentReceiptParams{TxDigest: "d2", Nonce: "unknown"}); !errors.Is(err, sql.ErrNoRows) { + t.Fatalf("foreign receipt recorded: %v", err) + } +} + +func TestApplyPaymentReceiptDisabled(t *testing.T) { + db := newRefundDatabase(t) + h, _ := newDisabledHandler(t, db, true, false) + _, err := h.ApplyPaymentReceipt(context.Background(), validReceipt("d1")) + if !errors.Is(err, ErrPaymentsDisabled) { + t.Fatalf("disabled mode: %v", err) + } + var n int + if err := db.QueryRow("SELECT COUNT(*) FROM payment_receipts").Scan(&n); err != nil || n != 0 { + t.Fatalf("disabled mode recorded %d receipts: %v", n, err) + } +} diff --git a/internal/dispatcher/payments/refund_admission_test.go b/internal/dispatcher/payments/refund_admission_test.go index a6b7de79..5e9be0e0 100644 --- a/internal/dispatcher/payments/refund_admission_test.go +++ b/internal/dispatcher/payments/refund_admission_test.go @@ -15,6 +15,7 @@ import ( "github.com/google/uuid" "github.com/netsec-ethz/debuglet/internal/dispatcher/database" "github.com/netsec-ethz/debuglet/internal/dispatcher/models" + "github.com/netsec-ethz/debuglet/internal/dispatcher/payments/sui" "github.com/netsec-ethz/debuglet/internal/sqlitedb" ) @@ -99,7 +100,9 @@ func TestUnadmittedRefundAndAdmissionHaveOneWinner(t *testing.T) { for _, latePayment := range []bool{false, true} { if latePayment { // A repeated payment notification must not revive a refunded order. - h.CompleteTransaction(testTxID, t.Context()) + if _, err := h.ApplyPaymentReceipt(t.Context(), sui.PaymentReceipt{Digest: "late-payment", Nonce: testTxID}); err != nil { + t.Fatal(err) + } } if claimed, err := claimRefundOrder(t.Context(), db); err != nil || claimed { t.Fatalf("claim refunded order: %t, %v", claimed, err) diff --git a/internal/dispatcher/payments/sui/export_test.go b/internal/dispatcher/payments/sui/export_test.go new file mode 100644 index 00000000..b37bcec0 --- /dev/null +++ b/internal/dispatcher/payments/sui/export_test.go @@ -0,0 +1,32 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package sui + +import ( + "context" + + v2 "github.com/block-vision/sui-go-sdk/pb/sui/rpc/v2" +) + +// CatchUpRange runs one catch-up over a known tip, without the chain's ledger +// service. +func (l *Listener) CatchUpRange(ctx context.Context, after, tip uint64) error { + return l.catchUpRange(ctx, after, tip) +} + +// CatchUpTo runs the catch-up of Start over a known tip. +func (l *Listener) CatchUpTo(ctx context.Context, cursor *uint64, tip uint64) (*uint64, error) { + return l.catchUpTo(ctx, cursor, tip) +} + +// ProcessCheckpoint handles one streamed checkpoint. +func (l *Listener) ProcessCheckpoint(ctx context.Context, cp *v2.Checkpoint) error { + return l.processCheckpoint(ctx, cp) +} + +// StreamCheckpoint handles one streamed checkpoint after cursor, as the +// stream loop does. +func (l *Listener) StreamCheckpoint(ctx context.Context, cursor *uint64, cp *v2.Checkpoint) (uint64, error) { + return l.streamCheckpoint(ctx, cursor, cp) +} diff --git a/internal/dispatcher/payments/sui/listener.go b/internal/dispatcher/payments/sui/listener.go index a90d10e0..baed7a63 100644 --- a/internal/dispatcher/payments/sui/listener.go +++ b/internal/dispatcher/payments/sui/listener.go @@ -9,7 +9,9 @@ import ( "database/sql" "encoding/base64" "encoding/json" + "errors" "fmt" + "math" "net/http" "strconv" "strings" @@ -31,8 +33,44 @@ import ( const catchUpPageSize = 50 +// ReceiptDisposition is what a chain payment receipt was recorded as. +type ReceiptDisposition string + +const ( + // ReceiptApplied marks the receipt that paid its transaction. + ReceiptApplied ReceiptDisposition = "applied" + // ReceiptDuplicate is returned for a receipt that was already applied; + // its effect is not repeated. + ReceiptDuplicate ReceiptDisposition = "duplicate" + // ReceiptMismatch marks a receipt that names one of our transactions but + // does not pay it: wrong method, coin type, receiver or amount, or a + // transaction that is no longer outstanding. + ReceiptMismatch ReceiptDisposition = "mismatch" + // ReceiptUnknownIntent marks a receipt to our address whose nonce names + // no local transaction. It is left for operator reconciliation. + ReceiptUnknownIntent ReceiptDisposition = "unknown_intent" + // ReceiptExpired marks a receipt timestamped after its transaction expired. + ReceiptExpired ReceiptDisposition = "expired" +) + +// PaymentReceipt is a decoded payment kit receipt event. +type PaymentReceipt struct { + Digest string // chain transaction digest + Nonce string // our transaction id + Amount uint64 // base units of CoinType + CoinType string + Receiver string + Timestamp time.Time + Checkpoint uint64 // 0 when the source does not report it +} + +// TransactionFulfiller records payment receipts. type TransactionFulfiller interface { - CompleteTransaction(transactionId string, ctx context.Context) + // ApplyPaymentReceipt records r and applies its effect at most once. An + // empty disposition with a nil error means the receipt is not addressed to + // this dispatcher and nothing was recorded. After an error nothing was + // recorded and the receipt must be processed again. + ApplyPaymentReceipt(ctx context.Context, r PaymentReceipt) (ReceiptDisposition, error) } type Listener struct { @@ -48,7 +86,6 @@ type Listener struct { httpClient *http.Client db *sql.DB fulfiller TransactionFulfiller - cfg *config.DispatcherConfig } func NewListener(cfg *config.DispatcherConfig, db *sql.DB, logger *zap.Logger, tf TransactionFulfiller) *Listener { @@ -71,25 +108,17 @@ func NewListener(cfg *config.DispatcherConfig, db *sql.DB, logger *zap.Logger, t client: client, httpClient: &http.Client{Timeout: 30 * time.Second}, fulfiller: tf, - cfg: cfg, } } +// Start processes payment receipts until ctx ends. The stored cursor names +// the last checkpoint whose receipts are all recorded; it advances only after +// that, so an interrupted range is read again and its receipts are recognized +// as already recorded. A stored cursor that cannot be parsed is an error. func (l *Listener) Start(ctx context.Context) error { - queries := database.New(l.db) - raw, err := queries.GetTransactionState(ctx, l.cursorKey) - if err != nil && err != sql.ErrNoRows { - return fmt.Errorf("load sui cursor: %w", err) - } - - var cursor *uint64 - if raw.Value != "" { - seq, err := strconv.ParseUint(raw.Value, 10, 64) - if err != nil { - l.logger.Warn("invalid stored sui cursor, resetting to start", zap.Error(err)) - } else { - cursor = &seq - } + cursor, err := l.loadCursor(ctx) + if err != nil { + return err } l.logger.Info("sui event listener started", zap.String("event_type", l.eventType)) @@ -98,14 +127,15 @@ func (l *Listener) Start(ctx context.Context) error { for { cursor, err = l.catchUp(ctx, cursor) if err != nil { + // The stream would advance the cursor past the unprocessed range. l.logger.Error("sui catch-up error", zap.Error(err)) + } else { + err = l.subscribeGRPC(ctx, &cursor) } - - err = l.subscribeGRPC(ctx, &cursor) if ctx.Err() != nil { return nil } - l.logger.Warn("sui grpc stream ended, reconnecting", zap.Error(err), zap.Duration("backoff", backoff)) + l.logger.Warn("sui receipt processing interrupted, retrying", zap.Error(err), zap.Duration("backoff", backoff)) select { case <-ctx.Done(): @@ -116,6 +146,30 @@ func (l *Listener) Start(ctx context.Context) error { } } +// loadCursor returns the stored cursor, or nil when none is stored. +func (l *Listener) loadCursor(ctx context.Context) (*uint64, error) { + raw, err := database.New(l.db).GetTransactionState(ctx, l.cursorKey) + if errors.Is(err, sql.ErrNoRows) { + return nil, nil + } + if err != nil { + return nil, fmt.Errorf("load sui cursor %q: %w", l.cursorKey, err) + } + seq, err := strconv.ParseUint(raw.Value, 10, 64) + if err != nil { + return nil, fmt.Errorf("stored sui cursor %q is invalid: %w", l.cursorKey, err) + } + return &seq, nil +} + +func (l *Listener) storeCursor(ctx context.Context, seq uint64) error { + _, err := database.New(l.db).UpdateTransactionState(ctx, database.UpdateTransactionStateParams{Key: l.cursorKey, Value: strconv.FormatUint(seq, 10)}) + if err != nil { + return fmt.Errorf("persist sui cursor: %w", err) + } + return nil +} + func (l *Listener) catchUp(ctx context.Context, cursor *uint64) (*uint64, error) { ledger, err := l.client.LedgerService(ctx) if err != nil { @@ -126,9 +180,16 @@ func (l *Listener) catchUp(ctx context.Context, cursor *uint64) (*uint64, error) if err != nil { return cursor, fmt.Errorf("get service info: %w", err) } - tip := info.GetCheckpointHeight() + return l.catchUpTo(ctx, cursor, info.GetCheckpointHeight()) +} +// catchUpTo brings the stored cursor to tip. Without a stored cursor it +// stores tip, so a restart keeps the same starting point. +func (l *Listener) catchUpTo(ctx context.Context, cursor *uint64, tip uint64) (*uint64, error) { if cursor == nil { + if err := l.storeCursor(ctx, tip); err != nil { + return nil, err + } l.logger.Info("no stored sui cursor, starting at chain tip", zap.Uint64("checkpoint", tip)) return &tip, nil } @@ -136,8 +197,18 @@ func (l *Listener) catchUp(ctx context.Context, cursor *uint64) (*uint64, error) return cursor, nil } + if err := l.catchUpRange(ctx, *cursor, tip); err != nil { + return cursor, err + } + return &tip, nil +} + +// catchUpRange records every receipt event after checkpoint after and then +// stores tip as the cursor. It returns on the first event that could not be +// recorded, leaving the stored cursor where it was. +func (l *Listener) catchUpRange(ctx context.Context, after, tip uint64) error { l.logger.Info("sui catch-up: querying PaymentReceipt events via GraphQL", - zap.Uint64("after_checkpoint", *cursor), zap.Uint64("to", tip)) + zap.Uint64("after_checkpoint", after), zap.Uint64("to", tip)) var ( pageCursor *string @@ -145,21 +216,23 @@ func (l *Listener) catchUp(ctx context.Context, cursor *uint64) (*uint64, error) ) for { if ctx.Err() != nil { - return cursor, ctx.Err() + return ctx.Err() } - page, err := l.queryPaymentReceiptEvents(ctx, *cursor, pageCursor) + page, err := l.queryPaymentReceiptEvents(ctx, after, pageCursor) if err != nil { - return cursor, fmt.Errorf("query payment receipt events: %w", err) + return fmt.Errorf("query payment receipt events: %w", err) } for _, node := range page.Events.Nodes { contents, err := base64.StdEncoding.DecodeString(node.Contents.Bcs) if err != nil { - l.logger.Warn("PaymentReceipt: failed to decode base64 contents", zap.Error(err)) - continue + return fmt.Errorf("payment receipt in transaction %s: decode base64: %w", node.Transaction.Digest, err) + } + // The GraphQL query does not report the event's checkpoint. + if _, err := l.processPaymentReceipt(ctx, contents, node.Transaction.Digest, 0); err != nil { + return err } - l.processPaymentReceipt(ctx, contents, node.Transaction.Digest) numEvents++ } @@ -170,17 +243,11 @@ func (l *Listener) catchUp(ctx context.Context, cursor *uint64) (*uint64, error) pageCursor = &endCursor } - l.logger.Info("sui catch-up: done", zap.Int("events_processed", numEvents), zap.Uint64("checkpoint", tip)) - - cursor = &tip - - queries := database.New(l.db) - _, err = queries.UpdateTransactionState(ctx, database.UpdateTransactionStateParams{Key: l.cursorKey, Value: strconv.FormatUint(tip, 10)}) - if err != nil { - l.logger.Error("failed to persist sui cursor", zap.Error(err)) + if err := l.storeCursor(ctx, tip); err != nil { + return err } - - return cursor, nil + l.logger.Info("sui catch-up: done", zap.Int("events_processed", numEvents), zap.Uint64("checkpoint", tip)) + return nil } const paymentReceiptEventsQuery = ` @@ -291,84 +358,76 @@ func (l *Listener) subscribeGRPC(ctx context.Context, cursor **uint64) error { return fmt.Errorf("recv checkpoint: %w", err) } - cp := resp.GetCheckpoint() - for _, tx := range cp.GetTransactions() { - txDigest := tx.GetDigest() - for _, ev := range tx.GetEvents().GetEvents() { - if ev.GetEventType() != l.eventType { - continue - } - l.processEventGRPC(ctx, ev, txDigest) - } - } - - seq := cp.GetSequenceNumber() - *cursor = &seq - - queries := database.New(l.db) - _, err = queries.UpdateTransactionState(ctx, database.UpdateTransactionStateParams{Key: l.cursorKey, Value: strconv.FormatUint(seq, 10)}) + seq, err := l.streamCheckpoint(ctx, *cursor, resp.GetCheckpoint()) if err != nil { - l.logger.Error("failed to persist sui cursor", zap.Error(err)) + return err } + *cursor = &seq } } -func (l *Listener) processEventGRPC(ctx context.Context, ev *v2.Event, txDigest string) { - l.processPaymentReceipt(ctx, ev.GetContents().GetValue(), txDigest) -} -func (l *Listener) processPaymentReceipt(ctx context.Context, contents []byte, txDigest string) { - receipt, err := decodePaymentReceiptEvent(contents) - if err != nil { - l.logger.Warn("PaymentReceipt: failed to decode BCS contents", - zap.String("tx", txDigest), - zap.Error(err), - ) - return - } - - amount := int64(receipt.PaymentAmount) - receiver := fmt.Sprintf("0x%x", receipt.Receiver) - // TODO refund failed purchases - queries := database.New(l.db) - transaction, err := queries.GetTransactionByID(ctx, receipt.Nonce) - if err != nil { - l.logger.Warn("failed to get transaction", zap.String("id", receipt.Nonce), zap.Error(err)) - return +// streamCheckpoint handles one streamed checkpoint after the stored cursor. +// The stream starts at the live checkpoint, so checkpoints between the cursor +// and it are caught up first; the cursor never passes an unread checkpoint. +func (l *Listener) streamCheckpoint(ctx context.Context, cursor *uint64, cp *v2.Checkpoint) (uint64, error) { + seq := cp.GetSequenceNumber() + if cursor != nil && seq > *cursor+1 { + if err := l.catchUpRange(ctx, *cursor, seq-1); err != nil { + return 0, err + } } - - if transaction.Method != "SUI" && transaction.Method != "USDC" { - l.logger.Warn("Wrong method for transaction", zap.String("found", transaction.Method)) + if err := l.processCheckpoint(ctx, cp); err != nil { + return 0, err } - switch transaction.Currency { - case "SUI": - if !strings.EqualFold(receipt.CoinType, "0x2::sui::SUI") && !strings.EqualFold(receipt.CoinType, "0000000000000000000000000000000000000000000000000000000000000002::sui::SUI") { - l.logger.Warn("wrong coin type", zap.String("expected", "0x2::sui::SUI"), zap.String("found", receipt.CoinType)) - return - } - case "USDC": - if !strings.EqualFold("0x"+receipt.CoinType, GetCoinType(transaction.Currency, l.cfg.Sui.Network)) { - l.logger.Warn("wrong coin type", zap.String("expected", GetCoinType(transaction.Currency, l.cfg.Sui.Network)), zap.String("found", receipt.CoinType)) - return + return seq, nil +} + +// processCheckpoint records every receipt event of one streamed checkpoint +// and then stores its sequence number as the cursor. +func (l *Listener) processCheckpoint(ctx context.Context, cp *v2.Checkpoint) error { + seq := cp.GetSequenceNumber() + for _, tx := range cp.GetTransactions() { + for _, ev := range tx.GetEvents().GetEvents() { + if ev.GetEventType() != l.eventType { + continue + } + if _, err := l.processPaymentReceipt(ctx, ev.GetContents().GetValue(), tx.GetDigest(), seq); err != nil { + return err + } } } + return l.storeCursor(ctx, seq) +} - if amount != transaction.Price { - l.logger.Warn("payment didn't match price", zap.Int64("expected", transaction.Price), zap.Int64("actual", amount)) - return +// processPaymentReceipt decodes one receipt event and records it. An event +// that cannot be decoded is an error, like a failed write: skipping it would +// lose the payment once the cursor moves past it. +func (l *Listener) processPaymentReceipt(ctx context.Context, contents []byte, txDigest string, checkpoint uint64) (ReceiptDisposition, error) { + if txDigest == "" { + return "", errors.New("payment receipt event without transaction digest") } - if receiver != l.receiverAddress { - l.logger.Warn("payment to wrong address", zap.String("expected", l.receiverAddress), zap.String("actual", receiver)) - return + ev, err := decodePaymentReceiptEvent(contents) + if err != nil { + return "", fmt.Errorf("payment receipt in transaction %s: decode: %w", txDigest, err) } - if receipt.Timestamp.After(transaction.ExpiresAt.Time) { - l.logger.Warn("transaction expired", zap.Time("exp_time", transaction.ExpiresAt.Time), zap.Time("executed_at", receipt.Timestamp)) - return + receipt := PaymentReceipt{ + Digest: txDigest, + Nonce: ev.Nonce, + Amount: ev.PaymentAmount, + CoinType: ev.CoinType, + Receiver: fmt.Sprintf("0x%x", ev.Receiver[:]), + Timestamp: time.UnixMilli(int64(ev.TimestampMs)).UTC(), + Checkpoint: checkpoint, } - l.fulfiller.CompleteTransaction(transaction.ID, ctx) + disposition, err := l.fulfiller.ApplyPaymentReceipt(ctx, receipt) if err != nil { - l.logger.Error("failed to mark transaction as paid", zap.String("id", transaction.ID), zap.Error(err)) - return + return "", fmt.Errorf("record payment receipt %s/%s: %w", txDigest, ev.Nonce, err) + } + if disposition != "" { + l.logger.Info("payment receipt recorded", + zap.String("tx", txDigest), zap.String("nonce", ev.Nonce), zap.String("disposition", string(disposition))) } + return disposition, nil } type paymentType struct { @@ -384,13 +443,23 @@ type paymentReceipt struct { PaymentAmount uint64 Receiver suiModels.SuiAddressBytes CoinType string - Timestamp time.Time + TimestampMs uint64 } +// decodePaymentReceiptEvent decodes the BCS contents of a payment kit +// PaymentReceipt event. The layout is fixed by the Move struct, so bytes left +// over mean the event was not decoded as what it is. func decodePaymentReceiptEvent(data []byte) (paymentReceipt, error) { var ev paymentReceipt - if _, err := mystenbcs.Unmarshal(data, &ev); err != nil { + n, err := mystenbcs.Unmarshal(data, &ev) + if err != nil { return ev, err } + if n != len(data) { + return ev, fmt.Errorf("%d unexpected trailing bytes", len(data)-n) + } + if ev.TimestampMs > math.MaxInt64 { + return ev, fmt.Errorf("timestamp %d ms out of range", ev.TimestampMs) + } return ev, nil } diff --git a/internal/dispatcher/payments/sui/listener_test.go b/internal/dispatcher/payments/sui/listener_test.go new file mode 100644 index 00000000..50a2bb6f --- /dev/null +++ b/internal/dispatcher/payments/sui/listener_test.go @@ -0,0 +1,546 @@ +// SPDX-License-Identifier: Apache-2.0 +// Copyright 2026 ETH Zurich + +package sui_test + +import ( + "context" + "database/sql" + "encoding/base64" + "encoding/hex" + "encoding/json" + "fmt" + "math" + "net/http" + "net/http/httptest" + "path/filepath" + "strings" + "sync" + "testing" + "time" + + "github.com/netsec-ethz/debuglet/internal/dispatcher/config" + "github.com/netsec-ethz/debuglet/internal/dispatcher/database" + "github.com/netsec-ethz/debuglet/internal/dispatcher/models" + "github.com/netsec-ethz/debuglet/internal/dispatcher/payments" + "github.com/netsec-ethz/debuglet/internal/dispatcher/payments/sui" + "github.com/netsec-ethz/debuglet/internal/sqlitedb" + + suiModels "github.com/block-vision/sui-go-sdk/models" + "github.com/block-vision/sui-go-sdk/mystenbcs" + v2 "github.com/block-vision/sui-go-sdk/pb/sui/rpc/v2" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "go.uber.org/zap/zaptest/observer" + "google.golang.org/protobuf/proto" + _ "modernc.org/sqlite" +) + +const ( + testPackage = "0x5ca1ab1e" + eventType = testPackage + "::payment_kit::PaymentReceipt" + cursorKey = "sui_event_cursor:" + testPackage + price = 7 +) + +var ( + ourAddress = strings.Repeat("ab", 32) + otherAddress = strings.Repeat("cd", 32) + // The chain reports coin types without the 0x prefix. + usdcType = strings.TrimPrefix(sui.GetCoinType("USDC", "testnet"), "0x") +) + +// registryPayment and receiptEvent mirror the payment kit's PaymentReceipt +// event layout, so fixtures are encoded the way the chain encodes them. +type registryPayment struct { + Ephemeral any + Registry *suiModels.SuiAddressBytes +} + +func (*registryPayment) IsBcsEnum() {} + +type receiptEvent struct { + PaymentType *registryPayment + Nonce string + PaymentAmount uint64 + Receiver suiModels.SuiAddressBytes + CoinType string + TimestampMs uint64 +} + +func receipt(nonce string, edit ...func(*receiptEvent)) receiptEvent { + ev := receiptEvent{ + PaymentType: ®istryPayment{Registry: &suiModels.SuiAddressBytes{1}}, + Nonce: nonce, + PaymentAmount: price, + Receiver: address(ourAddress), + CoinType: usdcType, + TimestampMs: uint64(time.Now().UnixMilli()), + } + for _, e := range edit { + e(&ev) + } + return ev +} + +func address(h string) suiModels.SuiAddressBytes { + var a suiModels.SuiAddressBytes + b, err := hex.DecodeString(h) + if err != nil || len(b) != len(a) { + panic("bad fixture address " + h) + } + copy(a[:], b) + return a +} + +func encode(t *testing.T, ev receiptEvent) []byte { + t.Helper() + b, err := mystenbcs.Marshal(ev) + if err != nil { + t.Fatal(err) + } + return b +} + +// event is one GraphQL event node. +type event struct { + digest string + bcs []byte +} + +func node(t *testing.T, digest string, ev receiptEvent) event { + t.Helper() + return event{digest: digest, bcs: encode(t, ev)} +} + +// graphQL serves PaymentReceipt events in pages, linked by endCursor. +type graphQL struct { + mu sync.Mutex + pages [][]event + queries []map[string]any +} + +func (g *graphQL) setPages(pages ...[]event) { + g.mu.Lock() + defer g.mu.Unlock() + g.pages = pages +} + +func (g *graphQL) ServeHTTP(w http.ResponseWriter, r *http.Request) { + var req struct { + Variables map[string]any `json:"variables"` + } + if err := json.NewDecoder(r.Body).Decode(&req); err != nil { + http.Error(w, err.Error(), http.StatusBadRequest) + return + } + g.mu.Lock() + defer g.mu.Unlock() + g.queries = append(g.queries, req.Variables) + index := 0 + if after, ok := req.Variables["after"].(string); ok { + fmt.Sscanf(after, "page-%d", &index) + } + type nodeJSON struct { + Transaction struct { + Digest string `json:"digest"` + } `json:"transaction"` + Contents struct { + Bcs string `json:"bcs"` + } `json:"contents"` + } + nodes := []nodeJSON{} + if index < len(g.pages) { + for _, ev := range g.pages[index] { + var n nodeJSON + n.Transaction.Digest = ev.digest + n.Contents.Bcs = base64.StdEncoding.EncodeToString(ev.bcs) + nodes = append(nodes, n) + } + } + resp := map[string]any{"data": map[string]any{"events": map[string]any{ + "pageInfo": map[string]any{"hasNextPage": index+1 < len(g.pages), "endCursor": fmt.Sprintf("page-%d", index+1)}, + "nodes": nodes, + }}} + _ = json.NewEncoder(w).Encode(resp) +} + +type fixture struct { + db *sql.DB + cfg *config.DispatcherConfig + server *graphQL + core zapcore.Core + logs *observer.ObservedLogs + ph *payments.PaymentHandler +} + +// newFixture is a real dispatcher database, an enabled payment handler as the +// listener's fulfiller and a local GraphQL server. No chain endpoint is +// contacted: the gRPC client is never used and the keystore does not exist. +func newFixture(t *testing.T) *fixture { + t.Helper() + db, err := sqlitedb.Open(filepath.Join(t.TempDir(), "dispatcher.sqlite"), sqlitedb.Create()) + if err != nil { + t.Fatal(err) + } + t.Cleanup(func() { _ = db.Close() }) + if _, err := sqlitedb.Migrate(t.Context(), db, database.MigrationFS(), sqlitedb.Latest); err != nil { + t.Fatalf("migrate: %v", err) + } + server := &graphQL{} + httpServer := httptest.NewServer(server) + t.Cleanup(httpServer.Close) + cfg := &config.DispatcherConfig{Sui: config.SuiConfig{ + Network: "testnet", + GRPCEndpoint: "fullnode.invalid:443", + GraphQLURL: httpServer.URL, + Address: "0x" + strings.ToUpper(ourAddress), + PaymentKitPackage: testPackage, + KeystorePath: filepath.Join(t.TempDir(), "missing.keystore"), + }} + core, logs := observer.New(zapcore.InfoLevel) + return &fixture{db: db, cfg: cfg, server: server, core: core, logs: logs, ph: payments.NewPaymentHandler(db, cfg, zap.New(core))} +} + +// listener is a fresh listener, as after a dispatcher restart. +func (f *fixture) listener() *sui.Listener { + return sui.NewListener(f.cfg, f.db, zap.New(f.core), f.ph) +} + +func (f *fixture) transaction(t *testing.T, id string, expires time.Time) { + t.Helper() + if _, err := database.New(f.db).CreateTransaction(t.Context(), database.CreateTransactionParams{ + ID: id, AuthKey: "key", Price: price, Currency: "USDC", Method: "USDC", + ExpiresAt: models.NewUTCTime(expires), Status: int64(models.Outstanding), Hash: "hash", + }); err != nil { + t.Fatal(err) + } +} + +func (f *fixture) status(t *testing.T, id string) models.TransactionState { + t.Helper() + transaction, err := database.New(f.db).GetTransactionByID(t.Context(), id) + if err != nil { + t.Fatal(err) + } + return models.TransactionState(transaction.Status) +} + +func (f *fixture) setCursor(t *testing.T, value string) { + t.Helper() + if _, err := database.New(f.db).UpdateTransactionState(t.Context(), database.UpdateTransactionStateParams{Key: cursorKey, Value: value}); err != nil { + t.Fatal(err) + } +} + +func (f *fixture) cursor(t *testing.T) string { + t.Helper() + state, err := database.New(f.db).GetTransactionState(t.Context(), cursorKey) + if err != nil { + t.Fatal(err) + } + return state.Value +} + +// receipts returns "digest/nonce=disposition:detail:amount" for every row. +func (f *fixture) receipts(t *testing.T) []string { + t.Helper() + rows, err := f.db.QueryContext(t.Context(), "SELECT tx_digest, nonce, disposition, detail, amount FROM payment_receipts ORDER BY tx_digest, nonce") + if err != nil { + t.Fatal(err) + } + defer rows.Close() + var out []string + for rows.Next() { + var digest, nonce, disposition, detail, amount string + if err := rows.Scan(&digest, &nonce, &disposition, &detail, &amount); err != nil { + t.Fatal(err) + } + out = append(out, fmt.Sprintf("%s/%s=%s:%s:%s", digest, nonce, disposition, detail, amount)) + } + if err := rows.Err(); err != nil { + t.Fatal(err) + } + return out +} + +// dispositions returns the dispositions the listener logged since the last +// call, in order. +func (f *fixture) dispositions() []string { + var out []string + for _, entry := range f.logs.TakeAll() { + if entry.Message == "payment receipt recorded" { + out = append(out, entry.ContextMap()["tx"].(string)+"="+entry.ContextMap()["disposition"].(string)) + } + } + return out +} + +func equal(t *testing.T, what string, got, want []string) { + t.Helper() + if strings.Join(got, "\n") != strings.Join(want, "\n") { + t.Fatalf("%s:\n got %q\nwant %q", what, got, want) + } +} + +func TestCatchUpAppliesEachReceiptOnce(t *testing.T) { + f := newFixture(t) + f.transaction(t, "tx-a", time.Now().Add(time.Hour)) + f.transaction(t, "tx-b", time.Now().Add(time.Hour)) + pageOne := []event{node(t, "d1", receipt("tx-a")), node(t, "d2", receipt("tx-b"))} + pageTwo := []event{node(t, "d1", receipt("tx-a")), node(t, "d3", receipt("tx-a"))} + f.server.setPages(pageOne, pageTwo) + + if err := f.listener().CatchUpRange(t.Context(), 10, 20); err != nil { + t.Fatal(err) + } + equal(t, "first pass", f.dispositions(), []string{"d1=applied", "d2=applied", "d1=duplicate", "d3=mismatch"}) + if f.status(t, "tx-a") != models.Paid || f.status(t, "tx-b") != models.Paid || f.cursor(t) != "20" { + t.Fatalf("after first pass: a=%v b=%v cursor=%s", f.status(t, "tx-a"), f.status(t, "tx-b"), f.cursor(t)) + } + want := []string{"d1/tx-a=applied::7", "d2/tx-b=applied::7", "d3/tx-a=mismatch:already paid by d1:7"} + equal(t, "rows", f.receipts(t), want) + f.server.mu.Lock() + after := f.server.queries[0]["afterCheckpoint"] + f.server.mu.Unlock() + if after != float64(10) { + t.Fatalf("queried after checkpoint %v", after) + } + + // A restart reads the same events again, in another order. + f.server.setPages(pageTwo, pageOne) + if err := f.listener().CatchUpRange(t.Context(), 20, 30); err != nil { + t.Fatal(err) + } + equal(t, "after restart", f.dispositions(), []string{"d1=duplicate", "d3=mismatch", "d1=duplicate", "d2=duplicate"}) + equal(t, "rows after restart", f.receipts(t), want) + if f.cursor(t) != "30" { + t.Fatalf("cursor %s", f.cursor(t)) + } +} + +func TestCatchUpRecordsRejectedReceipts(t *testing.T) { + f := newFixture(t) + for _, id := range []string{"amount", "huge", "coin", "receiver"} { + f.transaction(t, id, time.Now().Add(time.Hour)) + } + f.transaction(t, "late", time.Now().Add(-time.Minute)) + f.server.setPages([]event{ + node(t, "d1", receipt("amount", func(ev *receiptEvent) { ev.PaymentAmount = price + 1 })), + node(t, "d2", receipt("huge", func(ev *receiptEvent) { ev.PaymentAmount = math.MaxUint64 })), + node(t, "d3", receipt("coin", func(ev *receiptEvent) { + ev.CoinType = "0000000000000000000000000000000000000000000000000000000000000002::sui::SUI" + })), + node(t, "d4", receipt("receiver", func(ev *receiptEvent) { ev.Receiver = address(otherAddress) })), + node(t, "d5", receipt("late")), + node(t, "d6", receipt("nobody")), + node(t, "d7", receipt("nobody", func(ev *receiptEvent) { ev.Receiver = address(otherAddress) })), + }) + + if err := f.listener().CatchUpRange(t.Context(), 0, 5); err != nil { + t.Fatal(err) + } + equal(t, "rows", f.receipts(t), []string{ + "d1/amount=mismatch:amount:8", + "d2/huge=mismatch:amount:18446744073709551615", + "d3/coin=mismatch:coin type:7", + "d4/receiver=mismatch:receiver:7", + "d5/late=expired::7", + "d6/nobody=unknown_intent::7", + }) + for _, id := range []string{"amount", "huge", "coin", "receiver", "late"} { + if f.status(t, id) != models.Outstanding { + t.Fatalf("%s was paid by a rejected receipt", id) + } + } + if f.cursor(t) != "5" { + t.Fatalf("cursor %s", f.cursor(t)) + } +} + +// A receipt that cannot be recorded stops the pass and keeps the cursor, so +// the same range is read again and nothing is lost or applied twice. +func TestCatchUpFailureKeepsCursor(t *testing.T) { + f := newFixture(t) + f.transaction(t, "tx-a", time.Now().Add(time.Hour)) + f.transaction(t, "tx-b", time.Now().Add(time.Hour)) + f.setCursor(t, "10") + f.server.setPages([]event{node(t, "d1", receipt("tx-a"))}, []event{node(t, "d2", receipt("tx-b"))}) + if _, err := f.db.Exec(`CREATE TRIGGER fail_receipt BEFORE INSERT ON payment_receipts WHEN NEW.nonce = 'tx-b' +BEGIN SELECT RAISE(ABORT, 'scripted receipt failure'); END`); err != nil { + t.Fatal(err) + } + + err := f.listener().CatchUpRange(t.Context(), 10, 20) + if err == nil || !strings.Contains(err.Error(), "scripted receipt failure") { + t.Fatalf("catch-up with a failing write: %v", err) + } + if f.cursor(t) != "10" || f.status(t, "tx-b") != models.Outstanding { + t.Fatalf("failed pass: cursor %s, tx-b %v", f.cursor(t), f.status(t, "tx-b")) + } + equal(t, "rows after failure", f.receipts(t), []string{"d1/tx-a=applied::7"}) + + if _, err := f.db.Exec(`DROP TRIGGER fail_receipt`); err != nil { + t.Fatal(err) + } + f.dispositions() + if err := f.listener().CatchUpRange(t.Context(), 10, 20); err != nil { + t.Fatal(err) + } + equal(t, "retry", f.dispositions(), []string{"d1=duplicate", "d2=applied"}) + if f.cursor(t) != "20" || f.status(t, "tx-b") != models.Paid { + t.Fatalf("retried pass: cursor %s, tx-b %v", f.cursor(t), f.status(t, "tx-b")) + } +} + +func TestCatchUpUndecodableEventKeepsCursor(t *testing.T) { + for name, bcs := range map[string][]byte{ + "truncated": encode(t, receipt("tx-a"))[:20], + "trailing bytes": append(encode(t, receipt("tx-a")), 0), + } { + t.Run(name, func(t *testing.T) { + f := newFixture(t) + f.transaction(t, "tx-a", time.Now().Add(time.Hour)) + f.setCursor(t, "10") + f.server.setPages([]event{{digest: "d1", bcs: bcs}}) + if err := f.listener().CatchUpRange(t.Context(), 10, 20); err == nil || !strings.Contains(err.Error(), "decode") { + t.Fatalf("undecodable event: %v", err) + } + if f.cursor(t) != "10" || len(f.receipts(t)) != 0 { + t.Fatalf("cursor %s, rows %v", f.cursor(t), f.receipts(t)) + } + }) + } +} + +// checkpoint is a streamed checkpoint with one receipt for nonce among +// another package's event. +func checkpoint(t *testing.T, seq uint64, digest string, nonce string) *v2.Checkpoint { + t.Helper() + return &v2.Checkpoint{ + SequenceNumber: proto.Uint64(seq), + Transactions: []*v2.ExecutedTransaction{{ + Digest: proto.String(digest), + Events: &v2.TransactionEvents{Events: []*v2.Event{ + {EventType: proto.String("0x2::coin::Other"), Contents: &v2.Bcs{Value: []byte{0xff}}}, + {EventType: proto.String(eventType), Contents: &v2.Bcs{Value: encode(t, receipt(nonce))}}, + }}, + }}, + } +} + +func TestProcessCheckpoint(t *testing.T) { + f := newFixture(t) + f.transaction(t, "tx-a", time.Now().Add(time.Hour)) + f.transaction(t, "tx-b", time.Now().Add(time.Hour)) + f.setCursor(t, "41") + if err := f.listener().ProcessCheckpoint(t.Context(), checkpoint(t, 42, "d1", "tx-a")); err != nil { + t.Fatal(err) + } + row, err := database.New(f.db).GetPaymentReceipt(t.Context(), database.GetPaymentReceiptParams{TxDigest: "d1", Nonce: "tx-a"}) + if err != nil || row.Disposition != "applied" || row.Checkpoint != (sql.NullInt64{Int64: 42, Valid: true}) { + t.Fatalf("streamed receipt %+v, %v", row, err) + } + if f.cursor(t) != "42" || f.status(t, "tx-a") != models.Paid { + t.Fatalf("cursor %s, tx-a %v", f.cursor(t), f.status(t, "tx-a")) + } + + if _, err := f.db.Exec(`CREATE TRIGGER fail_receipt BEFORE INSERT ON payment_receipts +BEGIN SELECT RAISE(ABORT, 'scripted receipt failure'); END`); err != nil { + t.Fatal(err) + } + if err := f.listener().ProcessCheckpoint(t.Context(), checkpoint(t, 43, "d2", "tx-b")); err == nil { + t.Fatal("checkpoint with a failing write succeeded") + } + if f.cursor(t) != "42" || f.status(t, "tx-b") != models.Outstanding { + t.Fatalf("failed checkpoint: cursor %s, tx-b %v", f.cursor(t), f.status(t, "tx-b")) + } +} + +func TestStartRefusesInvalidCursor(t *testing.T) { + f := newFixture(t) + f.setCursor(t, "not-a-checkpoint") + ctx, cancel := context.WithTimeout(t.Context(), 5*time.Second) + defer cancel() + err := f.listener().Start(ctx) + if err == nil || !strings.Contains(err.Error(), cursorKey) { + t.Fatalf("Start with an invalid cursor: %v", err) + } + if ctx.Err() != nil { + t.Fatal("Start did not fail before running") + } +} + +// The stream starts at the live checkpoint. Checkpoints between the stored +// cursor and it are caught up before the cursor moves past them. +func TestStreamCatchesUpGapBeforeCheckpoint(t *testing.T) { + f := newFixture(t) + f.transaction(t, "tx-gap", time.Now().Add(time.Hour)) + f.transaction(t, "tx-live", time.Now().Add(time.Hour)) + f.setCursor(t, "10") + f.server.setPages([]event{node(t, "d-gap", receipt("tx-gap"))}) + l := f.listener() + cursor := uint64(10) + + seq, err := l.StreamCheckpoint(t.Context(), &cursor, checkpoint(t, 15, "d-live", "tx-live")) + if err != nil || seq != 15 { + t.Fatalf("StreamCheckpoint = %d, %v", seq, err) + } + equal(t, "order", f.dispositions(), []string{"d-gap=applied", "d-live=applied"}) + f.server.mu.Lock() + queries := len(f.server.queries) + after := f.server.queries[0]["afterCheckpoint"] + f.server.mu.Unlock() + if queries != 1 || after != float64(10) { + t.Fatalf("gap queries %d after %v", queries, after) + } + if f.cursor(t) != "15" { + t.Fatalf("cursor %s", f.cursor(t)) + } + + // The next checkpoint follows directly: no catch-up query. + cursor = 15 + if _, err := l.StreamCheckpoint(t.Context(), &cursor, checkpoint(t, 16, "d-next", "tx-live")); err != nil { + t.Fatal(err) + } + f.server.mu.Lock() + queries = len(f.server.queries) + f.server.mu.Unlock() + if queries != 1 || f.cursor(t) != "16" { + t.Fatalf("contiguous checkpoint: queries %d, cursor %s", queries, f.cursor(t)) + } +} + +// A failed gap catch-up leaves the cursor before the gap. +func TestStreamGapFailureKeepsCursor(t *testing.T) { + f := newFixture(t) + f.transaction(t, "tx-gap", time.Now().Add(time.Hour)) + f.setCursor(t, "10") + f.server.setPages([]event{{digest: "d-gap", bcs: []byte{1}}}) + cursor := uint64(10) + if _, err := f.listener().StreamCheckpoint(t.Context(), &cursor, checkpoint(t, 15, "d-live", "tx-gap")); err == nil { + t.Fatal("gap with an undecodable event succeeded") + } + if f.cursor(t) != "10" || len(f.receipts(t)) != 0 { + t.Fatalf("cursor %s, rows %v", f.cursor(t), f.receipts(t)) + } +} + +// Without a stored cursor the listener starts at the tip and stores it, so a +// restart before the first streamed checkpoint keeps that starting point. +func TestFirstStartStoresTip(t *testing.T) { + f := newFixture(t) + cursor, err := f.listener().CatchUpTo(t.Context(), nil, 77) + if err != nil || cursor == nil || *cursor != 77 { + t.Fatalf("CatchUpTo = %v, %v", cursor, err) + } + if f.cursor(t) != "77" { + t.Fatalf("stored cursor %s", f.cursor(t)) + } + f.server.mu.Lock() + queries := len(f.server.queries) + f.server.mu.Unlock() + if queries != 0 { + t.Fatalf("first start queried %d pages", queries) + } +} diff --git a/internal/dispatcher/transport/api/wallet_free_test.go b/internal/dispatcher/transport/api/wallet_free_test.go index 83b8a5fd..10835b43 100644 --- a/internal/dispatcher/transport/api/wallet_free_test.go +++ b/internal/dispatcher/transport/api/wallet_free_test.go @@ -24,6 +24,7 @@ import ( "github.com/netsec-ethz/debuglet/internal/dispatcher/database" "github.com/netsec-ethz/debuglet/internal/dispatcher/models" "github.com/netsec-ethz/debuglet/internal/dispatcher/payments" + "github.com/netsec-ethz/debuglet/internal/dispatcher/payments/sui" "github.com/netsec-ethz/debuglet/internal/dispatcher/transport/rpc" "github.com/netsec-ethz/debuglet/internal/sqlitedb" "github.com/netsec-ethz/debuglet/protocol" @@ -499,13 +500,15 @@ func TestWalletFreeHTTPFlow(t *testing.T) { t.Fatalf("%s in disabled mode returned %v, want ErrPaymentsDisabled", c.name, err) } } - ph.CompleteTransaction(wfChainOutstandingID, ctx) + if _, err := ph.ApplyPaymentReceipt(ctx, sui.PaymentReceipt{Digest: "wf-digest", Nonce: wfChainOutstandingID}); !errors.Is(err, payments.ErrPaymentsDisabled) { + t.Fatalf("ApplyPaymentReceipt in disabled mode returned %v, want ErrPaymentsDisabled", err) + } outstanding, err := queries.GetTransactionByID(ctx, wfChainOutstandingID) if err != nil { t.Fatalf("outstanding chain transaction: %v", err) } if outstanding.Status != int64(models.Outstanding) { - t.Fatalf("CompleteTransaction marked a chain transaction as %d in disabled mode", outstanding.Status) + t.Fatalf("ApplyPaymentReceipt marked a chain transaction as %d in disabled mode", outstanding.Status) } if after := wfTakeSnapshot(t, db); after != chainBefore { t.Fatalf("disabled chain paths changed rows:\nbefore:\n%s\nafter:\n%s", chainBefore, after) diff --git a/internal/storagecheck/init_test.go b/internal/storagecheck/init_test.go index 956f8b7e..e5a024bf 100644 --- a/internal/storagecheck/init_test.go +++ b/internal/storagecheck/init_test.go @@ -50,6 +50,8 @@ func TestBootstrapFresh(t *testing.T) { "measurement_execution": "debuglet_id started_observed_ns terminal_observed_ns exit_code tcp_endpoint", "retry_requests": "caller_scope request_id parent_run_id transaction_id request_hash intent_metadata", "allocation_reclamations": "debuglet_id reclaimed_at", + "payment_receipts": "tx_digest nonce disposition amount coin_type receiver checkpoint observed_at detail", + "chain_transfers": "id kind executor_id transaction_id order_id amount currency receiver state digest signed_transaction signature detail created_at updated_at", "account_run_reservations": "debuglet_id account_id queued_bytes retired_at last_retirement_check", "payload_tombstones": "debuglet_id deleted_at reason workload_sha256 certificate_sha256", "debuglets": "id uuid start_time end_time usage ceil_bw executor_id addresses state error transaction_id order_id dispatcher_incarnation session_id", @@ -76,7 +78,7 @@ func TestBootstrapFresh(t *testing.T) { "oauth_login_attempts": "state_hash provider verifier nonce purpose session_selector expires_at", "pending_identity_links": "user_id provider issuer subject login session_selector expires_at", "device_logins": "selector verifier_hash user_code_hash audience scopes label expires_at next_poll_at poll_interval state approver_session user_id", - }, []string{"account_recovery_pending", "account_run_reservations_live", "attribution_runs_source_idx", "debuglet_logs_sequence_idx", "debuglets_uuid_idx", "device_logins_expiry", "executor_enrollment_tokens_executor_idx", "measurement_profiles_owner", "oauth_login_expiry", "owned_executors_user_idx", "sessions_user_idx", "users_uuid_idx"}, []int64{0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21}) + }, []string{"account_recovery_pending", "account_run_reservations_live", "attribution_runs_source_idx", "chain_transfers_executor_idx", "debuglet_logs_sequence_idx", "debuglets_uuid_idx", "device_logins_expiry", "executor_enrollment_tokens_executor_idx", "measurement_profiles_owner", "oauth_login_expiry", "owned_executors_user_idx", "sessions_user_idx", "users_uuid_idx"}, []int64{0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22}) dispatcherSchemaRoundTrip(t, db) } else { assertSchema(t, db, map[string]string{ diff --git a/internal/storagecheck/policy.go b/internal/storagecheck/policy.go index c9d0257f..8b1d0012 100644 --- a/internal/storagecheck/policy.go +++ b/internal/storagecheck/policy.go @@ -31,7 +31,9 @@ const ( // an older database can then no longer answer them and must be refused instead // of failing later during service. const ( - MinimumDispatcherVersion int64 = 21 + // Schema 22: the chain listener records payment receipts and outbound + // transfers in payment_receipts and chain_transfers. + MinimumDispatcherVersion int64 = 22 MinimumExecutorVersion int64 = 6 ) @@ -72,6 +74,8 @@ func PolicyFor(role Role) (Policy, error) { }, Tables: map[string][]string{ "account_recovery_audit": {"selector", "user_id", "case_reference", "issued_by_uid", "issued_at", "expires_at", "consumed_at", "revoked_at", "revoked_by_uid", "revocation_reference"}, "allocation_reclamations": {"debuglet_id", "reclaimed_at"}, + "payment_receipts": {"tx_digest", "nonce", "disposition", "amount", "checkpoint", "observed_at"}, + "chain_transfers": {"id", "kind", "transaction_id", "amount", "state", "digest", "signed_transaction", "signature", "updated_at"}, "measurement_profiles": {"id", "user_id", "document"}, "measurement_requests": {"debuglet_id", "document"}, "measurement_execution": {"debuglet_id", "started_observed_ns", "terminal_observed_ns", "exit_code", "tcp_endpoint"}, From 2697f97632c81f02ef8d9b55dae85d1237392a61 Mon Sep 17 00:00:00 2001 From: TheodorAdrienIsaak Mattli Date: Mon, 5 Oct 2026 10:36:21 +0200 Subject: [PATCH 6/8] Expect the refunded TEST order in the rejected-allocation test The executor's rejected-allocation test still asserted that the failed run's TEST order stays outstanding, the limitation the settlement change removes: a failed TEST run now refunds its order locally and no credit is invented. The assertion follows the new behaviour. GitHub issue #78. --- internal/executor/cancellation_integration_test.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/internal/executor/cancellation_integration_test.go b/internal/executor/cancellation_integration_test.go index 48ae4c93..35f7e638 100644 --- a/internal/executor/cancellation_integration_test.go +++ b/internal/executor/cancellation_integration_test.go @@ -372,9 +372,9 @@ func TestRejectedAllocationFinalizesBothSQLiteOwners(t *testing.T) { t.Fatalf("duplicate report: %+v", extra) default: } - // The existing TEST refund limitation is preserved; no credit is invented. + // The failed run refunds its TEST order locally; no credit is invented. order, err := queries.GetDebugletOrder(ctx, dispatcherdb.GetDebugletOrderParams{TransactionID: transaction, OrderID: 1}) - if err != nil || order.State != int64(models.Outstanding) { + if err != nil || order.State != int64(models.Refunded) { t.Fatalf("TEST order = %+v, err=%v", order, err) } } From 83de859dfe4623f3bd7c19fdf01cadb6b84f4786 Mon Sep 17 00:00:00 2001 From: TheodorAdrienIsaak Mattli Date: Mon, 5 Oct 2026 11:11:41 +0200 Subject: [PATCH 7/8] Retry only local settlements and scan pending orders fairly The maintenance pass retried every outstanding order of a terminal run, including USDC refunds, which the terminal path sends inside the local transaction: a transfer whose response was lost or whose commit failed left the order outstanding and the next pass paid the buyer again. The pass also always listed the oldest rows, so a page of orders that keep failing kept every later order from being attempted. The pass now settles only wholly local outcomes, credits of any currency and TEST refunds, and defers a chain refund without touching the backend; chain refunds are attempted once from the terminal path until a durable transfer record takes them over. The listing continues after the last run the previous pass attempted and starts over once it is exhausted, so a failing order never blocks the ones after it. GitHub issue #78. --- .../database/queries/transactions.sql | 6 +- .../dispatcher/database/transactions.sql.go | 18 ++- internal/dispatcher/dispatcher.go | 3 + internal/dispatcher/payments/payments.go | 43 +++++-- .../dispatcher/payments/settlement_test.go | 112 ++++++++++++++++++ internal/dispatcher/settlement_sweep.go | 10 +- internal/dispatcher/settlement_sweep_test.go | 72 +++++++++-- 7 files changed, 238 insertions(+), 26 deletions(-) diff --git a/internal/dispatcher/database/queries/transactions.sql b/internal/dispatcher/database/queries/transactions.sql index 7e7f92fa..9b00e1ad 100644 --- a/internal/dispatcher/database/queries/transactions.sql +++ b/internal/dispatcher/database/queries/transactions.sql @@ -75,12 +75,14 @@ SELECT * FROM order_settlements WHERE transaction_id = ? AND order_id = ?; -- name: ListPendingSettlements :many -SELECT sqlc.embed(d), e.exit_code FROM debuglet_order o +-- Only wholly local settlements: credits of any currency and TEST refunds. +SELECT sqlc.embed(d), e.exit_code, o.currency FROM debuglet_order o JOIN debuglets d ON d.id = o.debuglet_id AND d.transaction_id = o.transaction_id AND d.order_id = o.order_id JOIN measurement_execution e ON e.debuglet_id = d.id WHERE o.state = sqlc.arg(outstanding_state) AND d.state = sqlc.arg(exited_state) - AND e.exit_code IS NOT NULL + AND e.exit_code IS NOT NULL AND (e.exit_code = 0 OR o.currency = 'TEST') + AND d.id > sqlc.arg(after_id) ORDER BY d.id LIMIT sqlc.arg(row_limit); diff --git a/internal/dispatcher/database/transactions.sql.go b/internal/dispatcher/database/transactions.sql.go index 813f5b47..ad5fef9e 100644 --- a/internal/dispatcher/database/transactions.sql.go +++ b/internal/dispatcher/database/transactions.sql.go @@ -464,29 +464,38 @@ func (q *Queries) InsertOrderSettlement(ctx context.Context, arg InsertOrderSett } const listPendingSettlements = `-- name: ListPendingSettlements :many -SELECT d.id, d.uuid, d.start_time, d.end_time, d.usage, d.ceil_bw, d.executor_id, d.addresses, d.state, d.error, d.transaction_id, d.order_id, d.dispatcher_incarnation, d.session_id, e.exit_code FROM debuglet_order o +SELECT d.id, d.uuid, d.start_time, d.end_time, d.usage, d.ceil_bw, d.executor_id, d.addresses, d.state, d.error, d.transaction_id, d.order_id, d.dispatcher_incarnation, d.session_id, e.exit_code, o.currency FROM debuglet_order o JOIN debuglets d ON d.id = o.debuglet_id AND d.transaction_id = o.transaction_id AND d.order_id = o.order_id JOIN measurement_execution e ON e.debuglet_id = d.id WHERE o.state = ?1 AND d.state = ?2 - AND e.exit_code IS NOT NULL + AND e.exit_code IS NOT NULL AND (e.exit_code = 0 OR o.currency = 'TEST') + AND d.id > ?3 ORDER BY d.id -LIMIT ?3 +LIMIT ?4 ` type ListPendingSettlementsParams struct { OutstandingState int64 ExitedState models.DebugletRunState + AfterID int64 RowLimit int64 } type ListPendingSettlementsRow struct { Debuglet Debuglet ExitCode sql.NullInt64 + Currency string } +// Only wholly local settlements: credits of any currency and TEST refunds. func (q *Queries) ListPendingSettlements(ctx context.Context, arg ListPendingSettlementsParams) ([]ListPendingSettlementsRow, error) { - rows, err := q.db.QueryContext(ctx, listPendingSettlements, arg.OutstandingState, arg.ExitedState, arg.RowLimit) + rows, err := q.db.QueryContext(ctx, listPendingSettlements, + arg.OutstandingState, + arg.ExitedState, + arg.AfterID, + arg.RowLimit, + ) if err != nil { return nil, err } @@ -510,6 +519,7 @@ func (q *Queries) ListPendingSettlements(ctx context.Context, arg ListPendingSet &i.Debuglet.DispatcherIncarnation, &i.Debuglet.SessionID, &i.ExitCode, + &i.Currency, ); err != nil { return nil, err } diff --git a/internal/dispatcher/dispatcher.go b/internal/dispatcher/dispatcher.go index 0d6dd168..23b7008a 100644 --- a/internal/dispatcher/dispatcher.go +++ b/internal/dispatcher/dispatcher.go @@ -77,6 +77,9 @@ type Dispatcher struct { now func() time.Time newExpiryTicker func(time.Duration) expiryTicker initializeEarnings func(context.Context, *RegisteredExecutor) + // settlementAfter is the run id the next settlement sweep continues + // after. Only the maintenance goroutine reads or writes it. + settlementAfter int64 destinations *resource.DestinationsUsage Payment *payments.PaymentHandler diff --git a/internal/dispatcher/payments/payments.go b/internal/dispatcher/payments/payments.go index 3d2d1182..15e5727b 100644 --- a/internal/dispatcher/payments/payments.go +++ b/internal/dispatcher/payments/payments.go @@ -291,7 +291,11 @@ func (p *PaymentHandler) RefundDebugletOrder(debuglet *database.Debuglet, refund // the decision in order_settlements in the same SQL transaction, together with // the earnings credit or the chain refund. The conditional state write is the // cheap guard against a second settlement, the settlement row's primary key the -// durable one; any failure rolls back all of it. +// durable one; any failure rolls back all of it. A USDC refund is sent inside +// the SQL transaction, so a failure after the transfer may leave the order +// Outstanding although the money moved: chain refunds are therefore attempted +// once, from the terminal path, and are not retried automatically until a +// durable transfer record takes them over. func (p *PaymentHandler) settleOrder(ctx context.Context, debuglet *database.Debuglet, kind string, refundAddress string, chainOnly bool) error { tx, err := p.db.BeginTx(ctx, nil) if err != nil { @@ -376,24 +380,35 @@ func (p *PaymentHandler) settleOrder(ctx context.Context, debuglet *database.Deb } // SettlePendingOrders applies SettleTerminalOrder to at most limit Outstanding -// orders whose run is terminal with a recorded exit code, in run order. A run -// without a recorded exit code is not settled: nothing infers its outcome. An -// order that fails stays Outstanding for a later pass and the others are still -// settled; the numbers of settled and failed orders are returned with the -// first failure. -func (p *PaymentHandler) SettlePendingOrders(ctx context.Context, limit int) (settled, failed int, err error) { +// orders whose run is terminal with a recorded exit code and whose run id is +// above after, in run order. A run without a recorded exit code is not settled: +// nothing infers its outcome. Only wholly local settlements are retried, credits +// and TEST refunds; a chain refund is never sent again from here and is counted +// as deferred. An order that fails stays Outstanding for a later pass and the +// others are still settled. next is the last run id attempted, or 0 once the +// listing is exhausted, so that the following pass continues after it and a +// failing order never keeps later ones from being attempted. The first failure +// is returned with the counts. +func (p *PaymentHandler) SettlePendingOrders(ctx context.Context, after int64, limit int) (settled, failed, deferred int, next int64, err error) { pending, err := database.New(p.db).ListPendingSettlements(ctx, database.ListPendingSettlementsParams{ - OutstandingState: int64(models.Outstanding), ExitedState: models.RunStateExited, RowLimit: int64(limit), + OutstandingState: int64(models.Outstanding), ExitedState: models.RunStateExited, AfterID: after, RowLimit: int64(limit), }) if err != nil { - return 0, 0, fmt.Errorf("failed to list pending settlements: %w", err) + return 0, 0, 0, after, fmt.Errorf("failed to list pending settlements: %w", err) } var first error + exhausted := len(pending) < limit for _, row := range pending { if ctx.Err() != nil { + exhausted = false break } run := row.Debuglet + next = run.ID + if row.ExitCode.Int64 != 0 && isChainCurrency(row.Currency) { + deferred++ + continue + } if err := p.SettleTerminalOrder(ctx, &run, int32(row.ExitCode.Int64)); err != nil { p.logger.Debug("Order settlement remains pending", zap.String("debugletID", run.Uuid.String())) failed++ @@ -405,7 +420,15 @@ func (p *PaymentHandler) SettlePendingOrders(ctx context.Context, limit int) (se settled++ p.logger.Info("Settled order of terminal run", zap.String("debugletID", run.Uuid.String()), zap.Int64("exitCode", row.ExitCode.Int64)) } - return settled, failed, first + if deferred > 0 { + p.logger.Debug("Chain refunds are not retried automatically", zap.Int("deferred", deferred)) + } + if exhausted { + next = 0 + } else if next == 0 { + next = after + } + return settled, failed, deferred, next, first } // RefundTransaction retains transaction-wide refunds, including claimed orders. diff --git a/internal/dispatcher/payments/settlement_test.go b/internal/dispatcher/payments/settlement_test.go index 5c3262f0..adbc24f3 100644 --- a/internal/dispatcher/payments/settlement_test.go +++ b/internal/dispatcher/payments/settlement_test.go @@ -5,9 +5,13 @@ package payments import ( "database/sql" + "errors" "strings" "testing" + "time" + "github.com/DATA-DOG/go-sqlmock" + "github.com/google/uuid" "github.com/netsec-ethz/debuglet/internal/dispatcher/database" "github.com/netsec-ethz/debuglet/internal/dispatcher/models" ) @@ -175,3 +179,111 @@ func TestSettleTerminalOrderRefusesAnUnsettleableState(t *testing.T) { t.Fatalf("an aborted order was settled: %d rows, state %v", n, orderState(t, db)) } } + +// seedFailedUSDCRun stores a paid USDC order whose claimed run exited with code +// 3, as the terminal path leaves it before the order is settled. +func seedFailedUSDCRun(t *testing.T, db *sql.DB) database.Debuglet { + t.Helper() + ctx := t.Context() + q := database.New(db) + if _, err := q.CreateTransaction(ctx, database.CreateTransactionParams{ + ID: testTxID, Price: testPrice, Currency: "USDC", Method: "USDC", + ExpiresAt: models.NewUTCTime(time.Now().Add(time.Hour)), Status: int64(models.Paid), Hash: testHash, + }); err != nil { + t.Fatal(err) + } + if _, err := q.CreateDebugletOrder(ctx, database.CreateDebugletOrderParams{ + TransactionID: testTxID, OrderID: testOrderID, ExecutorID: testExecutor, Price: testPrice, + Currency: "USDC", RefundAddress: testRefund, State: int64(models.Outstanding), + }); err != nil { + t.Fatal(err) + } + run, err := q.CreateDebuglet(ctx, database.CreateDebugletParams{ + Uuid: uuid.New(), StartTime: models.NewUTCTime(time.Now()), EndTime: models.NewUTCTime(time.Now()), + ExecutorID: testExecutor, State: models.RunStateExited, TransactionID: testTxID, OrderID: testOrderID, + }) + if err != nil { + t.Fatal(err) + } + if err := q.RecordMeasurementTerminal(ctx, database.RecordMeasurementTerminalParams{ + DebugletID: run.ID, ExitCode: sql.NullInt64{Int64: 3, Valid: true}, + }); err != nil { + t.Fatal(err) + } + if _, err := db.ExecContext(ctx, "UPDATE debuglet_order SET debuglet_id = ? WHERE transaction_id = ? AND order_id = ?", + run.ID, testTxID, testOrderID); err != nil { + t.Fatal(err) + } + return run +} + +// A chain refund whose outcome is uncertain is not sent again: after a failed +// inline refund the order stays Outstanding with no settlement row, and a +// later settlement pass does not select it, so the chain backend is reached +// exactly once. +func TestSettlementPassNeverResendsAChainRefund(t *testing.T) { + db := newRefundDatabase(t) + h, rec := newEnabledHandler(t, db, enabledConfig(t)) + rec.chain.refundErr = errors.New("transfer response lost") + run := seedFailedUSDCRun(t, db) + + if err := h.SettleTerminalOrder(t.Context(), &run, 3); !errors.Is(err, rec.chain.refundErr) { + t.Fatalf("SettleTerminalOrder = %v, want the chain failure", err) + } + if got := orderState(t, db); got != models.Outstanding { + t.Fatalf("order state %v after a failed chain refund, want %v", got, models.Outstanding) + } + if n, _ := settlementOf(t, db); n != 0 { + t.Fatalf("%d settlement rows after a failed chain refund", n) + } + for range 2 { + settled, failed, deferred, next, err := h.SettlePendingOrders(t.Context(), 0, 32) + if settled != 0 || failed != 0 || deferred != 0 || next != 0 || err != nil { + t.Fatalf("pass: settled %d, failed %d, deferred %d, next %d, error %v", settled, failed, deferred, next, err) + } + } + if calls := rec.chain.Calls(); len(calls) != 1 || calls[0] != "RefundDebuglet" { + t.Fatalf("chain backend calls %v, want one RefundDebuglet", calls) + } + if got := orderState(t, db); got != models.Outstanding { + t.Fatalf("order state %v after the passes, want %v", got, models.Outstanding) + } +} + +// A chain refund that was sent but whose local commit failed leaves the order +// Outstanding. A settlement pass that is handed such an order anyway defers it +// without reaching the chain backend again. +func TestSettlementPassDefersAChainRefundAfterAFailedCommit(t *testing.T) { + db, mock := newMockDB(t) + h, rec := newEnabledHandler(t, db, enabledConfig(t)) + run := database.Debuglet{ID: 9, Uuid: uuid.New(), TransactionID: testTxID, OrderID: testOrderID, ExecutorID: testExecutor, State: models.RunStateExited} + + mock.ExpectBegin() + expectOrderRead(mock, "USDC", models.Outstanding) + mock.ExpectExec(transitionDebugletOrderQuery). + WithArgs(int64(models.Refunded), testTxID, testOrderID, int64(models.Outstanding)). + WillReturnResult(sqlmock.NewResult(0, 1)) + mock.ExpectExec("INSERT INTO order_settlements"). + WithArgs(testTxID, testOrderID, "refund", testPrice, "USDC", testExecutor, nil, sqlmock.AnyArg()). + WillReturnResult(sqlmock.NewResult(0, 1)) + mock.ExpectCommit().WillReturnError(errScripted) + if err := h.SettleTerminalOrder(t.Context(), &run, 3); !errors.Is(err, errScripted) { + t.Fatalf("SettleTerminalOrder = %v, want the failed commit", err) + } + + now := time.Now().UTC() + mock.ExpectQuery("-- name: ListPendingSettlements"). + WithArgs(int64(models.Outstanding), int64(models.RunStateExited), int64(0), int64(32)). + WillReturnRows(sqlmock.NewRows([]string{"id", "uuid", "start_time", "end_time", "usage", "ceil_bw", "executor_id", + "addresses", "state", "error", "transaction_id", "order_id", "dispatcher_incarnation", "session_id", "exit_code", "currency"}). + AddRow(run.ID, run.Uuid.String(), now, now, 0, 0, testExecutor, "", int64(models.RunStateExited), nil, + testTxID, testOrderID, "", "", 3, "USDC")) + settled, failed, deferred, next, err := h.SettlePendingOrders(t.Context(), 0, 32) + if settled != 0 || failed != 0 || deferred != 1 || next != 0 || err != nil { + t.Fatalf("pass: settled %d, failed %d, deferred %d, next %d, error %v", settled, failed, deferred, next, err) + } + if calls := rec.chain.Calls(); len(calls) != 1 || calls[0] != "RefundDebuglet" { + t.Fatalf("chain backend calls %v, want one RefundDebuglet", calls) + } + assertMet(t, mock) +} diff --git a/internal/dispatcher/settlement_sweep.go b/internal/dispatcher/settlement_sweep.go index 3ba11658..f9c2dfba 100644 --- a/internal/dispatcher/settlement_sweep.go +++ b/internal/dispatcher/settlement_sweep.go @@ -21,8 +21,10 @@ const ( // order is still Outstanding, for example because the settlement after the // terminal report failed. The terminal row and its recorded exit code are the // request and settlement is idempotent per order, so an order settled by the -// terminal path meanwhile is left as it is. Each pass settles at most -// settlementSweepLimit orders. +// terminal path meanwhile is left as it is. Each pass attempts at most +// settlementSweepLimit orders, continuing after the last run the previous pass +// attempted and starting over once the listing is exhausted. Chain refunds are +// not retried here; a durable transfer record is to take them over. func (d *Dispatcher) sweepPendingSettlements(last time.Time) time.Time { now := d.now() if !last.IsZero() && now.Sub(last) < settlementSweepInterval { @@ -36,7 +38,9 @@ func (d *Dispatcher) sweepPendingSettlements(last time.Time) time.Time { } ctx, cancel := context.WithTimeout(context.Background(), settlementSweepBound) defer cancel() - if settled, failed, err := d.Payment.SettlePendingOrders(ctx, settlementSweepLimit); err != nil { + settled, failed, _, next, err := d.Payment.SettlePendingOrders(ctx, d.settlementAfter, settlementSweepLimit) + d.settlementAfter = next + if err != nil { d.logger.Warn("Pending order settlements remain", zap.Int("settled", settled), zap.Int("failed", failed)) d.logger.Debug("Private runtime diagnostic", zap.String("error", daemonlog.Diagnostic(err))) } diff --git a/internal/dispatcher/settlement_sweep_test.go b/internal/dispatcher/settlement_sweep_test.go index 9f5da7d8..79ef1042 100644 --- a/internal/dispatcher/settlement_sweep_test.go +++ b/internal/dispatcher/settlement_sweep_test.go @@ -4,6 +4,7 @@ package dispatcher import ( + "fmt" "testing" "time" @@ -73,7 +74,7 @@ func ssExitRefused(t *testing.T, f *tgFixture, exits []ssExit, prepare ...func(* tgAssertEarnings(t, f, 0) // While the settlement is still refused a pass settles nothing and // reports the failure. - if settled, failed, err := f.ph.SettlePendingOrders(f.ctx, settlementSweepLimit); settled != 0 || failed != len(exits) || err == nil { + if settled, failed, _, _, err := f.ph.SettlePendingOrders(f.ctx, 0, settlementSweepLimit); settled != 0 || failed != len(exits) || err == nil { t.Fatalf("pass while refused settled %d, failed %d, error %v", settled, failed, err) } g := reopenTG(t, f, prepare...) @@ -101,7 +102,7 @@ func TestSettlementSweepDeliversFailedInlineSettlements(t *testing.T) { t.Fatalf("%d credit and %d refund settlements, want one each", credits, refunds) } - if settled, failed, err := g.ph.SettlePendingOrders(g.ctx, settlementSweepLimit); settled != 0 || failed != 0 || err != nil { + if settled, failed, _, _, err := g.ph.SettlePendingOrders(g.ctx, 0, settlementSweepLimit); settled != 0 || failed != 0 || err != nil { t.Fatalf("second pass settled %d, failed %d, error %v", settled, failed, err) } loop.set(time.Now().Add(time.Hour)) @@ -129,7 +130,7 @@ func TestSettlementSweepSkipsRunsWithoutATerminalExitCode(t *testing.T) { t.Fatal(err) } - if settled, failed, err := f.ph.SettlePendingOrders(f.ctx, settlementSweepLimit); settled != 0 || failed != 0 || err != nil { + if settled, failed, _, _, err := f.ph.SettlePendingOrders(f.ctx, 0, settlementSweepLimit); settled != 0 || failed != 0 || err != nil { t.Fatalf("pass settled %d, failed %d, error %v", settled, failed, err) } f.d.sweepPendingSettlements(time.Time{}) @@ -147,13 +148,14 @@ func TestSettlementSweepIsBoundedByItsLimit(t *testing.T) { first, second := f.seedDirect(t, tgFloorA), f.seedDirect(t, tgFloorB) g := ssExitRefused(t, f, []ssExit{{first, 0}, {second, 0}}) - if settled, failed, err := g.ph.SettlePendingOrders(g.ctx, 1); settled != 1 || failed != 0 || err != nil { - t.Fatalf("bounded pass settled %d, failed %d, error %v", settled, failed, err) + settled, failed, _, next, err := g.ph.SettlePendingOrders(g.ctx, 0, 1) + if settled != 1 || failed != 0 || next != first.row.ID || err != nil { + t.Fatalf("bounded pass settled %d, failed %d, next %d, error %v", settled, failed, next, err) } tgAssertOrder(t, g, first, models.Credited) tgAssertOrder(t, g, second, models.Outstanding) - if settled, failed, err := g.ph.SettlePendingOrders(g.ctx, 1); settled != 1 || failed != 0 || err != nil { - t.Fatalf("next pass settled %d, failed %d, error %v", settled, failed, err) + if settled, failed, _, next, err := g.ph.SettlePendingOrders(g.ctx, next, 1); settled != 1 || failed != 0 || next != second.row.ID || err != nil { + t.Fatalf("next pass settled %d, failed %d, next %d, error %v", settled, failed, next, err) } tgAssertOrder(t, g, second, models.Credited) tgAssertEarnings(t, g, tgOrderPrice(tgFloorA)+tgOrderPrice(tgFloorB)) @@ -171,3 +173,59 @@ func TestSettlementSweepSkipsAClosedDispatcher(t *testing.T) { } tgAssertOrder(t, g, run, models.Outstanding) } + +// A failing order does not keep later ones from being settled: each pass +// continues after the last run the previous one attempted and starts over once +// the listing is exhausted, so the failing orders are attempted again. +func TestSettlementSweepContinuesPastFailingOrders(t *testing.T) { + f := newTGFixture(t, nil) + a, b, c := f.seedDirect(t, tgFloorA), f.seedDirect(t, tgFloorA), f.seedDirect(t, tgFloorA) + g := ssExitRefused(t, f, []ssExit{{a, 0}, {b, 0}, {c, 0}}) + if _, err := g.db.ExecContext(g.ctx, fmt.Sprintf(`CREATE TRIGGER ss_refuse_two BEFORE INSERT ON order_settlements +WHEN NEW.debuglet_id IN (%d, %d) BEGIN SELECT RAISE(ABORT, 'settlement refused'); END;`, a.row.ID, b.row.ID)); err != nil { + t.Fatal(err) + } + after := int64(0) + for i, want := range []struct { + settled, failed int + next int64 + }{ + {0, 2, b.row.ID}, + {1, 0, 0}, + {0, 2, b.row.ID}, + } { + settled, failed, deferred, next, err := g.ph.SettlePendingOrders(g.ctx, after, 2) + if settled != want.settled || failed != want.failed || deferred != 0 || next != want.next || (err == nil) != (failed == 0) { + t.Fatalf("pass %d after %d: settled %d, failed %d, deferred %d, next %d, error %v; want %+v", + i+1, after, settled, failed, deferred, next, err, want) + } + after = next + } + tgAssertOrder(t, g, a, models.Outstanding) + tgAssertOrder(t, g, b, models.Outstanding) + tgAssertOrder(t, g, c, models.Credited) + tgAssertEarnings(t, g, tgOrderPrice(tgFloorA)) +} + +// The maintenance sweep keeps its position between passes. +func TestSettlementSweepKeepsItsPosition(t *testing.T) { + f := newTGFixture(t, nil) + a, b := f.seedDirect(t, tgFloorA), f.seedDirect(t, tgFloorB) + g := ssExitRefused(t, f, []ssExit{{a, 0}, {b, 0}}) + if _, err := g.db.ExecContext(g.ctx, fmt.Sprintf(`CREATE TRIGGER ss_refuse_one BEFORE INSERT ON order_settlements +WHEN NEW.debuglet_id = %d BEGIN SELECT RAISE(ABORT, 'settlement refused'); END;`, a.row.ID)); err != nil { + t.Fatal(err) + } + g.d.settlementAfter = a.row.ID + g.d.sweepPendingSettlements(time.Time{}) + if g.d.settlementAfter != 0 { + t.Fatalf("an exhausted pass continues after %d, want a new start", g.d.settlementAfter) + } + tgAssertOrder(t, g, a, models.Outstanding) + tgAssertOrder(t, g, b, models.Credited) + g.d.sweepPendingSettlements(time.Time{}) + tgAssertOrder(t, g, a, models.Outstanding) + if g.d.settlementAfter != 0 { + t.Fatalf("a short pass continues after %d, want a new start", g.d.settlementAfter) + } +} From 2be11d4db1ccae13604e46779fb16724c9134904 Mon Sep 17 00:00:00 2001 From: TheodorAdrienIsaak Mattli Date: Mon, 5 Oct 2026 11:27:23 +0200 Subject: [PATCH 8/8] Bound the receipt cursor by the indexer and key receipts by event The catch-up read PaymentReceipt events through the GraphQL indexer up to the full node's checkpoint height and stored that height as the cursor. An indexer behind the node has not served the events of the checkpoints between its own mark and the tip yet, so a payment in that range was passed over for good. Ask the indexer for the last checkpoint whose events it serves (serviceConfig.availableRange) and read and store no further than that. Bound each events query above as well, so a pass reads exactly the range it claims. A streamed checkpoint ahead of a lagging indexer records its own receipts and leaves the cursor at the proven bound; the gap between them is read through the indexer once it has ingested it, and the cursor moves on only when the run of streamed checkpoints is joined to it, never backwards. A payment_receipts row was keyed by transaction digest and nonce, so a transaction carrying several receipt events for one nonce kept only the first: a valid event after a rejected one in the same transaction was treated as already recorded and did not pay. Key the row by transaction digest and event position instead (GraphQL Event.sequenceNumber, the event's index in the streamed transaction), index the nonce, and record a second valid event of an already paid intent as a mismatch naming the paying event. Migration 22 is edited in place; it has not shipped. Regressions: node at 110 with the indexer at 105 keeps the cursor at 105 and applies the payment at 108 exactly once when the indexer reaches it; a streamed checkpoint 115 at indexer 105 records its receipt, holds the cursor and completes the gap when the indexer has it; a rejected and a valid event of one transaction pay in either order, replay without effect, and a second valid event is a mismatch. Both GraphQL fields are taken from the published schema and not yet confirmed against a live service; receipts read during catch-up still record no checkpoint. GitHub issue #79. --- docs/operations/configuration.md | 5 +- .../database/migrations/00022_settlement.sql | 9 +- internal/dispatcher/database/models.go | 1 + .../database/queries/settlement.sql | 8 +- .../dispatcher/database/settlement.sql.go | 20 +- internal/dispatcher/payments/payments_test.go | 6 +- internal/dispatcher/payments/receipts.go | 14 +- internal/dispatcher/payments/receipts_test.go | 67 ++++- .../dispatcher/payments/sui/export_test.go | 24 +- internal/dispatcher/payments/sui/listener.go | 168 ++++++++---- .../dispatcher/payments/sui/listener_test.go | 248 ++++++++++++++---- internal/storagecheck/init_test.go | 4 +- internal/storagecheck/policy.go | 2 +- 13 files changed, 437 insertions(+), 139 deletions(-) diff --git a/docs/operations/configuration.md b/docs/operations/configuration.md index 00c47641..0e2c6b0d 100644 --- a/docs/operations/configuration.md +++ b/docs/operations/configuration.md @@ -127,8 +127,9 @@ and retain paid databases and backups for operator reconciliation. From dispatcher schema 22, the dispatcher database also keeps `payment_receipts`, one row per chain payment receipt addressed to the dispatcher (chain -transaction digest, nonce, amount, coin type, receiver and whether it was -applied, a duplicate, a mismatch, expired or for an unknown intent), and +transaction digest and event position, nonce, amount, coin type, receiver and +whether it was applied, a duplicate, a mismatch, expired or for an unknown +intent), and `chain_transfers`, the outbound payout and refund transfers and their states, including each signed transaction and its signature, stored before broadcast. Both are kept indefinitely for reconciliation; they stay empty while chain diff --git a/internal/dispatcher/database/migrations/00022_settlement.sql b/internal/dispatcher/database/migrations/00022_settlement.sql index d8ac11b2..c4e903f9 100644 --- a/internal/dispatcher/database/migrations/00022_settlement.sql +++ b/internal/dispatcher/database/migrations/00022_settlement.sql @@ -1,11 +1,14 @@ -- +goose up -- Every chain payment receipt addressed to this dispatcher, keyed by the chain --- transaction digest and the receipt nonce (our transaction id). The row is +-- transaction digest and the event's position among the transaction's events: +-- one transaction may emit several receipts, also with the same nonce (our +-- transaction id). The row is -- written in the same SQL transaction as the payment's effect, so a receipt -- read again after a restart is recognized instead of applied twice. The -- amount is decimal text so that a chain amount beyond INTEGER is kept exactly. CREATE TABLE payment_receipts ( tx_digest TEXT NOT NULL, + event_seq INTEGER NOT NULL CHECK (event_seq >= 0), nonce TEXT NOT NULL, disposition TEXT NOT NULL CHECK (disposition IN ('applied', 'duplicate', 'mismatch', 'unknown_intent', 'expired')), amount TEXT NOT NULL, @@ -14,8 +17,9 @@ CREATE TABLE payment_receipts ( checkpoint INTEGER, observed_at TIMESTAMP NOT NULL, detail TEXT NOT NULL DEFAULT '', - PRIMARY KEY (tx_digest, nonce) + PRIMARY KEY (tx_digest, event_seq) ); +CREATE INDEX payment_receipts_nonce_idx ON payment_receipts(nonce); -- Outbound chain transfers (executor payouts and refunds). A row is reserved -- before the chain call and records what is known about it afterwards. The @@ -44,4 +48,5 @@ CREATE INDEX chain_transfers_executor_idx ON chain_transfers(executor_id, curren -- +goose down DROP INDEX chain_transfers_executor_idx; DROP TABLE chain_transfers; +DROP INDEX payment_receipts_nonce_idx; DROP TABLE payment_receipts; diff --git a/internal/dispatcher/database/models.go b/internal/dispatcher/database/models.go index 0386eb00..216e789b 100644 --- a/internal/dispatcher/database/models.go +++ b/internal/dispatcher/database/models.go @@ -285,6 +285,7 @@ type PayloadTombstone struct { type PaymentReceipt struct { TxDigest string + EventSeq int64 Nonce string Disposition string Amount string diff --git a/internal/dispatcher/database/queries/settlement.sql b/internal/dispatcher/database/queries/settlement.sql index dc6d4ffc..f50a1b6c 100644 --- a/internal/dispatcher/database/queries/settlement.sql +++ b/internal/dispatcher/database/queries/settlement.sql @@ -1,15 +1,15 @@ -- name: InsertPaymentReceipt :exec -INSERT INTO payment_receipts (tx_digest, nonce, disposition, amount, coin_type, receiver, checkpoint, observed_at, detail) -VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?); +INSERT INTO payment_receipts (tx_digest, event_seq, nonce, disposition, amount, coin_type, receiver, checkpoint, observed_at, detail) +VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?); -- name: GetPaymentReceipt :one SELECT * FROM payment_receipts -WHERE tx_digest = ? AND nonce = ?; +WHERE tx_digest = ? AND event_seq = ?; -- name: ListPaymentReceiptsByNonce :many SELECT * FROM payment_receipts WHERE nonce = ? -ORDER BY observed_at, tx_digest; +ORDER BY observed_at, tx_digest, event_seq; -- name: MarkTransactionPaid :execrows UPDATE transactions diff --git a/internal/dispatcher/database/settlement.sql.go b/internal/dispatcher/database/settlement.sql.go index 14282ab8..9b101752 100644 --- a/internal/dispatcher/database/settlement.sql.go +++ b/internal/dispatcher/database/settlement.sql.go @@ -13,20 +13,21 @@ import ( ) const getPaymentReceipt = `-- name: GetPaymentReceipt :one -SELECT tx_digest, nonce, disposition, amount, coin_type, receiver, checkpoint, observed_at, detail FROM payment_receipts -WHERE tx_digest = ? AND nonce = ? +SELECT tx_digest, event_seq, nonce, disposition, amount, coin_type, receiver, checkpoint, observed_at, detail FROM payment_receipts +WHERE tx_digest = ? AND event_seq = ? ` type GetPaymentReceiptParams struct { TxDigest string - Nonce string + EventSeq int64 } func (q *Queries) GetPaymentReceipt(ctx context.Context, arg GetPaymentReceiptParams) (PaymentReceipt, error) { - row := q.db.QueryRowContext(ctx, getPaymentReceipt, arg.TxDigest, arg.Nonce) + row := q.db.QueryRowContext(ctx, getPaymentReceipt, arg.TxDigest, arg.EventSeq) var i PaymentReceipt err := row.Scan( &i.TxDigest, + &i.EventSeq, &i.Nonce, &i.Disposition, &i.Amount, @@ -40,12 +41,13 @@ func (q *Queries) GetPaymentReceipt(ctx context.Context, arg GetPaymentReceiptPa } const insertPaymentReceipt = `-- name: InsertPaymentReceipt :exec -INSERT INTO payment_receipts (tx_digest, nonce, disposition, amount, coin_type, receiver, checkpoint, observed_at, detail) -VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?) +INSERT INTO payment_receipts (tx_digest, event_seq, nonce, disposition, amount, coin_type, receiver, checkpoint, observed_at, detail) +VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) ` type InsertPaymentReceiptParams struct { TxDigest string + EventSeq int64 Nonce string Disposition string Amount string @@ -59,6 +61,7 @@ type InsertPaymentReceiptParams struct { func (q *Queries) InsertPaymentReceipt(ctx context.Context, arg InsertPaymentReceiptParams) error { _, err := q.db.ExecContext(ctx, insertPaymentReceipt, arg.TxDigest, + arg.EventSeq, arg.Nonce, arg.Disposition, arg.Amount, @@ -72,9 +75,9 @@ func (q *Queries) InsertPaymentReceipt(ctx context.Context, arg InsertPaymentRec } const listPaymentReceiptsByNonce = `-- name: ListPaymentReceiptsByNonce :many -SELECT tx_digest, nonce, disposition, amount, coin_type, receiver, checkpoint, observed_at, detail FROM payment_receipts +SELECT tx_digest, event_seq, nonce, disposition, amount, coin_type, receiver, checkpoint, observed_at, detail FROM payment_receipts WHERE nonce = ? -ORDER BY observed_at, tx_digest +ORDER BY observed_at, tx_digest, event_seq ` func (q *Queries) ListPaymentReceiptsByNonce(ctx context.Context, nonce string) ([]PaymentReceipt, error) { @@ -88,6 +91,7 @@ func (q *Queries) ListPaymentReceiptsByNonce(ctx context.Context, nonce string) var i PaymentReceipt if err := rows.Scan( &i.TxDigest, + &i.EventSeq, &i.Nonce, &i.Disposition, &i.Amount, diff --git a/internal/dispatcher/payments/payments_test.go b/internal/dispatcher/payments/payments_test.go index e9450628..0d967529 100644 --- a/internal/dispatcher/payments/payments_test.go +++ b/internal/dispatcher/payments/payments_test.go @@ -981,7 +981,7 @@ func TestEnabledChainMethodsForwardToBackend(t *testing.T) { // ---- ApplyPaymentReceipt (the chain listener's TransactionFulfiller) ---- var ( - getPaymentReceiptQuery = regexp.QuoteMeta("FROM payment_receipts\nWHERE tx_digest = ? AND nonce = ?") + getPaymentReceiptQuery = regexp.QuoteMeta("FROM payment_receipts\nWHERE tx_digest = ? AND event_seq = ?") markTransactionPaidQuery = regexp.QuoteMeta("UPDATE transactions\nSET status = ?1\nWHERE id = ?2 AND status = ?3") ) @@ -995,7 +995,7 @@ func TestApplyPaymentReceiptModes(t *testing.T) { } expectBeginAndReceiptMiss := func(mock sqlmock.Sqlmock) { mock.ExpectBegin() - mock.ExpectQuery(getPaymentReceiptQuery).WithArgs(receipt.Digest, testTxID).WillReturnError(sql.ErrNoRows) + mock.ExpectQuery(getPaymentReceiptQuery).WithArgs(receipt.Digest, int64(0)).WillReturnError(sql.ErrNoRows) } cases := []struct { name string @@ -1008,7 +1008,7 @@ func TestApplyPaymentReceiptModes(t *testing.T) { name: "enabled receipt lookup error: rolled back", expect: func(mock sqlmock.Sqlmock) { mock.ExpectBegin() - mock.ExpectQuery(getPaymentReceiptQuery).WithArgs(receipt.Digest, testTxID).WillReturnError(errScripted) + mock.ExpectQuery(getPaymentReceiptQuery).WithArgs(receipt.Digest, int64(0)).WillReturnError(errScripted) mock.ExpectRollback() }, want: errScripted, diff --git a/internal/dispatcher/payments/receipts.go b/internal/dispatcher/payments/receipts.go index b268907b..1ff68f27 100644 --- a/internal/dispatcher/payments/receipts.go +++ b/internal/dispatcher/payments/receipts.go @@ -22,7 +22,8 @@ import ( // In one SQL transaction it validates a chain payment receipt against the // transaction its nonce names, marks an outstanding transaction paid when the // receipt pays it exactly, and records the receipt with its disposition. A -// receipt that was recorded before is not applied again: an applied one is +// receipt is one event, identified by its transaction digest and position; one +// transaction may carry several. A receipt that was recorded before is not applied again: an applied one is // reported as duplicate, any other with its recorded disposition. A receipt // to another address whose nonce names no local transaction is not ours and // is not recorded (empty disposition). A database error is returned with @@ -39,7 +40,11 @@ func (p *PaymentHandler) ApplyPaymentReceipt(ctx context.Context, r sui.PaymentR defer tx.Rollback() queries := database.New(tx) - stored, err := queries.GetPaymentReceipt(ctx, database.GetPaymentReceiptParams{TxDigest: r.Digest, Nonce: r.Nonce}) + if r.EventSeq > math.MaxInt64 { + return "", fmt.Errorf("payment receipt %s: event position %d out of range", r.Digest, r.EventSeq) + } + eventSeq := int64(r.EventSeq) + stored, err := queries.GetPaymentReceipt(ctx, database.GetPaymentReceiptParams{TxDigest: r.Digest, EventSeq: eventSeq}) if err == nil { if disposition := sui.ReceiptDisposition(stored.Disposition); disposition != sui.ReceiptApplied { return disposition, nil @@ -60,6 +65,7 @@ func (p *PaymentHandler) ApplyPaymentReceipt(ctx context.Context, r sui.PaymentR } if err := queries.InsertPaymentReceipt(ctx, database.InsertPaymentReceiptParams{ TxDigest: r.Digest, + EventSeq: eventSeq, Nonce: r.Nonce, Disposition: string(disposition), Amount: strconv.FormatUint(r.Amount, 10), @@ -115,14 +121,14 @@ func (p *PaymentHandler) settleReceipt(ctx context.Context, queries *database.Qu return sui.ReceiptApplied, "", nil } // The same receipt was answered above from its own row, so an applied - // receipt for this nonce is a second payment by another chain transaction. + // receipt for this nonce is a second payment by another event. recorded, err := queries.ListPaymentReceiptsByNonce(ctx, r.Nonce) if err != nil { return "", "", fmt.Errorf("read payment receipts: %w", err) } for _, other := range recorded { if other.Disposition == string(sui.ReceiptApplied) { - return sui.ReceiptMismatch, "already paid by " + other.TxDigest, nil + return sui.ReceiptMismatch, fmt.Sprintf("already paid by %s event %d", other.TxDigest, other.EventSeq), nil } } return sui.ReceiptMismatch, "transaction not outstanding", nil diff --git a/internal/dispatcher/payments/receipts_test.go b/internal/dispatcher/payments/receipts_test.go index b0c243e5..be7a5cca 100644 --- a/internal/dispatcher/payments/receipts_test.go +++ b/internal/dispatcher/payments/receipts_test.go @@ -63,11 +63,11 @@ func transactionStatus(t *testing.T, db *sql.DB) models.TransactionState { return models.TransactionState(transaction.Status) } -func storedReceipt(t *testing.T, db *sql.DB, digest, nonce string) database.PaymentReceipt { +func storedReceipt(t *testing.T, db *sql.DB, digest string, eventSeq int64) database.PaymentReceipt { t.Helper() - row, err := database.New(db).GetPaymentReceipt(t.Context(), database.GetPaymentReceiptParams{TxDigest: digest, Nonce: nonce}) + row, err := database.New(db).GetPaymentReceipt(t.Context(), database.GetPaymentReceiptParams{TxDigest: digest, EventSeq: eventSeq}) if err != nil { - t.Fatalf("receipt %s/%s: %v", digest, nonce, err) + t.Fatalf("receipt %s event %d: %v", digest, eventSeq, err) } return row } @@ -81,7 +81,7 @@ func TestApplyPaymentReceiptPaysOnce(t *testing.T) { if transactionStatus(t, db) != models.Paid { t.Fatal("applied receipt left the transaction unpaid") } - row := storedReceipt(t, db, "d1", testTxID) + row := storedReceipt(t, db, "d1", 0) if row.Disposition != "applied" || row.Amount != "7" || row.Checkpoint != (sql.NullInt64{Int64: 12, Valid: true}) || row.ObservedAt.IsZero() { t.Fatalf("applied row %+v", row) } @@ -93,7 +93,7 @@ func TestApplyPaymentReceiptPaysOnce(t *testing.T) { if got := applyReceipt(t, h, validReceipt("d2")); got != sui.ReceiptMismatch { t.Fatalf("second payment %q", got) } - if row := storedReceipt(t, db, "d2", testTxID); row.Disposition != "mismatch" || row.Detail != "already paid by d1" { + if row := storedReceipt(t, db, "d2", 0); row.Disposition != "mismatch" || row.Detail != "already paid by d1 event 0" { t.Fatalf("second payment row %+v", row) } // A recorded mismatch keeps its disposition when seen again. @@ -137,7 +137,7 @@ func TestApplyPaymentReceiptRecordsRejections(t *testing.T) { if transactionStatus(t, db) != tc.status { t.Fatal("rejected receipt changed the transaction") } - row := storedReceipt(t, db, "d1", testTxID) + row := storedReceipt(t, db, "d1", 0) if row.Disposition != string(tc.disposition) || row.Detail != tc.detail || row.Amount != tc.amount { t.Fatalf("row %+v", row) } @@ -152,14 +152,14 @@ func TestApplyPaymentReceiptUnknownNonce(t *testing.T) { if got := applyReceipt(t, h, r); got != sui.ReceiptUnknownIntent { t.Fatalf("unknown nonce to our address %q", got) } - storedReceipt(t, db, "d1", "unknown") + storedReceipt(t, db, "d1", 0) // Another payee's receipt is not ours and is not recorded. r.Digest, r.Receiver = "d2", "0xbeef" if got := applyReceipt(t, h, r); got != "" { t.Fatalf("receipt to another address %q", got) } - if _, err := database.New(db).GetPaymentReceipt(t.Context(), database.GetPaymentReceiptParams{TxDigest: "d2", Nonce: "unknown"}); !errors.Is(err, sql.ErrNoRows) { + if _, err := database.New(db).GetPaymentReceipt(t.Context(), database.GetPaymentReceiptParams{TxDigest: "d2", EventSeq: 0}); !errors.Is(err, sql.ErrNoRows) { t.Fatalf("foreign receipt recorded: %v", err) } } @@ -176,3 +176,54 @@ func TestApplyPaymentReceiptDisabled(t *testing.T) { t.Fatalf("disabled mode recorded %d receipts: %v", n, err) } } + +// One chain transaction may carry several receipt events, also for the same +// nonce. Each event is its own receipt: a rejected one does not hide a valid +// one, the order does not matter, and the intent is paid once. +func TestApplyPaymentReceiptEventsOfOneTransaction(t *testing.T) { + wrong := validReceipt("d1") + wrong.Amount++ + valid := validReceipt("d1") + valid.EventSeq = 1 + second := validReceipt("d1") + second.EventSeq = 2 + + for name, order := range map[string][]sui.PaymentReceipt{ + "rejected first": {wrong, valid}, + "rejected last": {valid, wrong}, + } { + t.Run(name, func(t *testing.T) { + db, h := receiptFixture(t, "USDC", models.Outstanding) + want := map[uint64]sui.ReceiptDisposition{0: sui.ReceiptMismatch, 1: sui.ReceiptApplied} + for _, r := range order { + if got := applyReceipt(t, h, r); got != want[r.EventSeq] { + t.Fatalf("event %d: %q, want %q", r.EventSeq, got, want[r.EventSeq]) + } + } + if transactionStatus(t, db) != models.Paid { + t.Fatal("valid event did not pay the intent") + } + if row := storedReceipt(t, db, "d1", 0); row.Detail != "amount" { + t.Fatalf("rejected event row %+v", row) + } + // Replayed after a restart: recorded dispositions, no second effect. + want[1] = sui.ReceiptDuplicate + for _, r := range order { + if got := applyReceipt(t, h, r); got != want[r.EventSeq] { + t.Fatalf("replayed event %d: %q, want %q", r.EventSeq, got, want[r.EventSeq]) + } + } + // A second valid payment in the same transaction pays nothing. + if got := applyReceipt(t, h, second); got != sui.ReceiptMismatch { + t.Fatalf("second valid event %q", got) + } + if row := storedReceipt(t, db, "d1", 2); row.Detail != "already paid by d1 event 1" { + t.Fatalf("second valid event row %+v", row) + } + rows, err := database.New(db).ListPaymentReceiptsByNonce(t.Context(), testTxID) + if err != nil || len(rows) != 3 { + t.Fatalf("receipt rows %+v, %v", rows, err) + } + }) + } +} diff --git a/internal/dispatcher/payments/sui/export_test.go b/internal/dispatcher/payments/sui/export_test.go index b37bcec0..f40b8f8c 100644 --- a/internal/dispatcher/payments/sui/export_test.go +++ b/internal/dispatcher/payments/sui/export_test.go @@ -20,13 +20,23 @@ func (l *Listener) CatchUpTo(ctx context.Context, cursor *uint64, tip uint64) (* return l.catchUpTo(ctx, cursor, tip) } -// ProcessCheckpoint handles one streamed checkpoint. -func (l *Listener) ProcessCheckpoint(ctx context.Context, cp *v2.Checkpoint) error { - return l.processCheckpoint(ctx, cp) +// Stream is one subscription's handling of streamed checkpoints. +type Stream struct { + l *Listener + st streamState } -// StreamCheckpoint handles one streamed checkpoint after cursor, as the -// stream loop does. -func (l *Listener) StreamCheckpoint(ctx context.Context, cursor *uint64, cp *v2.Checkpoint) (uint64, error) { - return l.streamCheckpoint(ctx, cursor, cp) +// NewStream starts a subscription after the stored cursor. +func (l *Listener) NewStream(cursor *uint64) *Stream { + return &Stream{l: l, st: streamState{cursor: cursor}} +} + +// Checkpoint handles one streamed checkpoint, as the stream loop does. +func (s *Stream) Checkpoint(ctx context.Context, cp *v2.Checkpoint) error { + return s.l.streamCheckpoint(ctx, &s.st, cp) +} + +// Cursor is the cursor the stream loop holds. +func (s *Stream) Cursor() *uint64 { + return s.st.cursor } diff --git a/internal/dispatcher/payments/sui/listener.go b/internal/dispatcher/payments/sui/listener.go index baed7a63..45f5de34 100644 --- a/internal/dispatcher/payments/sui/listener.go +++ b/internal/dispatcher/payments/sui/listener.go @@ -56,6 +56,7 @@ const ( // PaymentReceipt is a decoded payment kit receipt event. type PaymentReceipt struct { Digest string // chain transaction digest + EventSeq uint64 // position of the event among the transaction's events Nonce string // our transaction id Amount uint64 // base units of CoinType CoinType string @@ -183,32 +184,40 @@ func (l *Listener) catchUp(ctx context.Context, cursor *uint64) (*uint64, error) return l.catchUpTo(ctx, cursor, info.GetCheckpointHeight()) } -// catchUpTo brings the stored cursor to tip. Without a stored cursor it -// stores tip, so a restart keeps the same starting point. +// catchUpTo brings the stored cursor towards the full node's tip, but only +// as far as the GraphQL indexer has proven to have ingested: events of later +// checkpoints may not be visible there yet. Without a stored cursor it stores +// that bound, so a restart keeps the same starting point. func (l *Listener) catchUpTo(ctx context.Context, cursor *uint64, tip uint64) (*uint64, error) { + indexed, err := l.indexedCheckpoint(ctx) + if err != nil { + return cursor, err + } + bound := min(tip, indexed) if cursor == nil { - if err := l.storeCursor(ctx, tip); err != nil { + if err := l.storeCursor(ctx, bound); err != nil { return nil, err } - l.logger.Info("no stored sui cursor, starting at chain tip", zap.Uint64("checkpoint", tip)) - return &tip, nil + l.logger.Info("no stored sui cursor, starting at chain tip", zap.Uint64("checkpoint", bound)) + return &bound, nil } - if *cursor >= tip { + if *cursor >= bound { return cursor, nil } - if err := l.catchUpRange(ctx, *cursor, tip); err != nil { + if err := l.catchUpRange(ctx, *cursor, bound); err != nil { return cursor, err } - return &tip, nil + return &bound, nil } -// catchUpRange records every receipt event after checkpoint after and then -// stores tip as the cursor. It returns on the first event that could not be -// recorded, leaving the stored cursor where it was. -func (l *Listener) catchUpRange(ctx context.Context, after, tip uint64) error { +// catchUpRange records every receipt event of the checkpoints (after, to] and +// then stores to as the cursor. The caller has established that the indexer +// covers to. It returns on the first event that could not be recorded, +// leaving the stored cursor where it was. +func (l *Listener) catchUpRange(ctx context.Context, after, to uint64) error { l.logger.Info("sui catch-up: querying PaymentReceipt events via GraphQL", - zap.Uint64("after_checkpoint", after), zap.Uint64("to", tip)) + zap.Uint64("after_checkpoint", after), zap.Uint64("to", to)) var ( pageCursor *string @@ -219,7 +228,7 @@ func (l *Listener) catchUpRange(ctx context.Context, after, tip uint64) error { return ctx.Err() } - page, err := l.queryPaymentReceiptEvents(ctx, after, pageCursor) + page, err := l.queryPaymentReceiptEvents(ctx, after, to+1, pageCursor) if err != nil { return fmt.Errorf("query payment receipt events: %w", err) } @@ -230,7 +239,7 @@ func (l *Listener) catchUpRange(ctx context.Context, after, tip uint64) error { return fmt.Errorf("payment receipt in transaction %s: decode base64: %w", node.Transaction.Digest, err) } // The GraphQL query does not report the event's checkpoint. - if _, err := l.processPaymentReceipt(ctx, contents, node.Transaction.Digest, 0); err != nil { + if _, err := l.processPaymentReceipt(ctx, contents, node.Transaction.Digest, node.SequenceNumber, 0); err != nil { return err } numEvents++ @@ -243,19 +252,51 @@ func (l *Listener) catchUpRange(ctx context.Context, after, tip uint64) error { pageCursor = &endCursor } - if err := l.storeCursor(ctx, tip); err != nil { + if err := l.storeCursor(ctx, to); err != nil { return err } - l.logger.Info("sui catch-up: done", zap.Int("events_processed", numEvents), zap.Uint64("checkpoint", tip)) + l.logger.Info("sui catch-up: done", zap.Int("events_processed", numEvents), zap.Uint64("checkpoint", to)) return nil } +// indexedCheckpointQuery asks for the last checkpoint whose events the +// indexer serves. +const indexedCheckpointQuery = ` +query IndexedCheckpoint { + serviceConfig { + availableRange(type: "Query", field: "events") { last { sequenceNumber } } + } +}` + +// indexedCheckpoint returns the last checkpoint the GraphQL indexer has +// ingested events for. +func (l *Listener) indexedCheckpoint(ctx context.Context) (uint64, error) { + var resp struct { + ServiceConfig struct { + AvailableRange struct { + Last *struct { + SequenceNumber uint64 `json:"sequenceNumber"` + } `json:"last"` + } `json:"availableRange"` + } `json:"serviceConfig"` + } + if err := l.graphQLQuery(ctx, indexedCheckpointQuery, nil, &resp); err != nil { + return 0, fmt.Errorf("query indexed checkpoint: %w", err) + } + last := resp.ServiceConfig.AvailableRange.Last + if last == nil { + return 0, errors.New("query indexed checkpoint: no checkpoint reported") + } + return last.SequenceNumber, nil +} + const paymentReceiptEventsQuery = ` -query PaymentReceiptEvents($type: String!, $afterCheckpoint: UInt53, $first: Int!, $after: String) { - events(first: $first, after: $after, filter: { type: $type, afterCheckpoint: $afterCheckpoint }) { +query PaymentReceiptEvents($type: String!, $afterCheckpoint: UInt53, $beforeCheckpoint: UInt53, $first: Int!, $after: String) { + events(first: $first, after: $after, filter: { type: $type, afterCheckpoint: $afterCheckpoint, beforeCheckpoint: $beforeCheckpoint }) { pageInfo { hasNextPage endCursor } nodes { transaction { digest } + sequenceNumber contents { bcs } } } @@ -265,7 +306,8 @@ type paymentReceiptEventNode struct { Transaction struct { Digest string `json:"digest"` } `json:"transaction"` - Contents struct { + SequenceNumber uint64 `json:"sequenceNumber"` + Contents struct { Bcs string `json:"bcs"` } `json:"contents"` } @@ -280,13 +322,14 @@ type paymentReceiptEventsResponse struct { } `json:"events"` } -func (l *Listener) queryPaymentReceiptEvents(ctx context.Context, afterCheckpoint uint64, after *string) (*paymentReceiptEventsResponse, error) { +func (l *Listener) queryPaymentReceiptEvents(ctx context.Context, afterCheckpoint, beforeCheckpoint uint64, after *string) (*paymentReceiptEventsResponse, error) { var resp paymentReceiptEventsResponse err := l.graphQLQuery(ctx, paymentReceiptEventsQuery, map[string]any{ - "type": l.eventType, - "afterCheckpoint": afterCheckpoint, - "first": catchUpPageSize, - "after": after, + "type": l.eventType, + "afterCheckpoint": afterCheckpoint, + "beforeCheckpoint": beforeCheckpoint, + "first": catchUpPageSize, + "after": after, }, &resp) return &resp, err } @@ -349,6 +392,7 @@ func (l *Listener) subscribeGRPC(ctx context.Context, cursor **uint64) error { return fmt.Errorf("SubscribeCheckpoints failed to start: %v", err) } + state := streamState{cursor: *cursor} for { resp, err := stream.Recv() if err != nil { @@ -358,51 +402,80 @@ func (l *Listener) subscribeGRPC(ctx context.Context, cursor **uint64) error { return fmt.Errorf("recv checkpoint: %w", err) } - seq, err := l.streamCheckpoint(ctx, *cursor, resp.GetCheckpoint()) - if err != nil { + if err := l.streamCheckpoint(ctx, &state, resp.GetCheckpoint()); err != nil { return err } - *cursor = &seq + *cursor = state.cursor } } -// streamCheckpoint handles one streamed checkpoint after the stored cursor. -// The stream starts at the live checkpoint, so checkpoints between the cursor -// and it are caught up first; the cursor never passes an unread checkpoint. -func (l *Listener) streamCheckpoint(ctx context.Context, cursor *uint64, cp *v2.Checkpoint) (uint64, error) { +// streamState is what one subscription has covered: the stored cursor and +// the run of consecutive streamed checkpoints whose receipts are recorded. +type streamState struct { + cursor *uint64 + runStart uint64 + last uint64 + running bool +} + +// streamCheckpoint records the receipts of one streamed checkpoint and +// advances the stored cursor only over checkpoints that are recorded: the +// stream starts at the live checkpoint, so the checkpoints between the cursor +// and the start of the streamed run are caught up through the indexer first, +// as far as it has ingested them. Until it covers them all, the cursor stays +// at the proven bound and the streamed receipts are recorded without moving +// it; reading them again later finds them recorded. +func (l *Listener) streamCheckpoint(ctx context.Context, st *streamState, cp *v2.Checkpoint) error { seq := cp.GetSequenceNumber() - if cursor != nil && seq > *cursor+1 { - if err := l.catchUpRange(ctx, *cursor, seq-1); err != nil { - return 0, err + if !st.running || seq != st.last+1 { + st.runStart, st.running = seq, true + } + st.last = seq + if st.cursor != nil && *st.cursor+1 < st.runStart { + indexed, err := l.indexedCheckpoint(ctx) + if err != nil { + return err + } + if bound := min(indexed, st.runStart-1); bound > *st.cursor { + if err := l.catchUpRange(ctx, *st.cursor, bound); err != nil { + return err + } + st.cursor = &bound } } - if err := l.processCheckpoint(ctx, cp); err != nil { - return 0, err + if err := l.recordCheckpoint(ctx, cp); err != nil { + return err } - return seq, nil + if st.cursor != nil && (*st.cursor+1 < st.runStart || *st.cursor >= seq) { + return nil + } + if err := l.storeCursor(ctx, seq); err != nil { + return err + } + st.cursor = &seq + return nil } -// processCheckpoint records every receipt event of one streamed checkpoint -// and then stores its sequence number as the cursor. -func (l *Listener) processCheckpoint(ctx context.Context, cp *v2.Checkpoint) error { +// recordCheckpoint records every receipt event of one streamed checkpoint. +func (l *Listener) recordCheckpoint(ctx context.Context, cp *v2.Checkpoint) error { seq := cp.GetSequenceNumber() for _, tx := range cp.GetTransactions() { - for _, ev := range tx.GetEvents().GetEvents() { + for i, ev := range tx.GetEvents().GetEvents() { if ev.GetEventType() != l.eventType { continue } - if _, err := l.processPaymentReceipt(ctx, ev.GetContents().GetValue(), tx.GetDigest(), seq); err != nil { + if _, err := l.processPaymentReceipt(ctx, ev.GetContents().GetValue(), tx.GetDigest(), uint64(i), seq); err != nil { return err } } } - return l.storeCursor(ctx, seq) + return nil } // processPaymentReceipt decodes one receipt event and records it. An event // that cannot be decoded is an error, like a failed write: skipping it would // lose the payment once the cursor moves past it. -func (l *Listener) processPaymentReceipt(ctx context.Context, contents []byte, txDigest string, checkpoint uint64) (ReceiptDisposition, error) { +func (l *Listener) processPaymentReceipt(ctx context.Context, contents []byte, txDigest string, eventSeq, checkpoint uint64) (ReceiptDisposition, error) { if txDigest == "" { return "", errors.New("payment receipt event without transaction digest") } @@ -412,6 +485,7 @@ func (l *Listener) processPaymentReceipt(ctx context.Context, contents []byte, t } receipt := PaymentReceipt{ Digest: txDigest, + EventSeq: eventSeq, Nonce: ev.Nonce, Amount: ev.PaymentAmount, CoinType: ev.CoinType, @@ -421,11 +495,11 @@ func (l *Listener) processPaymentReceipt(ctx context.Context, contents []byte, t } disposition, err := l.fulfiller.ApplyPaymentReceipt(ctx, receipt) if err != nil { - return "", fmt.Errorf("record payment receipt %s/%s: %w", txDigest, ev.Nonce, err) + return "", fmt.Errorf("record payment receipt %s event %d: %w", txDigest, eventSeq, err) } if disposition != "" { l.logger.Info("payment receipt recorded", - zap.String("tx", txDigest), zap.String("nonce", ev.Nonce), zap.String("disposition", string(disposition))) + zap.String("tx", txDigest), zap.Uint64("event", eventSeq), zap.String("nonce", ev.Nonce), zap.String("disposition", string(disposition))) } return disposition, nil } diff --git a/internal/dispatcher/payments/sui/listener_test.go b/internal/dispatcher/payments/sui/listener_test.go index 50a2bb6f..75ca5225 100644 --- a/internal/dispatcher/payments/sui/listener_test.go +++ b/internal/dispatcher/payments/sui/listener_test.go @@ -14,6 +14,7 @@ import ( "net/http" "net/http/httptest" "path/filepath" + "strconv" "strings" "sync" "testing" @@ -102,10 +103,13 @@ func encode(t *testing.T, ev receiptEvent) []byte { return b } -// event is one GraphQL event node. +// event is one GraphQL event node. A zero checkpoint passes every +// checkpoint filter. type event struct { - digest string - bcs []byte + digest string + seq uint64 + checkpoint uint64 + bcs []byte } func node(t *testing.T, digest string, ev receiptEvent) event { @@ -113,11 +117,33 @@ func node(t *testing.T, digest string, ev receiptEvent) event { return event{digest: digest, bcs: encode(t, ev)} } -// graphQL serves PaymentReceipt events in pages, linked by endCursor. +// graphQL serves PaymentReceipt events in pages, linked by endCursor, and +// the indexer's last ingested checkpoint. Events of later checkpoints are not +// served, like an indexer that has not ingested them yet. type graphQL struct { - mu sync.Mutex - pages [][]event - queries []map[string]any + mu sync.Mutex + pages [][]event + indexed uint64 + queries []map[string]any // events queries + watermarks int // indexed checkpoint queries +} + +func (g *graphQL) setIndexed(cp uint64) { + g.mu.Lock() + defer g.mu.Unlock() + g.indexed = cp +} + +func (g *graphQL) indexerQueries() int { + g.mu.Lock() + defer g.mu.Unlock() + return g.watermarks +} + +func (g *graphQL) eventQueries() []map[string]any { + g.mu.Lock() + defer g.mu.Unlock() + return append([]map[string]any(nil), g.queries...) } func (g *graphQL) setPages(pages ...[]event) { @@ -128,6 +154,7 @@ func (g *graphQL) setPages(pages ...[]event) { func (g *graphQL) ServeHTTP(w http.ResponseWriter, r *http.Request) { var req struct { + Query string `json:"query"` Variables map[string]any `json:"variables"` } if err := json.NewDecoder(r.Body).Decode(&req); err != nil { @@ -136,7 +163,23 @@ func (g *graphQL) ServeHTTP(w http.ResponseWriter, r *http.Request) { } g.mu.Lock() defer g.mu.Unlock() + if strings.Contains(req.Query, "serviceConfig") { + g.watermarks++ + _ = json.NewEncoder(w).Encode(map[string]any{"data": map[string]any{"serviceConfig": map[string]any{ + "availableRange": map[string]any{"last": map[string]any{"sequenceNumber": g.indexed}}, + }}}) + return + } g.queries = append(g.queries, req.Variables) + visible := func(ev event) bool { + if ev.checkpoint == 0 { + return true + } + after, hasAfter := req.Variables["afterCheckpoint"].(float64) + before, hasBefore := req.Variables["beforeCheckpoint"].(float64) + return ev.checkpoint <= g.indexed && (!hasAfter || float64(ev.checkpoint) > after) && + (!hasBefore || float64(ev.checkpoint) < before) + } index := 0 if after, ok := req.Variables["after"].(string); ok { fmt.Sscanf(after, "page-%d", &index) @@ -145,15 +188,20 @@ func (g *graphQL) ServeHTTP(w http.ResponseWriter, r *http.Request) { Transaction struct { Digest string `json:"digest"` } `json:"transaction"` - Contents struct { + SequenceNumber uint64 `json:"sequenceNumber"` + Contents struct { Bcs string `json:"bcs"` } `json:"contents"` } nodes := []nodeJSON{} if index < len(g.pages) { for _, ev := range g.pages[index] { + if !visible(ev) { + continue + } var n nodeJSON n.Transaction.Digest = ev.digest + n.SequenceNumber = ev.seq n.Contents.Bcs = base64.StdEncoding.EncodeToString(ev.bcs) nodes = append(nodes, n) } @@ -187,7 +235,7 @@ func newFixture(t *testing.T) *fixture { if _, err := sqlitedb.Migrate(t.Context(), db, database.MigrationFS(), sqlitedb.Latest); err != nil { t.Fatalf("migrate: %v", err) } - server := &graphQL{} + server := &graphQL{indexed: math.MaxInt32} httpServer := httptest.NewServer(server) t.Cleanup(httpServer.Close) cfg := &config.DispatcherConfig{Sui: config.SuiConfig{ @@ -298,12 +346,9 @@ func TestCatchUpAppliesEachReceiptOnce(t *testing.T) { if f.status(t, "tx-a") != models.Paid || f.status(t, "tx-b") != models.Paid || f.cursor(t) != "20" { t.Fatalf("after first pass: a=%v b=%v cursor=%s", f.status(t, "tx-a"), f.status(t, "tx-b"), f.cursor(t)) } - want := []string{"d1/tx-a=applied::7", "d2/tx-b=applied::7", "d3/tx-a=mismatch:already paid by d1:7"} + want := []string{"d1/tx-a=applied::7", "d2/tx-b=applied::7", "d3/tx-a=mismatch:already paid by d1 event 0:7"} equal(t, "rows", f.receipts(t), want) - f.server.mu.Lock() - after := f.server.queries[0]["afterCheckpoint"] - f.server.mu.Unlock() - if after != float64(10) { + if after := f.server.eventQueries()[0]["afterCheckpoint"]; after != float64(10) { t.Fatalf("queried after checkpoint %v", after) } @@ -429,27 +474,29 @@ func checkpoint(t *testing.T, seq uint64, digest string, nonce string) *v2.Check } } -func TestProcessCheckpoint(t *testing.T) { +func TestStreamRecordsCheckpoint(t *testing.T) { f := newFixture(t) f.transaction(t, "tx-a", time.Now().Add(time.Hour)) f.transaction(t, "tx-b", time.Now().Add(time.Hour)) f.setCursor(t, "41") - if err := f.listener().ProcessCheckpoint(t.Context(), checkpoint(t, 42, "d1", "tx-a")); err != nil { + cursor := uint64(41) + stream := f.listener().NewStream(&cursor) + if err := stream.Checkpoint(t.Context(), checkpoint(t, 42, "d1", "tx-a")); err != nil { t.Fatal(err) } - row, err := database.New(f.db).GetPaymentReceipt(t.Context(), database.GetPaymentReceiptParams{TxDigest: "d1", Nonce: "tx-a"}) + row, err := database.New(f.db).GetPaymentReceipt(t.Context(), database.GetPaymentReceiptParams{TxDigest: "d1", EventSeq: 1}) if err != nil || row.Disposition != "applied" || row.Checkpoint != (sql.NullInt64{Int64: 42, Valid: true}) { t.Fatalf("streamed receipt %+v, %v", row, err) } - if f.cursor(t) != "42" || f.status(t, "tx-a") != models.Paid { - t.Fatalf("cursor %s, tx-a %v", f.cursor(t), f.status(t, "tx-a")) + if f.cursor(t) != "42" || f.status(t, "tx-a") != models.Paid || f.server.indexerQueries() != 0 { + t.Fatalf("cursor %s, tx-a %v, indexer queries %d", f.cursor(t), f.status(t, "tx-a"), f.server.indexerQueries()) } if _, err := f.db.Exec(`CREATE TRIGGER fail_receipt BEFORE INSERT ON payment_receipts BEGIN SELECT RAISE(ABORT, 'scripted receipt failure'); END`); err != nil { t.Fatal(err) } - if err := f.listener().ProcessCheckpoint(t.Context(), checkpoint(t, 43, "d2", "tx-b")); err == nil { + if err := stream.Checkpoint(t.Context(), checkpoint(t, 43, "d2", "tx-b")); err == nil { t.Fatal("checkpoint with a failing write succeeded") } if f.cursor(t) != "42" || f.status(t, "tx-b") != models.Outstanding { @@ -478,36 +525,28 @@ func TestStreamCatchesUpGapBeforeCheckpoint(t *testing.T) { f.transaction(t, "tx-gap", time.Now().Add(time.Hour)) f.transaction(t, "tx-live", time.Now().Add(time.Hour)) f.setCursor(t, "10") - f.server.setPages([]event{node(t, "d-gap", receipt("tx-gap"))}) - l := f.listener() + f.server.setPages([]event{{digest: "d-gap", checkpoint: 12, bcs: encode(t, receipt("tx-gap"))}}) cursor := uint64(10) + stream := f.listener().NewStream(&cursor) - seq, err := l.StreamCheckpoint(t.Context(), &cursor, checkpoint(t, 15, "d-live", "tx-live")) - if err != nil || seq != 15 { - t.Fatalf("StreamCheckpoint = %d, %v", seq, err) + if err := stream.Checkpoint(t.Context(), checkpoint(t, 15, "d-live", "tx-live")); err != nil { + t.Fatal(err) } equal(t, "order", f.dispositions(), []string{"d-gap=applied", "d-live=applied"}) - f.server.mu.Lock() - queries := len(f.server.queries) - after := f.server.queries[0]["afterCheckpoint"] - f.server.mu.Unlock() - if queries != 1 || after != float64(10) { - t.Fatalf("gap queries %d after %v", queries, after) + queries := f.server.eventQueries() + if len(queries) != 1 || queries[0]["afterCheckpoint"] != float64(10) || queries[0]["beforeCheckpoint"] != float64(15) { + t.Fatalf("gap queries %v", queries) } if f.cursor(t) != "15" { t.Fatalf("cursor %s", f.cursor(t)) } // The next checkpoint follows directly: no catch-up query. - cursor = 15 - if _, err := l.StreamCheckpoint(t.Context(), &cursor, checkpoint(t, 16, "d-next", "tx-live")); err != nil { + if err := stream.Checkpoint(t.Context(), checkpoint(t, 16, "d-next", "tx-live")); err != nil { t.Fatal(err) } - f.server.mu.Lock() - queries = len(f.server.queries) - f.server.mu.Unlock() - if queries != 1 || f.cursor(t) != "16" { - t.Fatalf("contiguous checkpoint: queries %d, cursor %s", queries, f.cursor(t)) + if n := len(f.server.eventQueries()); n != 1 || f.cursor(t) != "16" { + t.Fatalf("contiguous checkpoint: queries %d, cursor %s", n, f.cursor(t)) } } @@ -518,7 +557,7 @@ func TestStreamGapFailureKeepsCursor(t *testing.T) { f.setCursor(t, "10") f.server.setPages([]event{{digest: "d-gap", bcs: []byte{1}}}) cursor := uint64(10) - if _, err := f.listener().StreamCheckpoint(t.Context(), &cursor, checkpoint(t, 15, "d-live", "tx-gap")); err == nil { + if err := f.listener().NewStream(&cursor).Checkpoint(t.Context(), checkpoint(t, 15, "d-live", "tx-gap")); err == nil { t.Fatal("gap with an undecodable event succeeded") } if f.cursor(t) != "10" || len(f.receipts(t)) != 0 { @@ -526,21 +565,128 @@ func TestStreamGapFailureKeepsCursor(t *testing.T) { } } -// Without a stored cursor the listener starts at the tip and stores it, so a -// restart before the first streamed checkpoint keeps that starting point. +// Without a stored cursor the listener starts at the tip the indexer has +// reached and stores it, so a restart before the first streamed checkpoint +// keeps that starting point. func TestFirstStartStoresTip(t *testing.T) { + for _, tc := range []struct { + indexed uint64 + want string + }{{100, "77"}, {70, "70"}} { + f := newFixture(t) + f.server.setIndexed(tc.indexed) + cursor, err := f.listener().CatchUpTo(t.Context(), nil, 77) + if err != nil || cursor == nil || strconv.FormatUint(*cursor, 10) != tc.want { + t.Fatalf("indexer at %d: CatchUpTo = %v, %v", tc.indexed, cursor, err) + } + if f.cursor(t) != tc.want || len(f.server.eventQueries()) != 0 { + t.Fatalf("indexer at %d: stored cursor %s, %d event queries", tc.indexed, f.cursor(t), len(f.server.eventQueries())) + } + } +} + +// The cursor never passes what the indexer has ingested. Node at 110, +// indexer at 105, a payment at 108 the indexer exposes only later: it is +// applied once, when the indexer has it. +func TestCatchUpStopsAtIndexedCheckpoint(t *testing.T) { f := newFixture(t) - cursor, err := f.listener().CatchUpTo(t.Context(), nil, 77) - if err != nil || cursor == nil || *cursor != 77 { - t.Fatalf("CatchUpTo = %v, %v", cursor, err) + f.transaction(t, "tx-108", time.Now().Add(time.Hour)) + f.setCursor(t, "100") + f.server.setPages([]event{{digest: "d108", checkpoint: 108, bcs: encode(t, receipt("tx-108"))}}) + f.server.setIndexed(105) + l := f.listener() + cursor := uint64(100) + + next, err := l.CatchUpTo(t.Context(), &cursor, 110) + if err != nil || f.cursor(t) != "105" || *next != 105 { + t.Fatalf("indexer behind the node: cursor %s, %v", f.cursor(t), err) + } + if f.status(t, "tx-108") != models.Outstanding || len(f.receipts(t)) != 0 { + t.Fatal("receipt of an unindexed checkpoint was applied") + } + // The indexer behind the stored cursor: nothing is stored. + f.server.setIndexed(103) + if again, err := l.CatchUpTo(t.Context(), next, 110); err != nil || *again != 105 || f.cursor(t) != "105" { + t.Fatalf("indexer behind the cursor: %v, cursor %s", err, f.cursor(t)) } - if f.cursor(t) != "77" { - t.Fatalf("stored cursor %s", f.cursor(t)) + + f.server.setIndexed(110) + if next, err = l.CatchUpTo(t.Context(), next, 110); err != nil || *next != 110 || f.cursor(t) != "110" { + t.Fatalf("indexer caught up: cursor %s, %v", f.cursor(t), err) + } + equal(t, "rows", f.receipts(t), []string{"d108/tx-108=applied::7"}) + if f.status(t, "tx-108") != models.Paid { + t.Fatal("receipt at 108 not applied") } - f.server.mu.Lock() - queries := len(f.server.queries) - f.server.mu.Unlock() - if queries != 0 { - t.Fatalf("first start queried %d pages", queries) +} + +// A streamed checkpoint far ahead of a lagging indexer records its own +// receipts but leaves the cursor at what the indexer has proven; the gap is +// read when the indexer has it. +func TestStreamWaitsForIndexer(t *testing.T) { + f := newFixture(t) + for _, id := range []string{"tx-108", "tx-115", "tx-116"} { + f.transaction(t, id, time.Now().Add(time.Hour)) + } + f.setCursor(t, "100") + f.server.setPages([]event{{digest: "d108", checkpoint: 108, bcs: encode(t, receipt("tx-108"))}}) + f.server.setIndexed(105) + cursor := uint64(100) + stream := f.listener().NewStream(&cursor) + + if err := stream.Checkpoint(t.Context(), checkpoint(t, 115, "d115", "tx-115")); err != nil { + t.Fatal(err) + } + if f.cursor(t) != "105" || *stream.Cursor() != 105 || f.status(t, "tx-115") != models.Paid || f.status(t, "tx-108") != models.Outstanding { + t.Fatalf("lagging indexer: cursor %s, tx-115 %v, tx-108 %v", f.cursor(t), f.status(t, "tx-115"), f.status(t, "tx-108")) + } + + f.server.setIndexed(115) + if err := stream.Checkpoint(t.Context(), checkpoint(t, 116, "d116", "tx-116")); err != nil { + t.Fatal(err) + } + if f.cursor(t) != "116" || f.status(t, "tx-108") != models.Paid || f.status(t, "tx-116") != models.Paid { + t.Fatalf("indexer caught up: cursor %s, tx-108 %v", f.cursor(t), f.status(t, "tx-108")) + } + equal(t, "rows", f.receipts(t), []string{"d108/tx-108=applied::7", "d115/tx-115=applied::7", "d116/tx-116=applied::7"}) + queries := f.server.eventQueries() + if len(queries) != 2 || queries[1]["afterCheckpoint"] != float64(105) || queries[1]["beforeCheckpoint"] != float64(115) { + t.Fatalf("catch-up queries %v", queries) + } + + // The same range read again on a restart applies nothing twice. + if _, err := f.listener().CatchUpTo(t.Context(), &cursor, 116); err != nil { + t.Fatal(err) + } + equal(t, "rows after restart", f.receipts(t), []string{"d108/tx-108=applied::7", "d115/tx-115=applied::7", "d116/tx-116=applied::7"}) +} + +// Several receipt events of one transaction are separate receipts. +func TestReceiptsOfOneTransaction(t *testing.T) { + f := newFixture(t) + f.transaction(t, "tx-a", time.Now().Add(time.Hour)) + wrong := encode(t, receipt("tx-a", func(ev *receiptEvent) { ev.PaymentAmount = price + 1 })) + valid := encode(t, receipt("tx-a")) + f.server.setPages([]event{{digest: "d1", seq: 0, bcs: wrong}, {digest: "d1", seq: 3, bcs: valid}}) + + if err := f.listener().CatchUpRange(t.Context(), 0, 5); err != nil { + t.Fatal(err) + } + if f.status(t, "tx-a") != models.Paid { + t.Fatal("valid event after a rejected one in the same transaction did not pay") + } + var dispositions []string + rows, err := f.db.QueryContext(t.Context(), "SELECT disposition || ':' || detail FROM payment_receipts WHERE tx_digest = 'd1' ORDER BY disposition") + if err != nil { + t.Fatal(err) + } + defer rows.Close() + for rows.Next() { + var d string + if err := rows.Scan(&d); err != nil { + t.Fatal(err) + } + dispositions = append(dispositions, d) } + equal(t, "events of d1", dispositions, []string{"applied:", "mismatch:amount"}) } diff --git a/internal/storagecheck/init_test.go b/internal/storagecheck/init_test.go index e5a024bf..c3b60f85 100644 --- a/internal/storagecheck/init_test.go +++ b/internal/storagecheck/init_test.go @@ -50,7 +50,7 @@ func TestBootstrapFresh(t *testing.T) { "measurement_execution": "debuglet_id started_observed_ns terminal_observed_ns exit_code tcp_endpoint", "retry_requests": "caller_scope request_id parent_run_id transaction_id request_hash intent_metadata", "allocation_reclamations": "debuglet_id reclaimed_at", - "payment_receipts": "tx_digest nonce disposition amount coin_type receiver checkpoint observed_at detail", + "payment_receipts": "tx_digest event_seq nonce disposition amount coin_type receiver checkpoint observed_at detail", "chain_transfers": "id kind executor_id transaction_id order_id amount currency receiver state digest signed_transaction signature detail created_at updated_at", "account_run_reservations": "debuglet_id account_id queued_bytes retired_at last_retirement_check", "payload_tombstones": "debuglet_id deleted_at reason workload_sha256 certificate_sha256", @@ -78,7 +78,7 @@ func TestBootstrapFresh(t *testing.T) { "oauth_login_attempts": "state_hash provider verifier nonce purpose session_selector expires_at", "pending_identity_links": "user_id provider issuer subject login session_selector expires_at", "device_logins": "selector verifier_hash user_code_hash audience scopes label expires_at next_poll_at poll_interval state approver_session user_id", - }, []string{"account_recovery_pending", "account_run_reservations_live", "attribution_runs_source_idx", "chain_transfers_executor_idx", "debuglet_logs_sequence_idx", "debuglets_uuid_idx", "device_logins_expiry", "executor_enrollment_tokens_executor_idx", "measurement_profiles_owner", "oauth_login_expiry", "owned_executors_user_idx", "sessions_user_idx", "users_uuid_idx"}, []int64{0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22}) + }, []string{"account_recovery_pending", "account_run_reservations_live", "attribution_runs_source_idx", "chain_transfers_executor_idx", "debuglet_logs_sequence_idx", "debuglets_uuid_idx", "device_logins_expiry", "executor_enrollment_tokens_executor_idx", "measurement_profiles_owner", "oauth_login_expiry", "owned_executors_user_idx", "payment_receipts_nonce_idx", "sessions_user_idx", "users_uuid_idx"}, []int64{0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22}) dispatcherSchemaRoundTrip(t, db) } else { assertSchema(t, db, map[string]string{ diff --git a/internal/storagecheck/policy.go b/internal/storagecheck/policy.go index 8b1d0012..e4a8d488 100644 --- a/internal/storagecheck/policy.go +++ b/internal/storagecheck/policy.go @@ -74,7 +74,7 @@ func PolicyFor(role Role) (Policy, error) { }, Tables: map[string][]string{ "account_recovery_audit": {"selector", "user_id", "case_reference", "issued_by_uid", "issued_at", "expires_at", "consumed_at", "revoked_at", "revoked_by_uid", "revocation_reference"}, "allocation_reclamations": {"debuglet_id", "reclaimed_at"}, - "payment_receipts": {"tx_digest", "nonce", "disposition", "amount", "checkpoint", "observed_at"}, + "payment_receipts": {"tx_digest", "event_seq", "nonce", "disposition", "amount", "checkpoint", "observed_at"}, "chain_transfers": {"id", "kind", "transaction_id", "amount", "state", "digest", "signed_transaction", "signature", "updated_at"}, "measurement_profiles": {"id", "user_id", "document"}, "measurement_requests": {"debuglet_id", "document"},