diff --git a/README.md b/README.md index a9ab0f1..b7b6e04 100644 --- a/README.md +++ b/README.md @@ -73,3 +73,20 @@ already be mounted, for example through Unassigned Devices. URBM checks array an USB mounts before starting the job and refuses leftover directories after an unmount. Keep the USB disk connected throughout the run. Reload the page after mounting a new array disk to refresh the available sources. + +### Rsync diagnostics (2026.09.27.r002) + +Run logs start collapsed and retain your open/closed selection during refresh. +New Rsync runs log the source paths, target, dry-run mode, overwrite/delete and +comparison options, exclusions, execution phases, up to 20 itemized change +examples, and final file/byte/deletion totals. Deletion counts include directories +and symlinks. Byte totals describe the contents of transferred files, not protocol +traffic. A dry run reports planned changes and records zero bytes actually copied; +its notification explicitly states that no changes were made. Historical logs +cannot be reconstructed with these additional details. + +For an integration test against Rsync 3.x, run +`URBM_TEST_RSYNC=/path/to/rsync go test ./internal/rsync -run TestRealRsync -v`. +The test uses temporary directories only and checks that a dry run changes nothing, +that a subsequent copy matches the planned counts, and that another comparison +then finds no changes. diff --git a/dist/urbm-2026.09.27.r002-x86_64-1.txz b/dist/urbm-2026.09.27.r002-x86_64-1.txz new file mode 100644 index 0000000..023952f Binary files /dev/null and b/dist/urbm-2026.09.27.r002-x86_64-1.txz differ diff --git a/dist/urbm-2026.09.27.r002-x86_64-1.txz.sha256 b/dist/urbm-2026.09.27.r002-x86_64-1.txz.sha256 new file mode 100644 index 0000000..9d4c98a --- /dev/null +++ b/dist/urbm-2026.09.27.r002-x86_64-1.txz.sha256 @@ -0,0 +1 @@ +12bf23238112ee7ad9fe6c1102528cdd7baeb32a89378b7ac17621642b001b87 urbm-2026.09.27.r002-x86_64-1.txz diff --git a/dist/urbm.plg b/dist/urbm.plg index d327344..285a314 100644 --- a/dist/urbm.plg +++ b/dist/urbm.plg @@ -2,13 +2,20 @@ - + - + ]> +### 2026.09.27.r002 +- Collapse run logs by default and retain manually opened logs during refresh. +- Log Rsync sources, destination, comparison and deletion options, execution phases, sample changes, errors and final totals. +- Clearly distinguish dry-run plans from actual copies and include deleted entries in logs and notifications. +- Parse exact byte statistics for progress, summaries and free-space checks; drain process output before closing pipes. +- Test dry runs, copies and deletions with real Rsync fixtures as well as regression tests. + ### 2026.09.27.r001 - Discover mounted array disks as selectable Rsync sources, including complete disks. - Show directory symlinks only when they resolve within allowed storage roots. diff --git a/internal/model/model.go b/internal/model/model.go index 16e7030..6a6ab64 100644 --- a/internal/model/model.go +++ b/internal/model/model.go @@ -138,6 +138,8 @@ type NotificationTarget struct { } type Run struct { + RsyncDryRun bool `json:"rsyncDryRun,omitempty"` + EntriesDeleted int64 `json:"entriesDeleted,omitempty"` SchemaVersion int `json:"schemaVersion"` ID string `json:"id"` JobID string `json:"jobId,omitempty"` diff --git a/internal/rsync/rsync.go b/internal/rsync/rsync.go index df39017..486f0a9 100644 --- a/internal/rsync/rsync.go +++ b/internal/rsync/rsync.go @@ -40,16 +40,19 @@ type Progress struct { Bytes int64 Files int64 CurrentFile string + Change string } type Summary struct { - Bytes int64 - Files int64 + Bytes int64 + Files int64 + Deleted int64 } var ( progressPattern = regexp.MustCompile(`^\s*([0-9,]+)\s+([0-9]+)%`) filesPattern = regexp.MustCompile(`^Number of regular files transferred:\s*([0-9,]+)`) + deletedPattern = regexp.MustCompile(`^Number of deleted files:\s*([0-9,]+)`) bytesPattern = regexp.MustCompile(`^Total transferred file size:\s*([0-9,]+) bytes`) ) @@ -88,17 +91,12 @@ func (r *Runner) Run(ctx context.Context, runID string, job model.Job, callback done := make(chan struct{}) go func() { scanOutput(stdout, func(line string) { - if value, ok := parseCount(filesPattern, line); ok { - summary.Files = value - } - if value, ok := parseCount(bytesPattern, line); ok { - summary.Bytes = value - } + summary.parseLine(line) if callback != nil { if progress, ok := parseProgress(line); ok { callback(progress) - } else if strings.HasPrefix(line, "FILE|") { - callback(Progress{CurrentFile: strings.TrimPrefix(line, "FILE|")}) + } else if change, ok := parseChange(line); ok { + callback(change) } } }) @@ -106,9 +104,10 @@ func (r *Runner) Run(ctx context.Context, runID string, job model.Job, callback }() stderrDone := make(chan []byte, 1) go func() { stderrDone <- drainLimited(stderr, 1024*1024) }() - err = cmd.Wait() + // Drain both pipes before Wait closes them, including the final statistics. <-done errBytes := <-stderrDone + err = cmd.Wait() if err != nil { if errors.Is(ctx.Err(), context.Canceled) { return Summary{}, fmt.Errorf("cancelled: %w", ctx.Err()) @@ -163,20 +162,16 @@ func (r *Runner) Estimate(ctx context.Context, runID string, job model.Job) (Sum done := make(chan struct{}) go func() { scanOutput(stdout, func(line string) { - if value, ok := parseCount(filesPattern, line); ok { - summary.Files = value - } - if value, ok := parseCount(bytesPattern, line); ok { - summary.Bytes = value - } + summary.parseLine(line) }) close(done) }() stderrDone := make(chan []byte, 1) go func() { stderrDone <- drainLimited(stderr, 1024*1024) }() - err = cmd.Wait() + // Drain both pipes before Wait closes them, including the final statistics. <-done errBytes := <-stderrDone + err = cmd.Wait() if err != nil { if errors.Is(ctx.Err(), context.Canceled) { return Summary{}, fmt.Errorf("cancelled: %w", ctx.Err()) @@ -188,7 +183,7 @@ func (r *Runner) Estimate(ctx context.Context, runID string, job model.Job) (Sum func Arguments(job model.Job) []string { options := job.Rsync - args := []string{"--recursive", "--human-readable", "--info=progress2", "--stats", "--partial", "--out-format=FILE|%n"} + args := []string{"--recursive", "--info=progress2", "--stats", "--partial", "--outbuf=L", "--out-format=CHANGE|%i|%n%L"} if !options.Overwrite { args = append(args, "--ignore-existing") } @@ -322,3 +317,26 @@ func parseCount(pattern *regexp.Regexp, line string) (int64, bool) { value, err := strconv.ParseInt(strings.ReplaceAll(match[1], ",", ""), 10, 64) return value, err == nil } + +func (s *Summary) parseLine(line string) { + if value, ok := parseCount(filesPattern, line); ok { + s.Files = value + } + if value, ok := parseCount(bytesPattern, line); ok { + s.Bytes = value + } + if value, ok := parseCount(deletedPattern, line); ok { + s.Deleted = value + } +} + +func parseChange(line string) (Progress, bool) { + if !strings.HasPrefix(line, "CHANGE|") { + return Progress{}, false + } + fields := strings.SplitN(strings.TrimPrefix(line, "CHANGE|"), "|", 2) + if len(fields) != 2 || len(fields[0]) != 11 { + return Progress{}, false + } + return Progress{Change: fields[0], CurrentFile: fields[1]}, true +} diff --git a/internal/rsync/rsync_test.go b/internal/rsync/rsync_test.go index 4c3f99f..a44a5cf 100644 --- a/internal/rsync/rsync_test.go +++ b/internal/rsync/rsync_test.go @@ -1,7 +1,11 @@ package rsync import ( + "context" + "os" + "path/filepath" "slices" + "strings" "testing" "git.casaderoll.de/michael/urbm/internal/model" @@ -31,3 +35,138 @@ func TestArrayDiskMirrorKeepsDiskDirectory(t *testing.T) { t.Fatalf("mirror arguments = %v", args) } } + +func TestMachineReadableArgumentsAndSummary(t *testing.T) { + args := Arguments(model.Job{}) + if slices.Contains(args, "--human-readable") { + t.Fatal("human readable sizes break byte parsing") + } + if !slices.Contains(args, "--out-format=CHANGE|%i|%n%L") { + t.Fatal(args) + } + var summary Summary + for _, line := range []string{"Number of regular files transferred: 1,376", "Number of deleted files: 1,214 (reg: 1,200, dir: 14)", "Total transferred file size: 1,234,567,890 bytes"} { + summary.parseLine(line) + } + if summary.Files != 1376 || summary.Deleted != 1214 || summary.Bytes != 1234567890 { + t.Fatalf("summary = %+v", summary) + } +} + +func TestParseChangePreservesNames(t *testing.T) { + for _, code := range []string{">f+++++++++", ">f.st......", ".d..t......", "*deleting "} { + got, ok := parseChange("CHANGE|" + code + "|disk1/a | b.txt") + if !ok || got.Change != code || got.CurrentFile != "disk1/a | b.txt" { + t.Fatalf("change = %+v, %v", got, ok) + } + } +} + +func TestRunnerReadsFinalStats(t *testing.T) { + binary := filepath.Join(t.TempDir(), "rsync") + script := "#!/bin/sh\nprintf '%s\\n' 'CHANGE|>f+++++++++|disk1/new.txt' 'Number of regular files transferred: 1,376' 'Number of deleted files: 1,214 (reg: 1214)' 'Total transferred file size: 1,234,567,890 bytes'\n" + if err := os.WriteFile(binary, []byte(script), 0700); err != nil { + t.Fatal(err) + } + runner := Runner{Binary: binary} + for _, estimate := range []bool{false, true} { + var summary Summary + var err error + var changes []string + if estimate { + summary, err = runner.Estimate(context.Background(), "test", model.Job{}) + } else { + summary, err = runner.Run(context.Background(), "test", model.Job{}, func(p Progress) { + if p.CurrentFile != "" { + changes = append(changes, p.CurrentFile) + } + }) + } + if err != nil || summary.Files != 1376 || summary.Deleted != 1214 || summary.Bytes != 1234567890 { + t.Fatalf("estimate=%v summary=%+v err=%v", estimate, summary, err) + } + if !estimate && strings.Join(changes, ",") != "disk1/new.txt" { + t.Fatal(changes) + } + } +} + +// Opt in with URBM_TEST_RSYNC pointing to rsync 3.x (Unraid's supported version). +func TestRealRsyncDryRunAndCopy(t *testing.T) { + binary := os.Getenv("URBM_TEST_RSYNC") + if binary == "" { + t.Skip("set URBM_TEST_RSYNC to test with rsync 3.x") + } + dir := t.TempDir() + source, target := filepath.Join(dir, "disk1"), filepath.Join(dir, "USB") + destination := filepath.Join(target, "disk1") + for _, path := range []string{source, filepath.Join(destination, "old-dir")} { + if err := os.MkdirAll(path, 0700); err != nil { + t.Fatal(err) + } + } + for path, data := range map[string]string{ + filepath.Join(source, "new"): "new", filepath.Join(source, "changed"): "updated", + filepath.Join(source, "same"): "same", filepath.Join(destination, "same"): "same", + filepath.Join(destination, "changed"): "old", filepath.Join(destination, "obsolete"): "delete", + filepath.Join(destination, "old-dir", "file"): "delete", + } { + if err := os.WriteFile(path, []byte(data), 0600); err != nil { + t.Fatal(err) + } + } + if err := os.Symlink("obsolete", filepath.Join(destination, "old-link")); err != nil { + t.Fatal(err) + } + runner := Runner{Binary: binary} + job := model.Job{Sources: []model.Source{{Path: source}}, Rsync: model.RsyncOptions{Target: target, DryRun: true, Overwrite: true, Delete: true, Checksum: true, PreserveLinks: true}} + var changes []Progress + summary, err := runner.Run(context.Background(), "test", job, func(p Progress) { + if p.Change != "" { + changes = append(changes, p) + } + }) + if err != nil || summary.Files != 2 || summary.Bytes != 10 || summary.Deleted != 4 { + t.Fatalf("dry run: %+v %v", summary, err) + } + if len(changes) < 6 { + t.Fatalf("missing change details: %+v", changes) + } + if _, err := os.Stat(filepath.Join(destination, "new")); !os.IsNotExist(err) { + t.Fatal("dry run wrote a file") + } + if _, err := os.Stat(filepath.Join(destination, "obsolete")); err != nil { + t.Fatal("dry run deleted a file") + } + estimate, err := runner.Estimate(context.Background(), "test", job) + if err != nil || estimate != summary { + t.Fatalf("estimate differs: %+v %v", estimate, err) + } + job.Rsync.DryRun = false + copied, err := runner.Run(context.Background(), "test", job, nil) + if err != nil || copied != summary { + t.Fatalf("copy differs: %+v %v", copied, err) + } + for _, name := range []string{"new", "changed", "same"} { + got, err := os.ReadFile(filepath.Join(destination, name)) + if err != nil { + t.Fatal(err) + } + want, err := os.ReadFile(filepath.Join(source, name)) + if err != nil { + t.Fatal(err) + } + if string(got) != string(want) { + t.Fatalf("different contents: %s", name) + } + } + for _, name := range []string{"obsolete", "old-dir", "old-link"} { + if _, err := os.Lstat(filepath.Join(destination, name)); !os.IsNotExist(err) { + t.Fatalf("not deleted: %s", name) + } + } + identical, err := runner.Estimate(context.Background(), "test", job) + if err != nil || identical.Files != 0 || identical.Bytes != 0 || identical.Deleted != 0 { + t.Fatalf("identical: %+v %v", identical, err) + } +} diff --git a/internal/service/rsync_log.go b/internal/service/rsync_log.go new file mode 100644 index 0000000..5403d42 --- /dev/null +++ b/internal/service/rsync_log.go @@ -0,0 +1,97 @@ +package service + +import ( + "fmt" + "strings" + + "git.casaderoll.de/michael/urbm/internal/model" + "git.casaderoll.de/michael/urbm/internal/rsync" +) + +func logRsyncSetup(run *model.Run, job model.Job) { + mode := "Kopierlauf – Änderungen am Ziel werden ausgeführt" + if job.Rsync.DryRun { + mode = "Testlauf – es werden keine Dateien geschrieben oder gelöscht" + } + appendLiveLog(run, "Rsync: "+mode) + for _, source := range job.Sources { + appendLiveLog(run, "Quelle: "+source.Path) + } + appendLiveLog(run, "Ziel: "+job.Rsync.Target) + overwrite := "vorhandene Dateien überspringen" + if job.Rsync.Overwrite { + overwrite = "abweichende vorhandene Dateien aktualisieren" + } + deletion := "aus" + if job.Rsync.Delete { + deletion = "an (zusätzliche Einträge im Ziel entfernen)" + } + comparison := "Dateigröße und Änderungszeit" + if job.Rsync.Checksum { + comparison = "Dateiinhalt per Prüfsumme (liest Dateien vollständig)" + } + appendLiveLog(run, "Vorhandene Dateien: "+overwrite+"; Löschen: "+deletion) + appendLiveLog(run, "Vergleich: "+comparison) + var preserve []string + for _, option := range []struct { + enabled bool + label string + }{ + {job.Rsync.PreserveTimes, "Zeitstempel"}, {job.Rsync.PreservePermissions, "Berechtigungen"}, + {job.Rsync.PreserveOwner, "Besitzer"}, {job.Rsync.PreserveGroup, "Gruppe"}, + {job.Rsync.PreserveLinks, "Symlinks"}, {job.Rsync.PreserveACLs, "ACLs"}, {job.Rsync.PreserveXattrs, "erweiterte Attribute"}, + } { + if option.enabled { + preserve = append(preserve, option.label) + } + } + if len(preserve) > 0 { + appendLiveLog(run, "Übernehmen: "+strings.Join(preserve, ", ")) + } + appendLiveLog(run, fmt.Sprintf("Ausschlussmuster: %d", len(job.Excludes))) + for index, pattern := range job.Excludes { + if index == 10 { + appendLiveLog(run, "Weitere Ausschlussmuster siehe Job-Konfiguration") + break + } + appendLiveLog(run, "Ausschluss: "+pattern) + } +} + +func rsyncChangeLabel(code string) string { + if strings.HasPrefix(code, "*deleting") { + return "Löschen" + } + if len(code) != 11 { + return "Änderung" + } + if code[2:] == "+++++++++" { + return "Neu" + } + if code[0] == '.' { + return "Metadaten ändern" + } + return "Aktualisieren" +} + +func applyRsyncSummary(run *model.Run, summary rsync.Summary) { + run.Status, run.Message = "success", "rsync completed" + run.BytesProcessed, run.FilesProcessed = summary.Bytes, summary.Files + run.EntriesDeleted = summary.Deleted + run.BytesAdded = summary.Bytes + if run.RsyncDryRun { + run.BytesAdded = 0 + run.Message = "Rsync-Testlauf erfolgreich – keine Änderungen vorgenommen" + } + // Rsync's transferred-file count combines new and updated regular files. + run.FilesNew, run.FilesChanged = 0, 0 +} + +func logRsyncSummary(run *model.Run, summary rsync.Summary) { + if run.RsyncDryRun { + appendLiveLog(run, fmt.Sprintf("Testlauf: %d Dateien würden kopiert/aktualisiert (%s Dateiinhalt); %d Einträge würden gelöscht (inkl. Ordner/Symlinks)", summary.Files, formatBytes(summary.Bytes), summary.Deleted)) + appendLiveLog(run, "Testlauf erfolgreich – keine Änderungen vorgenommen") + } else { + appendLiveLog(run, fmt.Sprintf("Rsync abgeschlossen: %d Dateien kopiert/aktualisiert (%s Dateiinhalt); %d Einträge gelöscht (inkl. Ordner/Symlinks)", summary.Files, formatBytes(summary.Bytes), summary.Deleted)) + } +} diff --git a/internal/service/rsync_log_test.go b/internal/service/rsync_log_test.go new file mode 100644 index 0000000..57c1a30 --- /dev/null +++ b/internal/service/rsync_log_test.go @@ -0,0 +1,79 @@ +package service + +import ( + "context" + "os" + "path/filepath" + "strings" + "testing" + "time" + + "git.casaderoll.de/michael/urbm/internal/model" + "git.casaderoll.de/michael/urbm/internal/queue" + "git.casaderoll.de/michael/urbm/internal/rsync" +) + +func TestRsyncSummaryDistinguishesDryRun(t *testing.T) { + for _, dry := range []bool{true, false} { + run := model.Run{TaskType: "rsync", RsyncDryRun: dry} + summary := rsync.Summary{Files: 1376, Deleted: 1214, Bytes: 1234567890} + applyRsyncSummary(&run, summary) + logRsyncSummary(&run, summary) + message := notificationMessage("Mirror", "", run, time.Now()) + for _, expected := range []string{"1376", "1214", "1.1 GiB"} { + if !strings.Contains(message, expected) || !strings.Contains(strings.Join(run.LiveLog, "\n"), expected) { + t.Fatalf("missing %s: %s %v", expected, message, run.LiveLog) + } + } + if dry { + if run.BytesAdded != 0 || !strings.Contains(message, "würden") || !strings.Contains(message, "keine Änderungen vorgenommen") || strings.Contains(message, "⚠️") { + t.Fatal(message) + } + } else if run.BytesAdded != summary.Bytes || strings.Contains(message, "würden") { + t.Fatal(message) + } + } +} + +func TestExecuteRsyncLogsSetupSamplesAndErrors(t *testing.T) { + for _, fail := range []bool{false, true} { + dir := t.TempDir() + source, target := filepath.Join(dir, "source"), filepath.Join(dir, "target") + for _, path := range []string{source, target} { + if err := os.Mkdir(path, 0700); err != nil { + t.Fatal(err) + } + } + binary := filepath.Join(dir, "rsync") + script := "#!/bin/sh\ncase \" $* \" in *' --dry-run '*) ;; *) exit 99;; esac\n" + if fail { + script += "echo 'test failure' >&2\nexit 23\n" + } else { + script += "i=0; while [ $i -lt 25 ]; do printf 'CHANGE|>f+++++++++|source/file%s\\n' \"$i\"; i=$((i+1)); done\nprintf '%s\\n' 'Number of regular files transferred: 25' 'Number of deleted files: 3 (reg: 3)' 'Total transferred file size: 123456 bytes'\n" + } + if err := os.WriteFile(binary, []byte(script), 0700); err != nil { + t.Fatal(err) + } + job := model.Job{ID: "mirror", Sources: []model.Source{{Path: source}}, Rsync: model.RsyncOptions{Target: target, DryRun: true, Overwrite: true, Delete: true, Checksum: true}} + s := &Service{config: model.Config{Jobs: []model.Job{job}}, rsync: &rsync.Runner{Binary: binary}, queue: queue.New(nil, nil)} + result := s.executeRsync(context.Background(), model.Run{ID: "run", JobID: job.ID, TaskType: "rsync"}) + log := strings.Join(result.LiveLog, "\n") + for _, expected := range []string{"Testlauf", "Quelle: " + source, "Ziel: " + target, "Löschen: an", "Prüfsumme"} { + if !strings.Contains(log, expected) { + t.Fatalf("missing %s: %s", expected, log) + } + } + if fail { + if result.Status != "failed" || !strings.Contains(log, "test failure") { + t.Fatal(result) + } + } else { + if result.Status != "success" || result.BytesAdded != 0 || result.BytesProcessed != 123456 || result.EntriesDeleted != 3 { + t.Fatal(result) + } + if strings.Count(log, "Geplant: Neu") != 20 || !strings.Contains(log, "Weitere Einzeländerungen ausgeblendet") || !strings.Contains(log, "25 Dateien würden") { + t.Fatal(log) + } + } + } +} diff --git a/internal/service/service.go b/internal/service/service.go index 771655a..ab58d12 100644 --- a/internal/service/service.go +++ b/internal/service/service.go @@ -1135,13 +1135,20 @@ func (s *Service) executeRsync(ctx context.Context, run model.Run) (result model if !ok { return failed(run, "validation", "job no longer exists") } + run.RsyncDryRun = job.Rsync.DryRun defer func() { result = s.finishJob(run, job, result) }() + live := run + logRsyncSetup(&live, job) + defer func() { + if result.Status == "failed" || result.Status == "cancelled" { + appendLiveLog(&live, "Rsync abgebrochen/fehlgeschlagen: "+result.Message) + } + result.LiveLog = live.LiveLog + }() + s.updateActive(live) if err := platform.ValidateRsyncPaths(job); err != nil { return failedError(run, err) } - live := run - appendLiveLog(&live, fmt.Sprintf("Rsync-Kopie wird vorbereitet: %d Quelle(n) nach %s", len(job.Sources), job.Rsync.Target)) - s.updateActive(live) for _, source := range job.Sources { if _, err := os.Stat(source.Path); err != nil { return failed(run, "source", "source unavailable: "+source.Path) @@ -1154,7 +1161,7 @@ func (s *Service) executeRsync(ctx context.Context, run model.Run) (result model return failed(run, "environment", "rsync target unavailable: "+err.Error()) } if !job.Rsync.DryRun && !job.Rsync.SkipSpaceCheck { - appendLiveLog(&live, "Rsync-Vorabprüfung ermittelt den tatsächlich zu übertragenden Datenumfang") + appendLiveLog(&live, "Speicherplatz-Vorabprüfung: rsync vergleicht Quellen und Ziel ohne Änderungen; bei großen Verzeichnissen kann dies dauern") s.updateActive(live) estimate, err := s.rsync.Estimate(ctx, run.ID, job) if err != nil { @@ -1170,6 +1177,14 @@ func (s *Service) executeRsync(ctx context.Context, run model.Run) (result model return failed(run, "environment", fmt.Sprintf("Rsync-Ziel hat nicht genügend freien Speicher: ungefähr %s für %d Dateien erforderlich, aber nur %s frei unter %s", formatBytes(estimate.Bytes), estimate.Files, formatBytes(available), job.Rsync.Target)) } } + if job.Rsync.DryRun { + appendLiveLog(&live, "Speicherplatz-Vorabprüfung entfällt beim Testlauf") + } else if job.Rsync.SkipSpaceCheck { + appendLiveLog(&live, "Speicherplatz-Vorabprüfung laut Job-Einstellung übersprungen") + } + appendLiveLog(&live, "Rsync startet den Dateivergleich; Änderungen werden als Stichprobe protokolliert (max. 20 Einträge)") + s.updateActive(live) + changesLogged := 0 started := time.Now() lastLoggedPercent := -10 summary, err := s.rsync.Run(ctx, run.ID, job, func(progress rsync.Progress) { @@ -1184,28 +1199,37 @@ func (s *Service) executeRsync(ctx context.Context, run model.Run) (result model } percent := int(progress.Percent) if percent >= lastLoggedPercent+10 { - appendLiveLog(&live, fmt.Sprintf("Rsync-Fortschritt: %.0f%%, %s übertragen", progress.Percent, formatBytes(progress.Bytes))) + if job.Rsync.DryRun { + appendLiveLog(&live, fmt.Sprintf("Testlauf-Fortschritt: %.0f%% (keine Übertragung)", progress.Percent)) + } else { + appendLiveLog(&live, fmt.Sprintf("Rsync-Fortschritt: %.0f%%, %s übertragen", progress.Percent, formatBytes(progress.Bytes))) + } lastLoggedPercent = percent - percent%10 } } if progress.CurrentFile != "" { live.CurrentFile = progress.CurrentFile + if changesLogged < 20 { + prefix := "Änderung: " + if job.Rsync.DryRun { + prefix = "Geplant: " + } + appendLiveLog(&live, prefix+rsyncChangeLabel(progress.Change)+" · "+progress.CurrentFile) + } else if changesLogged == 20 { + appendLiveLog(&live, "Weitere Einzeländerungen ausgeblendet; die Zusammenfassung zählt alle Dateien und Löschungen") + } + changesLogged++ } s.updateActive(live) }) if err != nil { - appendLiveLog(&live, "Rsync-Kopie fehlgeschlagen: "+err.Error()) - failedRun := failedError(run, err) - failedRun.LiveLog = live.LiveLog - return failedRun + return failedError(run, err) } - run.Status, run.Message = "success", "rsync completed" - run.BytesAdded, run.BytesProcessed = summary.Bytes, summary.Bytes - run.FilesNew, run.FilesProcessed = summary.Files, summary.Files + applyRsyncSummary(&run, summary) run.ProgressPercent, run.ProgressBytes, run.ProgressTotal = 100, summary.Bytes, summary.Bytes run.ProgressFiles, run.ProgressFileTotal = summary.Files, summary.Files run.BytesPerSecond, run.CurrentFile = live.BytesPerSecond, live.CurrentFile - appendLiveLog(&live, fmt.Sprintf("Rsync-Kopie abgeschlossen: %d Dateien, %s", summary.Files, formatBytes(summary.Bytes))) + logRsyncSummary(&live, summary) run.LiveLog = live.LiveLog return run } @@ -1447,6 +1471,7 @@ func diffKindLabel(kind string) string { func (s *Service) updateActive(run model.Run) { s.queue.UpdateActive(run.ID, func(active *model.Run) { + active.RsyncDryRun = run.RsyncDryRun active.ProgressPercent, active.ProgressBytes, active.ProgressTotal = run.ProgressPercent, run.ProgressBytes, run.ProgressTotal active.ProgressFiles, active.ProgressFileTotal = run.ProgressFiles, run.ProgressFileTotal active.BytesPerSecond, active.SecondsRemaining = run.BytesPerSecond, run.SecondsRemaining @@ -1592,6 +1617,9 @@ func notificationMessage(name, repository string, run model.Run, now time.Time) if status == "" { status = run.Status } + if run.TaskType == "rsync" && run.RsyncDryRun && run.Status == "success" { + status = "Testlauf erfolgreich – keine Änderungen vorgenommen" + } summaryTitle := map[string]string{"backup": "📊 Backup-Zusammenfassung", "rsync": "📊 Rsync-Zusammenfassung", "restore": "📊 Restore-Zusammenfassung", "prune": "🧹 Prune-Zusammenfassung", "check": "🔎 Prüfungs-Zusammenfassung"}[run.TaskType] if summaryTitle == "" { summaryTitle = "📊 URBM-Zusammenfassung" @@ -1615,19 +1643,29 @@ func notificationMessage(name, repository string, run model.Run, now time.Time) lines = append(lines, "", "⏱️ Dauer: "+formatDuration(duration)) } } - if (run.TaskType == "backup" || run.TaskType == "rsync") && (run.Status == "success" || run.Status == "warning") { + if run.TaskType == "backup" && (run.Status == "success" || run.Status == "warning") { lines = append(lines, fmt.Sprintf("📂 Dateien: %d verarbeitet", run.FilesProcessed), "💾 Verarbeitet: "+formatBytes(run.BytesProcessed), ) - if run.TaskType == "backup" { + lines = append(lines, + fmt.Sprintf("➕ Neu: %d Dateien", run.FilesNew), + fmt.Sprintf("✏️ Geändert: %d Dateien", run.FilesChanged), + "📤 Neu gespeichert: "+formatBytes(run.BytesAdded), + ) + } + if run.TaskType == "rsync" && (run.Status == "success" || run.Status == "warning") { + if run.RsyncDryRun { lines = append(lines, - fmt.Sprintf("➕ Neu: %d Dateien", run.FilesNew), - fmt.Sprintf("✏️ Geändert: %d Dateien", run.FilesChanged), - "📤 Neu gespeichert: "+formatBytes(run.BytesAdded), - ) + "🧪 Testlauf – keine Änderungen vorgenommen", + fmt.Sprintf("📂 Dateien würden kopiert/aktualisiert: %d", run.FilesProcessed), + "💾 Geplanter Dateiinhalt: "+formatBytes(run.BytesProcessed), + fmt.Sprintf("🗑️ Einträge würden gelöscht (inkl. Ordner/Symlinks): %d", run.EntriesDeleted)) } else { - lines = append(lines, "📤 Kopiert: "+formatBytes(run.BytesAdded)) + lines = append(lines, + fmt.Sprintf("📂 Dateien kopiert/aktualisiert: %d", run.FilesProcessed), + "📤 Kopierter Dateiinhalt: "+formatBytes(run.BytesAdded), + fmt.Sprintf("🗑️ Einträge gelöscht (inkl. Ordner/Symlinks): %d", run.EntriesDeleted)) } } if run.TaskType == "backup" && run.RetentionAfter > 0 { @@ -1646,7 +1684,7 @@ func notificationMessage(name, repository string, run model.Run, now time.Time) ) } lines = append(lines, "", "🔐 Ziel: "+notificationTargetLabel(run.TaskType), statusIcon(run.Status)+" Status: "+status) - if run.Message != "" && run.Message != run.TaskType+" completed" { + if run.Message != "" && run.Message != run.TaskType+" completed" && !(run.RsyncDryRun && run.Status == "success") { lines = append(lines, "⚠️ Details: "+run.Message) } return strings.Join(lines, "\n") diff --git a/plugin/urbm.plg b/plugin/urbm.plg index eab5511..54b927f 100644 --- a/plugin/urbm.plg +++ b/plugin/urbm.plg @@ -2,13 +2,20 @@ - + ]> +### 2026.09.27.r002 +- Collapse run logs by default and retain manually opened logs during refresh. +- Log Rsync sources, destination, comparison and deletion options, execution phases, sample changes, errors and final totals. +- Clearly distinguish dry-run plans from actual copies and include deleted entries in logs and notifications. +- Parse exact byte statistics for progress, summaries and free-space checks; drain process output before closing pipes. +- Test dry runs, copies and deletions with real Rsync fixtures as well as regression tests. + ### 2026.09.27.r001 - Discover mounted array disks as selectable Rsync sources, including complete disks. - Show directory symlinks only when they resolve within allowed storage roots. diff --git a/webgui/URBM.page b/webgui/URBM.page index 9c974a0..960c3ec 100644 --- a/webgui/URBM.page +++ b/webgui/URBM.page @@ -8,7 +8,7 @@ Tag="URBM Unraid Restic Backup Manager backup snapshots restore" --- diff --git a/webgui/assets/urbm.js b/webgui/assets/urbm.js index c1c92c3..5117d6c 100644 --- a/webgui/assets/urbm.js +++ b/webgui/assets/urbm.js @@ -813,7 +813,7 @@ const daemon=state.logs?.daemon||{}; const daemonLines=daemon.lines||[]; const daemonHint=daemon.error?`
${esc(daemon.error)}
`:`
${esc(daemon.path||'/var/log/urbm.log')}${daemon.truncatedLines?` · ${daemon.truncatedLines} ältere Zeilen ausgeblendet`:''}${daemon.truncatedBytes?` · Anfang wegen Größe gekürzt`:''}
`; - const runLogs=(state.logs?.runs||[]).map(run=>`
${esc(taskLabels[run.taskType]||run.taskType)} · ${esc(runTarget(run))} · ${esc(statusLabels[run.status]||run.status)} · ${esc(new Date(run.createdAt).toLocaleString())}
${esc((run.liveLog||[]).join('\n'))}
`).join(''); + const runLogs=(state.logs?.runs||[]).map(run=>`
${esc(run.rsyncDryRun?'Rsync-Testlauf':taskLabels[run.taskType]||run.taskType)} · ${esc(runTarget(run))} · ${esc(statusLabels[run.status]||run.status)} · ${esc(new Date(run.createdAt).toLocaleString())}
${esc((run.liveLog||[]).join('\n'))}
`).join(''); return `

Protokolle

Nur lesbare Diagnoseansicht. Secrets und Passwörter werden von URBM nicht geloggt.
${button('Aktualisieren','refresh-logs','primary')}
${state.logsLoading?'
Protokolle werden geladen…
':state.logsError?`
${esc(state.logsError)}
`:`

Daemon-Protokoll

${daemonHint}
${esc(daemonLines.join('\n'))}

Laufprotokolle

${runLogs||'
Keine gespeicherten Laufprotokolle vorhanden.
'}
`}`; } function progressView(run) { @@ -838,7 +838,7 @@ } function liveLogView(run) { if(!(run.liveLog||[]).length) return ''; - const open=Object.prototype.hasOwnProperty.call(state.liveLogOpen,run.id)?state.liveLogOpen[run.id]:run.status==='running'; + const open=Object.prototype.hasOwnProperty.call(state.liveLogOpen,run.id)?state.liveLogOpen[run.id]:false; return `
${run.status==='running'?'Live-Protokoll':'Laufprotokoll'} (${run.liveLog.length})
${esc(run.liveLog.join('\n'))}
`; } function runsTable(runs) {