R-379/R-380: put the customer's undo copy back when a database restore fails
gates / gates (push) Successful in 11s
gates / gates (push) Successful in 11s
R-379 and R-380 were one failure. Both ended with a half-restored database; the only difference was whether it looked broken. Postgres emptied and crash-looped; MariaDB applied part of the dump and reported health=healthy with a zero-row schema-version table. Measured live on demo-hp 2026-08-22. The undo copy was already taken and already good - proven by hand that day on both engines. Nothing in the product could apply it. Now it does, with the same ImportDump call, before any restart and inside the DB-only window. The WHOLE undo set, matched on this run's stamp. writeSafetyDump returned one path for an app with two databases; a rollback on that would restore one and leave the other half-written. When the rollback also fails the app is HELD STOPPED (operator ruling): a running app on a half-written database lets the customer make the damage permanent. Every start path refuses it - customer button, appstop Recover, boot sweep - via the shared driveStartGate, checked ABOVE its driveless early return because these apps have no drive. The marker is ended so nothing auto-restarts it. The row goes red. Cleared with --clear-restore-hold, an operator CLI route. --single-transaction is a belt on Postgres only; MariaDB DDL is not transactional and that is why the rollback is the fix. R-381: the engine's stderr stops reaching the customer (615 bytes on MariaDB, its middle rows out of their own database) and starts reaching the operator log, which never had it. R-382: the summary log prints the volume count it already held. Undo copies resolve to their own app, are marked IsUndo, and are capped at 3 per app, pruned from the capture side. The reported render-as-an-app symptom did NOT reproduce - the live page was read first and had zero occurrences. Tests 1468 -> 1483. Eight red-proofs; ONE PASSED and is reported: the R-381 behavioural test injected below ImportDump. A guard at that layer now convicts.
This commit is contained in:
@@ -75,6 +75,42 @@ type DumpFileInfo struct {
|
||||
Size int64
|
||||
ModTime time.Time
|
||||
Validation DumpValidation
|
||||
// IsUndo (R-379, v0.220.0) marks a `pre-restore-` safety copy: the undo taken immediately before
|
||||
// a reconstitution, not the app's own backup. Its VISIBILITY is a recorded decision — see the
|
||||
// comment on preRestoreDumpPrefix, "an undo the customer cannot see is not much of one" — so this
|
||||
// flag names it rather than hiding it.
|
||||
//
|
||||
// It also fixes a real, if latent, naming defect: the filename parse below used to derive
|
||||
// StackName by trimming only the engine suffix, so
|
||||
// `pre-restore-20260822T140924Z-docmost-postgres.sql` yielded the phantom stack
|
||||
// `pre-restore-20260822T140924Z-docmost`. That name reaches the `dbStacks` lookup in
|
||||
// web.buildAppBackupRows as a KEY. It renders nothing today because that function iterates
|
||||
// DEPLOYED apps and only reads the map by key — verified on the live page 2026-08-22, which
|
||||
// contained zero `pre-restore` strings while four such files sat on disk — but any future code
|
||||
// that RANGES over that map would surface a stack that does not exist.
|
||||
IsUndo bool
|
||||
// UndoAt is when the undo copy was taken, parsed from the stamp in its own filename. Zero for a
|
||||
// normal dump.
|
||||
UndoAt time.Time
|
||||
}
|
||||
|
||||
// UndoDumpPrefix is the marker on a pre-restore safety copy. It is duplicated from
|
||||
// backup.preRestoreDumpPrefix on purpose — appbackup must not import backup (that direction is the
|
||||
// dependency, not this one) — and the two are pinned equal by a test.
|
||||
const UndoDumpPrefix = "pre-restore-"
|
||||
|
||||
// trimUndoPrefix splits `pre-restore-<stamp>-<rest>` into (<rest>, <stamp>, true). Returns
|
||||
// (base, "", false) for anything that is not an undo copy, so a normal dump flows unchanged.
|
||||
func trimUndoPrefix(base string) (string, string, bool) {
|
||||
if !strings.HasPrefix(base, UndoDumpPrefix) {
|
||||
return base, "", false
|
||||
}
|
||||
after := strings.TrimPrefix(base, UndoDumpPrefix)
|
||||
i := strings.Index(after, "-")
|
||||
if i <= 0 {
|
||||
return base, "", false // a prefix with no stamp is not the shape writeSafetyDump writes
|
||||
}
|
||||
return after[i+1:], after[:i], true
|
||||
}
|
||||
|
||||
// DiscoverDatabases finds running database containers via docker ps.
|
||||
@@ -571,6 +607,15 @@ func ListDumpFiles(dumpDir string, cached func(name string, size int64, mod time
|
||||
|
||||
// Parse stack name and DB type from filename: "paperless-ngx-postgres.sql"
|
||||
base := strings.TrimSuffix(e.Name(), ".sql")
|
||||
// R-379: strip the `pre-restore-<stamp>-` head FIRST, so an undo copy resolves to the app it
|
||||
// belongs to instead of a phantom stack named after its own timestamp.
|
||||
if rest, stamp, ok := trimUndoPrefix(base); ok {
|
||||
base = rest
|
||||
f.IsUndo = true
|
||||
if t, err := time.Parse("20060102T150405Z", stamp); err == nil {
|
||||
f.UndoAt = t
|
||||
}
|
||||
}
|
||||
if strings.HasSuffix(base, "-postgres") {
|
||||
f.StackName = strings.TrimSuffix(base, "-postgres")
|
||||
f.DBType = DBTypePostgres
|
||||
@@ -680,8 +725,15 @@ func ImportDump(ctx context.Context, db DiscoveredDB, dumpPath string, logger *l
|
||||
dbName = user
|
||||
}
|
||||
// ON_ERROR_STOP=1: a real import error must FAIL (and surface), not silently half-apply.
|
||||
//
|
||||
// --single-transaction (R-380, v0.220.0) is a BELT, not the fix. It makes a Postgres replay
|
||||
// all-or-nothing at the engine, so the emptied-and-crash-looping state measured on `docmost`
|
||||
// on 2026-08-22 stops being reachable on this engine. It does NOT make MariaDB atomic —
|
||||
// MariaDB's DDL is not transactional, so a partial apply there is unavoidable at the engine
|
||||
// and is why the rollback in offbox_reconstitute.go exists and is the actual fix. Do not
|
||||
// read this flag as making the rollback optional.
|
||||
cmd = exec.CommandContext(impCtx, "docker", "exec", "-i", db.ContainerID,
|
||||
"psql", "-v", "ON_ERROR_STOP=1", "-U", user, "-d", dbName)
|
||||
"psql", "-v", "ON_ERROR_STOP=1", "--single-transaction", "-U", user, "-d", dbName)
|
||||
case DBTypeMariaDB:
|
||||
password := getMariaDBPassword(impCtx, db.ContainerID)
|
||||
if password == "" {
|
||||
@@ -700,11 +752,21 @@ func ImportDump(ctx context.Context, db DiscoveredDB, dumpPath string, logger *l
|
||||
logger.Printf("[DEBUG] [backup] ImportDump: importing %s into %s (%s)", dumpPath, db.ContainerName, db.DBType)
|
||||
}
|
||||
if err := cmd.Run(); err != nil {
|
||||
msg := strings.TrimSpace(stderr.String())
|
||||
if len(msg) > 300 {
|
||||
msg = msg[:300]
|
||||
// R-381: the engine's stderr goes to the OPERATOR LOG, in full. It used to be truncated to
|
||||
// 300 chars and folded into the returned error, which the restore surface then rendered to
|
||||
// the customer — measured 2026-08-22 at 407 bytes (Postgres, a caret diagram and
|
||||
// `exit status 3`) and 615 bytes (MariaDB, whose middle was an `INSERT INTO migrations
|
||||
// VALUES (...)` listing, i.e. ROWS OUT OF THE CUSTOMER'S OWN DATABASE, HTML-escaped, on
|
||||
// their dashboard).
|
||||
//
|
||||
// The diagnostic is ADDED here, not removed: previously nothing logged the full text at all,
|
||||
// so this is strictly more for the operator and strictly less for the customer.
|
||||
full := strings.TrimSpace(stderr.String())
|
||||
if logger != nil {
|
||||
logger.Printf("[ERROR] [backup] %s import into %s FAILED: %v — engine output follows:\n%s",
|
||||
db.DBType, db.ContainerName, err, full)
|
||||
}
|
||||
return fmt.Errorf("%s import into %s failed: %s — %w", db.DBType, db.ContainerName, msg, err)
|
||||
return fmt.Errorf("%s import into %s failed: %w", db.DBType, db.ContainerName, err)
|
||||
}
|
||||
if logger != nil {
|
||||
logger.Printf("[INFO] [backup] Imported DB dump %s into %s (%s)", filepath.Base(dumpPath), db.ContainerName, db.DBType)
|
||||
|
||||
@@ -0,0 +1,182 @@
|
||||
package appbackup
|
||||
|
||||
import (
|
||||
"go/ast"
|
||||
"go/parser"
|
||||
"go/token"
|
||||
"os"
|
||||
"path/filepath"
|
||||
"testing"
|
||||
"time"
|
||||
)
|
||||
|
||||
// R-379/R-381. An undo copy used to derive its stack name by trimming only the engine suffix, so
|
||||
// `pre-restore-20260822T140924Z-docmost-postgres.sql` yielded the phantom stack
|
||||
// `pre-restore-20260822T140924Z-docmost`. That name reaches web.buildAppBackupRows' `dbStacks` map
|
||||
// as a KEY.
|
||||
//
|
||||
// MEASURED ON THE LIVE PAGE 2026-08-22 BEFORE CHANGING ANYTHING: /backups/apps contained ZERO
|
||||
// `pre-restore` strings while four such files sat on disk, because that function iterates DEPLOYED
|
||||
// apps and only reads the map by key. So the phantom never renders TODAY — the visible-row defect
|
||||
// does not reproduce, and this test does not claim it did. What it pins is the naming, so any future
|
||||
// code that RANGES over that map cannot surface a stack that does not exist.
|
||||
func TestUndoCopyResolvesToItsOwnApp(t *testing.T) {
|
||||
dir := t.TempDir()
|
||||
write := func(name string) {
|
||||
if err := os.WriteFile(filepath.Join(dir, name), []byte("-- PostgreSQL database dump\nCREATE TABLE x();\n"), 0o644); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
}
|
||||
write("docmost-postgres.sql")
|
||||
write("pre-restore-20260822T140924Z-docmost-postgres.sql")
|
||||
write("pre-restore-20260822T142418Z-bookstack-mariadb.sql")
|
||||
|
||||
files, err := ListDumpFiles(dir, nil)
|
||||
if err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
byName := map[string]DumpFileInfo{}
|
||||
for _, f := range files {
|
||||
byName[f.FileName] = f
|
||||
}
|
||||
if len(byName) != 3 {
|
||||
t.Fatalf("expected 3 dumps listed, got %d", len(byName))
|
||||
}
|
||||
|
||||
own := byName["docmost-postgres.sql"]
|
||||
if own.StackName != "docmost" || own.IsUndo {
|
||||
t.Errorf("the app's own dump must be stack=docmost and NOT an undo; got stack=%q isUndo=%v", own.StackName, own.IsUndo)
|
||||
}
|
||||
|
||||
u := byName["pre-restore-20260822T140924Z-docmost-postgres.sql"]
|
||||
if u.StackName != "docmost" {
|
||||
t.Errorf("an undo copy must resolve to the app it belongs to, not a phantom; got %q", u.StackName)
|
||||
}
|
||||
if !u.IsUndo {
|
||||
t.Error("an undo copy must be marked as one — its visibility is a recorded decision, so it must be NAMED rather than hidden")
|
||||
}
|
||||
if u.DBType != DBTypePostgres {
|
||||
t.Errorf("the engine must still be parsed; got %q", u.DBType)
|
||||
}
|
||||
want, _ := time.Parse("20060102T150405Z", "20260822T140924Z")
|
||||
if !u.UndoAt.Equal(want) {
|
||||
t.Errorf("UndoAt = %v, want %v", u.UndoAt, want)
|
||||
}
|
||||
|
||||
m := byName["pre-restore-20260822T142418Z-bookstack-mariadb.sql"]
|
||||
if m.StackName != "bookstack" || !m.IsUndo || m.DBType != DBTypeMariaDB {
|
||||
t.Errorf("mariadb undo copy mis-parsed: stack=%q isUndo=%v type=%q", m.StackName, m.IsUndo, m.DBType)
|
||||
}
|
||||
}
|
||||
|
||||
// A file that merely starts with the prefix but is not the shape writeSafetyDump writes must be left
|
||||
// alone rather than guessed at.
|
||||
func TestUndoPrefixWithoutAStampIsNotTreatedAsAnUndo(t *testing.T) {
|
||||
if base, stamp, ok := trimUndoPrefix("pre-restore-nostamp"); ok {
|
||||
t.Errorf("a prefix with no stamp separator must not parse as an undo; got base=%q stamp=%q", base, stamp)
|
||||
}
|
||||
if base, _, ok := trimUndoPrefix("docmost-postgres"); ok || base != "docmost-postgres" {
|
||||
t.Errorf("a normal dump must flow through unchanged; got base=%q ok=%v", base, ok)
|
||||
}
|
||||
}
|
||||
|
||||
// R-381, AT THE LAYER THE LEAK LIVES IN.
|
||||
//
|
||||
// WHY THIS TEST EXISTS AND THE BEHAVIOURAL ONE WAS NOT ENOUGH — recorded because it was caught by a
|
||||
// red-proof that PASSED. The sibling test in internal/backup asserts that the reconstitution's
|
||||
// customer sentence carries no engine output, but it injects at `m.importDBDump`, i.e. BELOW
|
||||
// ImportDump. Re-adding the stderr to ImportDump's own fmt.Errorf therefore did not fail it. The
|
||||
// leak's home is this function, so the guard belongs here.
|
||||
//
|
||||
// ImportDump shells out to docker, so its failure path cannot be driven in a unit test. What CAN be
|
||||
// pinned is the thing the mutation changes: the error it constructs must not reference the captured
|
||||
// stderr. AST, not strings.Contains — a commented-out reference still contains the string.
|
||||
func TestImportDumpErrorDoesNotCarryEngineStderr(t *testing.T) {
|
||||
fset := token.NewFileSet()
|
||||
f, err := parser.ParseFile(fset, "dbdump.go", nil, 0)
|
||||
if err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
var body *ast.BlockStmt
|
||||
for _, d := range f.Decls {
|
||||
if fn, ok := d.(*ast.FuncDecl); ok && fn.Name.Name == "ImportDump" && fn.Body != nil {
|
||||
body = fn.Body
|
||||
}
|
||||
}
|
||||
if body == nil {
|
||||
t.Fatal("ImportDump not found — this guard can no longer prove anything")
|
||||
}
|
||||
|
||||
// Find the name the stderr text is captured into, so the test tracks a rename instead of
|
||||
// silently passing when the variable is called something else.
|
||||
stderrVar := ""
|
||||
ast.Inspect(body, func(n ast.Node) bool {
|
||||
as, ok := n.(*ast.AssignStmt)
|
||||
if !ok || len(as.Lhs) != 1 || len(as.Rhs) != 1 {
|
||||
return true
|
||||
}
|
||||
call, ok := as.Rhs[0].(*ast.CallExpr)
|
||||
if !ok {
|
||||
return true
|
||||
}
|
||||
// strings.TrimSpace(stderr.String())
|
||||
if sel, ok := call.Fun.(*ast.SelectorExpr); ok && sel.Sel.Name == "TrimSpace" {
|
||||
if id, ok := as.Lhs[0].(*ast.Ident); ok {
|
||||
stderrVar = id.Name
|
||||
}
|
||||
}
|
||||
return true
|
||||
})
|
||||
if stderrVar == "" {
|
||||
t.Fatal("could not find where ImportDump captures the engine stderr — the guard cannot aim")
|
||||
}
|
||||
|
||||
var leaked bool
|
||||
ast.Inspect(body, func(n ast.Node) bool {
|
||||
ret, ok := n.(*ast.ReturnStmt)
|
||||
if !ok {
|
||||
return true
|
||||
}
|
||||
for _, r := range ret.Results {
|
||||
call, ok := r.(*ast.CallExpr)
|
||||
if !ok {
|
||||
continue
|
||||
}
|
||||
sel, ok := call.Fun.(*ast.SelectorExpr)
|
||||
if !ok || sel.Sel.Name != "Errorf" {
|
||||
continue
|
||||
}
|
||||
for _, arg := range call.Args {
|
||||
if id, ok := arg.(*ast.Ident); ok && id.Name == stderrVar {
|
||||
leaked = true
|
||||
}
|
||||
}
|
||||
}
|
||||
return true
|
||||
})
|
||||
if leaked {
|
||||
t.Fatalf("ImportDump's returned error passes %q (the engine stderr) — that text reaches the customer's dashboard. "+
|
||||
"Measured 2026-08-22 at 615 bytes on MariaDB, whose middle was rows out of the customer's own database. "+
|
||||
"The full text belongs in the operator log, which this function already writes.", stderrVar)
|
||||
}
|
||||
|
||||
// POSITIVE CONTROL for the "it is still logged" half: the operator must not lose the diagnostic.
|
||||
var logged bool
|
||||
ast.Inspect(body, func(n ast.Node) bool {
|
||||
call, ok := n.(*ast.CallExpr)
|
||||
if !ok {
|
||||
return true
|
||||
}
|
||||
if sel, ok := call.Fun.(*ast.SelectorExpr); ok && sel.Sel.Name == "Printf" {
|
||||
for _, arg := range call.Args {
|
||||
if id, ok := arg.(*ast.Ident); ok && id.Name == stderrVar {
|
||||
logged = true
|
||||
}
|
||||
}
|
||||
}
|
||||
return true
|
||||
})
|
||||
if !logged {
|
||||
t.Error("the engine stderr is no longer logged either — the diagnostic must be ADDED to the operator log, not removed from everywhere")
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user