From 02836151636409144411372a9cb67c4fdca9b27c Mon Sep 17 00:00:00 2001 From: Juergen Kellerer Date: Mon, 1 May 2023 16:17:21 +0200 Subject: [PATCH 1/2] Term: Refactored for async and ANSI status support Also moved reusable utils to utils package --- commands_display.go | 154 +++-------------- commands_display_test.go | 264 +--------------------------- integration_test.go | 18 +- logger.go | 142 +-------------- logger_test.go | 5 +- main.go | 3 + schedule/schedules_test.go | 23 +-- term/term.go | 322 ++++++++++++++++++++++++++++++----- term/term_test.go | 28 ++- util/ansi/colors.go | 41 +++++ util/ansi/colors_test.go | 19 +++ util/ansi/escape.go | 36 ++++ util/ansi/escape_test.go | 14 ++ util/ansi/linewriter.go | 110 ++++++++++++ util/ansi/linewriter_test.go | 283 ++++++++++++++++++++++++++++++ util/ansi/runes.go | 26 +++ util/ansi/runes_test.go | 40 +++++ util/filewriter.go | 222 ++++++++++++++++++++++++ util/filewriter_test.go | 3 + util/reader.go | 94 ++++++++++ util/reader_test.go | 3 + util/writer.go | 73 ++++++++ util/writer_test.go | 3 + wrapper_streamsource.go | 113 ++++++------ wrapper_test.go | 55 +++--- 25 files changed, 1405 insertions(+), 689 deletions(-) create mode 100644 util/ansi/colors.go create mode 100644 util/ansi/colors_test.go create mode 100644 util/ansi/escape.go create mode 100644 util/ansi/escape_test.go create mode 100644 util/ansi/linewriter.go create mode 100644 util/ansi/linewriter_test.go create mode 100644 util/ansi/runes.go create mode 100644 util/ansi/runes_test.go create mode 100644 util/filewriter.go create mode 100644 util/filewriter_test.go create mode 100644 util/reader.go create mode 100644 util/reader_test.go create mode 100644 util/writer.go create mode 100644 util/writer_test.go diff --git a/commands_display.go b/commands_display.go index e569c8148..7c64c8410 100644 --- a/commands_display.go +++ b/commands_display.go @@ -16,30 +16,19 @@ import ( "github.com/creativeprojects/resticprofile/filesearch" "github.com/creativeprojects/resticprofile/shell" "github.com/creativeprojects/resticprofile/term" + "github.com/creativeprojects/resticprofile/util/ansi" "github.com/creativeprojects/resticprofile/util/collect" - "github.com/fatih/color" - "github.com/mattn/go-colorable" ) -var ( - ansiBold = color.New(color.Bold).SprintFunc() - ansiCyan = color.New(color.FgCyan).SprintFunc() - ansiYellow = color.New(color.FgYellow).SprintFunc() -) - -func displayWriter(output io.Writer, flags commandLineFlags) (out func(args ...any) io.Writer, closer func()) { +func displayWriter(output io.Writer) (out func(args ...any) io.Writer, closer func()) { if term.GetOutput() == output { output = term.GetColorableOutput() if width, _ := term.OsStdoutTerminalSize(); width > 10 { - output = newLineLengthWriter(output, width) + output = ansi.NewLineLengthWriter(output, width) } } - if flags.noAnsi { - output = colorable.NewNonColorable(output) - } - w := tabwriter.NewWriter(output, 0, 0, 2, ' ', 0) out = func(args ...any) io.Writer { @@ -69,12 +58,12 @@ func getCommonUsageHelpLine(commandName string, withProfile bool) string { } return fmt.Sprintf( "%s [resticprofile flags] %s%s", - ansiBold("resticprofile"), profile, ansiBold(commandName), + ansi.Bold("resticprofile"), profile, ansi.Bold(commandName), ) } func displayOwnCommands(output io.Writer, request commandRequest) { - out, closer := displayWriter(output, request.flags) + out, closer := displayWriter(output) defer closer() for _, command := range request.ownCommands.commands { @@ -87,7 +76,7 @@ func displayOwnCommands(output io.Writer, request commandRequest) { } func displayOwnCommandHelp(output io.Writer, commandName string, request commandRequest) { - out, closer := displayWriter(output, request.flags) + out, closer := displayWriter(output) defer closer() var command *ownCommand @@ -131,7 +120,7 @@ func displayOwnCommandHelp(output io.Writer, commandName string, request command } func displayCommonUsageHelp(output io.Writer, request commandRequest) { - out, closer := displayWriter(output, request.flags) + out, closer := displayWriter(output) defer closer() out("resticprofile is a configuration profiles manager for backup profiles and ") @@ -141,21 +130,21 @@ func displayCommonUsageHelp(output io.Writer, request commandRequest) { out("\t%s [restic flags]\n", getCommonUsageHelpLine("restic-command", true)) out("\t%s [command specific flags]\n", getCommonUsageHelpLine("resticprofile-command", true)) out("\n") - out(ansiBold("resticprofile flags:\n")) + out(ansi.Bold("resticprofile flags:\n")) out(request.flags.usagesHelp) out("\n\n") - out(ansiBold("resticprofile own commands:\n")) + out(ansi.Bold("resticprofile own commands:\n")) displayOwnCommands(out(), request) out("\n") out("%s at %s\n", - ansiBold("Documentation available"), - ansiBold(ansiCyan("https://creativeprojects.github.io/resticprofile/"))) + ansi.Bold("Documentation available"), + ansi.Bold(ansi.Cyan("https://creativeprojects.github.io/resticprofile/"))) out("\n") } func displayResticHelp(output io.Writer, configuration *config.Config, flags commandLineFlags, command string) { - out, closer := displayWriter(output, flags) + out, closer := displayWriter(output) defer closer() // try to load the config @@ -196,7 +185,7 @@ func displayResticHelp(output io.Writer, configuration *config.Config, flags com } if configuration != nil { - out("\nFlags applied by resticprofile (configuration \"%s\"):\n\n", ansiBold(configuration.GetConfigFile())) + out("\nFlags applied by resticprofile (configuration \"%s\"):\n\n", ansi.Bold(configuration.GetConfigFile())) if profileNames := configuration.GetProfileNames(); len(profileNames) > 0 { profiles := configuration.GetProfiles() @@ -210,14 +199,14 @@ func displayResticHelp(output io.Writer, configuration *config.Config, flags com ) for _, name := range profileNames { - out("\tprofile \"%s\":", ansiBold(name)) + out("\tprofile \"%s\":", ansi.Bold(name)) profile := profiles[name] cmdFlags := config.GetNonConfidentialArgs(profile, profile.GetCommandFlags(command)) for _, flag := range cmdFlags.GetAll() { if strings.HasPrefix(flag, "-") { out("\n\t\t") } - out("%s\t", ansiCyan(unescaper.Replace(flag))) + out("%s\t", ansi.Cyan(unescaper.Replace(flag))) } out("\n") } @@ -230,7 +219,7 @@ func displayResticHelp(output io.Writer, configuration *config.Config, flags com func displayHelpCommand(output io.Writer, request commandRequest) error { flags := request.flags - out, closer := displayWriter(output, request.flags) + out, closer := displayWriter(output) defer closer() if flags.log == "" { @@ -259,10 +248,10 @@ func displayHelpCommand(output io.Writer, request commandRequest) error { } func displayVersion(output io.Writer, request commandRequest) error { - out, closer := displayWriter(output, request.flags) + out, closer := displayWriter(output) defer closer() - out("resticprofile version %s commit %s\n", ansiBold(version), ansiYellow(commit)) + out("resticprofile version %s commit %s\n", ansi.Bold(version), ansi.Yellow(commit)) // allow for the general verbose flag, or specified after the command if request.flags.verbose || (len(request.args) > 0 && (request.args[0] == "-v" || request.args[0] == "--verbose")) { @@ -282,7 +271,7 @@ func displayVersion(output io.Writer, request commandRequest) error { out("\t%s:\n", "go modules") bi, _ := debug.ReadBuildInfo() for _, dep := range bi.Deps { - out("\t\t%s\t%s\n", ansiCyan(dep.Path), dep.Version) + out("\t\t%s\t%s\n", ansi.Cyan(dep.Path), dep.Version) } out("\n") } @@ -296,7 +285,7 @@ func displayProfilesCommand(output io.Writer, request commandRequest) error { } func displayProfiles(output io.Writer, configuration *config.Config, flags commandLineFlags) { - out, closer := displayWriter(output, flags) + out, closer := displayWriter(output) defer closer() profiles := configuration.GetProfiles() @@ -304,14 +293,14 @@ func displayProfiles(output io.Writer, configuration *config.Config, flags comma if len(profiles) == 0 { out("\nThere's no available profile in the configuration\n") } else { - out("\n%s (name, sections, description):\n", ansiBold("Profiles available")) + out("\n%s (name, sections, description):\n", ansi.Bold("Profiles available")) for _, name := range keys { sections := profiles[name].DefinedCommands() sort.Strings(sections) if len(sections) == 0 { out("\t%s:\t(n/a)\t%s\n", name, profiles[name].Description) } else { - out("\t%s:\t(%s)\t%s\n", name, ansiCyan(strings.Join(sections, ", ")), profiles[name].Description) + out("\t%s:\t(%s)\t%s\n", name, ansi.Cyan(strings.Join(sections, ", ")), profiles[name].Description) } } } @@ -319,109 +308,16 @@ func displayProfiles(output io.Writer, configuration *config.Config, flags comma } func displayGroups(output io.Writer, configuration *config.Config, flags commandLineFlags) { - out, closer := displayWriter(output, flags) + out, closer := displayWriter(output) defer closer() groups := configuration.GetProfileGroups() if len(groups) == 0 { return } - out("%s (name, profiles, description):\n", ansiBold("Groups available")) + out("%s (name, profiles, description):\n", ansi.Bold("Groups available")) for name, groupList := range groups { - out("\t%s:\t[%s]\t%s\n", name, ansiCyan(strings.Join(groupList.Profiles, ", ")), groupList.Description) + out("\t%s:\t[%s]\t%s\n", name, ansi.Cyan(strings.Join(groupList.Profiles, ", ")), groupList.Description) } out("\n") } - -// lineLengthWriter limits the max line length, adding line breaks ('\n') as needed. -// the writer detects the right most column (consecutive whitespace) and aligns content if possible. -type lineLengthWriter struct { - writer io.Writer - tokens []byte - maxLineLength, lastWhite, breakLength, lineLength int - ansiLength, lastWhiteAnsiLength int -} - -func newLineLengthWriter(writer io.Writer, maxLineLength int) *lineLengthWriter { - return &lineLengthWriter{writer: writer, maxLineLength: maxLineLength} -} - -func (l *lineLengthWriter) Write(p []byte) (n int, err error) { - written := 0 - inAnsi := false - offset := l.lineLength - lineLength := func() int { return l.lineLength - l.ansiLength } - - if len(l.tokens) == 0 { - l.tokens = []byte{' ', '\n'} - } - - for i := 0; i < len(p); i++ { - l.lineLength++ - ws := p[i] == l.tokens[0] // ' ' - br := p[i] == l.tokens[1] // '\n' - - // don't count ansi control sequences - if inAnsi = inAnsi || p[i] == 0x1b; inAnsi { - inAnsi = p[i] != 'm' - l.ansiLength++ - continue - } - - if !br && lineLength() > l.maxLineLength && l.lastWhite-offset > 0 { - lastWhiteIndex := l.lastWhite - offset - 1 - remainder := i - lastWhiteIndex - - if written, err = l.writer.Write(p[:lastWhiteIndex]); err == nil { - p = p[lastWhiteIndex+1:] - i = remainder - 1 - n += written + 1 - - _, _ = l.writer.Write(l.tokens[1:]) // write break (instead of WS at lastWhiteIndex) - for j := 0; j < l.breakLength; j++ { - _, _ = l.writer.Write(l.tokens[0:1]) // fill spaces for alignment - } - - l.lineLength = l.breakLength + remainder - l.lastWhite = l.breakLength - offset = l.breakLength - - l.ansiLength -= l.lastWhiteAnsiLength - l.lastWhiteAnsiLength = 0 - } else { - return - } - } - - if ws { - if l.lastWhite == l.lineLength-1 && lineLength() < l.maxLineLength*2/3 { - l.breakLength = lineLength() - } - l.lastWhite = l.lineLength - l.lastWhiteAnsiLength = l.ansiLength - - } else if br { - if written, err = l.writer.Write(p[:i+1]); err == nil { - p = p[i+1:] - i = -1 - n += written - - l.lineLength = 0 - l.lastWhite = 0 - l.breakLength = 0 - offset = 0 - - l.ansiLength = 0 - l.lastWhiteAnsiLength = 0 - } else { - return - } - } - } - - // write remainder - if written, err = l.writer.Write(p); err == nil { - n += written - } - return -} diff --git a/commands_display_test.go b/commands_display_test.go index d6c2efaeb..b6ce1fb71 100644 --- a/commands_display_test.go +++ b/commands_display_test.go @@ -2,8 +2,6 @@ package main import ( "bytes" - "fmt" - "strings" "testing" "github.com/fatih/color" @@ -19,279 +17,33 @@ var ansiColor = func() (c *color.Color) { var colored = ansiColor.SprintFunc() func TestDisplayWriter(t *testing.T) { - flags, noAnsiFlags := commandLineFlags{}, commandLineFlags{noAnsi: true} - buffer := bytes.Buffer{} - write := func(clf commandLineFlags, v ...any) string { + write := func(v ...any) string { buffer.Reset() - out, closer := displayWriter(&buffer, clf) + out, closer := displayWriter(&buffer) out(v...) closer() return buffer.String() } t.Run("write-plain", func(t *testing.T) { - actual := write(flags, "hello %s %d") + actual := write("hello %s %d") assert.Equal(t, "hello %s %d", actual) }) t.Run("write-with-format", func(t *testing.T) { - actual := write(flags, "hello %s %02d", "world", 5) + actual := write("hello %s %02d", "world", 5) assert.Equal(t, "hello world 05", actual) }) t.Run("write-tabs", func(t *testing.T) { - actual := write(flags, "col1\tcol2\tcol3\nvalue1\tvalue2\tvalue3") + actual := write("col1\tcol2\tcol3\nvalue1\tvalue2\tvalue3") assert.Equal(t, "col1 col2 col3\nvalue1 value2 value3", actual) }) - t.Run("no-ansi", func(t *testing.T) { - actual := write(flags, colored("test")) + t.Run("ansi", func(t *testing.T) { + actual := write(colored("test")) assert.Equal(t, colored("test"), actual) - - actual = write(noAnsiFlags, colored("test")) - assert.Equal(t, "test", actual) + assert.Contains(t, colored("test"), "\x1b[") }) } - -func TestLineLengthWriter(t *testing.T) { - tests := []struct { - input, expected string - chunks, scale int - }{ - // test non-breakable - {input: strings.Repeat("-", 50), expected: strings.Repeat("-", 50), chunks: 15}, - - // test breakable without columns - { - input: strings.Repeat("word ", 20), - expected: "" + - strings.TrimSpace(strings.Repeat("word ", 8)) + "\n" + - strings.TrimSpace(strings.Repeat("word ", 8)) + "\n" + - strings.Repeat("word ", 4), - chunks: 5, scale: 6, - }, - - // test breakable with ANSI color - { - input: strings.Repeat(colored("word "), 20), - expected: "" + - strings.Repeat(colored("word "), 7) + colored("word\n") + - strings.Repeat(colored("word "), 7) + colored("word\n") + - strings.Repeat(colored("word "), 4), - }, - - // test breakable with 2 columns - { - input: "word word word word " + - strings.Repeat("word ", 20), - expected: "" + - "word word word word " + - "word word word\n" + - strings.Repeat(" word word word\n", 5) + - " word word ", - chunks: 3, scale: 15, - }, - - // test breakable with 2 columns and ANSI color - { - input: colored("word word word word ") + - strings.Repeat(colored("word "), 20), - expected: "" + - colored("word word word word ") + - colored("word ") + colored("word ") + colored("word\n ") + - strings.Repeat(colored("word ")+colored("word ")+colored("word\n "), 5) + - colored("word ") + colored("word "), - }, - - // test real-world content - { - input: ` -Usage of resticprofile: - resticprofile [resticprofile flags] [profile name.][restic command] [restic flags] - resticprofile [resticprofile flags] [profile name.][resticprofile command] [command specific flags] - -resticprofile flags: - -c, --config string configuration file (default "profiles") - --dry-run display the restic commands instead of running them - -f, --format string file format of the configuration (default is to use the file extension) - -h, --help display this help - --lock-wait duration wait up to duration to acquire a lock (syntax "1h5m30s") - -l, --log string logs to a target instead of the console - -n, --name string profile name (default "default") - --no-ansi disable ansi control characters (disable console colouring) - --no-lock skip profile lock file - --no-prio don't set any priority on load: used when started from a service that has already set the priority - -q, --quiet display only warnings and errors - --theme string console colouring theme (dark, light, none) (default "light") - --trace display even more debugging information - -v, --verbose display some debugging information - -w, --wait wait at the end until the user presses the enter key - - -resticprofile own commands: - help display help (run in verbose mode for detailed information) - version display version (run in verbose mode for detailed information) - self-update update to latest resticprofile (use -q/--quiet flag to update without confirmation) - profiles display profile names from the configuration file - show show all the details of the current profile - schedule schedule jobs from a profile (use --all flag to schedule all jobs of all profiles) - unschedule remove scheduled jobs of a profile (use --all flag to unschedule all profiles) - status display the status of scheduled jobs (use --all flag for all profiles) - generate generate resources (--random-key [size], --bash-completion & --zsh-completion) - -Documentation available at https://creativeprojects.github.io/resticprofile/ -`, - expected: ` -Usage of resticprofile: - resticprofile [resticprofile flags] - [profile name.][restic command] - [restic flags] - resticprofile [resticprofile flags] - [profile name.][resticprofile - command] [command specific flags] - -resticprofile flags: - -c, --config string - configuration - file (default - "profiles") - --dry-run display - the restic - commands - instead of - running them - -f, --format string file - format of the - configuration - (default is to - use the file - extension) - -h, --help display - this help - --lock-wait duration wait up to - duration to acquire a lock - (syntax "1h5m30s") - -l, --log string logs to a - target instead - of the console - -n, --name string profile - name (default - "default") - --no-ansi disable - ansi control - characters - (disable - console - colouring) - --no-lock skip - profile lock - file - --no-prio don't set - any priority - on load: used - when started - from a service - that has - already set - the priority - -q, --quiet display - only warnings - and errors - --theme string console - colouring - theme (dark, - light, none) - (default - "light") - --trace display - even more - debugging - information - -v, --verbose display - some debugging - information - -w, --wait wait at - the end until - the user - presses the - enter key - - -resticprofile own commands: - help display help (run in - verbose mode for - detailed information) - version display version (run - in verbose mode for - detailed information) - self-update update to latest - resticprofile (use - -q/--quiet flag to - update without - confirmation) - profiles display profile names - from the configuration - file - show show all the details - of the current profile - schedule schedule jobs from a - profile (use --all - flag to schedule all - jobs of all profiles) - unschedule remove scheduled jobs - of a profile (use - --all flag to - unschedule all - profiles) - status display the status of - scheduled jobs (use - --all flag for all - profiles) - generate generate resources - (--random-key [size], - --bash-completion & - --zsh-completion) - -Documentation available at -https://creativeprojects.github.io/resticprofile/ -`, - }, - } - - for i, test := range tests { - if test.scale == 0 { - test.scale = 1 - } - for chunkSize := 0; chunkSize <= test.chunks; chunkSize++ { - t.Run(fmt.Sprintf("%d-%d", i, chunkSize), func(t *testing.T) { - buffer := bytes.Buffer{} - writer := newLineLengthWriter(&buffer, 40) - input := []byte(test.input) - - var ( - n int - err error - ) - switch chunkSize { - case 0: - n, err = writer.Write(input) - assert.Equal(t, len(input), n) - default: - for len(input) > 0 && err == nil { - length := test.scale * chunkSize - if length > len(input) { - length = len(input) - } - n, err = writer.Write(input[:length]) - assert.Equal(t, length, n) - input = input[length:] - } - } - - assert.Nil(t, err) - assert.Equal(t, test.expected, buffer.String()) - }) - } - } -} diff --git a/integration_test.go b/integration_test.go index c053f1549..89837dfa4 100644 --- a/integration_test.go +++ b/integration_test.go @@ -1,8 +1,6 @@ package main import ( - "bytes" - "os" "os/exec" "path/filepath" "runtime" @@ -146,12 +144,12 @@ func TestFromConfigFileToCommandLine(t *testing.T) { fixture.cmdlineArgs, nil, ) - buffer := &bytes.Buffer{} + // setting the output via the package global setter could lead to some issues // when some tests are running in parallel. I should fix that at some point :-/ - term.SetOutput(buffer) + term.StartRecording(term.RecordOutput) err = wrapper.runCommand(fixture.commandName) - term.SetOutput(os.Stdout) + stdout := term.StopRecording() require.NoError(t, err) @@ -163,7 +161,7 @@ func TestFromConfigFileToCommandLine(t *testing.T) { t.SkipNow() } } - assert.Equal(t, expected, strings.TrimSpace(buffer.String())) + assert.Equal(t, expected, strings.TrimSpace(stdout)) }) if runtime.GOOS == "windows" { @@ -187,16 +185,16 @@ func TestFromConfigFileToCommandLine(t *testing.T) { fixture.cmdlineArgs, nil, ) - buffer := &bytes.Buffer{} + // setting the output via the package global setter could lead to some issues // when some tests are running in parallel. I should fix that at some point :-/ - term.SetOutput(buffer) + term.StartRecording(term.RecordOutput) err = wrapper.runCommand(fixture.commandName) - term.SetOutput(os.Stdout) + content := term.StopRecording() require.NoError(t, err) - assert.Equal(t, fixture.legacy, strings.TrimSpace(buffer.String())) + assert.Equal(t, fixture.legacy, strings.TrimSpace(content)) }) } }) diff --git a/logger.go b/logger.go index 19196a71a..edd5c7d65 100644 --- a/logger.go +++ b/logger.go @@ -6,7 +6,6 @@ import ( "os" "path/filepath" "strings" - "time" "github.com/creativeprojects/clog" "github.com/creativeprojects/resticprofile/constants" @@ -81,9 +80,8 @@ func getFileHandler(flags commandLineFlags) (*clog.StandardLogHandler, io.Writer } // create a platform aware log file appender - keepOpen, appender := true, appendFunc(nil) + var appender util.AsyncFileWriterAppendFunc if platform.IsWindows() { - keepOpen = false appender = func(dst []byte, c byte) []byte { switch c { case '\n': @@ -95,7 +93,11 @@ func getFileHandler(flags commandLineFlags) (*clog.StandardLogHandler, io.Writer } } - writer, err := newDeferredFileWriter(flags.log, keepOpen, appender) + writer, err := util.NewAsyncFileWriter( + flags.log, + util.WithAsyncFileAppendFunc(appender), + util.WithAsyncFilePerm(0644), + ) if err != nil { return nil, nil, err } @@ -140,135 +142,3 @@ func changeLevelFilter(level clog.LogLevel) { filter.SetLevel(level) } } - -// deferredFileWriter accumulates Write requests and writes them at a fixed rate (every 250 ms) -type deferredFileWriter struct { - done, flush chan chan error - data chan []byte -} - -func (d *deferredFileWriter) Close() error { - req := make(chan error) - d.done <- req - return <-req -} - -func (d *deferredFileWriter) Flush() error { - req := make(chan error) - d.flush <- req - return <-req -} - -func (d *deferredFileWriter) Write(data []byte) (n int, _ error) { - c := make([]byte, len(data)) - n = copy(c, data) - d.data <- c - return -} - -type appendFunc func(dst []byte, c byte) []byte - -func newDeferredFileWriter(filename string, keepOpen bool, appender appendFunc) (io.WriteCloser, error) { - d := &deferredFileWriter{ - flush: make(chan chan error), - done: make(chan chan error), - data: make(chan []byte, 64), - } - - var ( - buffer []byte - lastError error - file *os.File - ) - - closeFile := func() { - if file != nil { - lastError = file.Close() - file = nil - } - } - - flush := func(alsoEmpty bool) { - if len(buffer) == 0 && !alsoEmpty { - return - } - if file == nil { - file, lastError = os.OpenFile(filename, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0644) - } - if file != nil { - var written int - written, lastError = file.Write(buffer) - if written == len(buffer) { - buffer = buffer[:0] - } else { - buffer = buffer[written:] - } - } - if keepOpen { - _ = file.Sync() - } else { - closeFile() - } - } - - // test if we can create the file - buffer = make([]byte, 0, 4096) - flush(true) - - // data appending - addToBuffer := func(data []byte) { - buffer = append(buffer, data...) // fast path - } - if appender != nil { - addToBuffer = func(data []byte) { - for _, c := range data { - buffer = appender(buffer, c) - } - } - } - - addPendingData := func(max int) { - for ; max > 0; max-- { - select { - case data, ok := <-d.data: - if ok { - addToBuffer(data) - } else { - return // closed - } - default: - return // no-more-data - } - } - } - - // data transport - go func() { - ticker := time.NewTicker(250 * time.Millisecond) - defer ticker.Stop() - - for { - select { - case data := <-d.data: - addToBuffer(data) - case <-ticker.C: - flush(false) - case req := <-d.flush: - addPendingData(1024) - flush(false) - req <- lastError - case req := <-d.done: - close(d.done) - close(d.flush) - close(d.data) - addPendingData(1024) - flush(false) - closeFile() - req <- lastError - return - } - } - }() - - return d, lastError -} diff --git a/logger_test.go b/logger_test.go index 5e8971777..5b5be02e3 100644 --- a/logger_test.go +++ b/logger_test.go @@ -10,7 +10,6 @@ import ( "github.com/creativeprojects/clog" "github.com/creativeprojects/resticprofile/constants" - "github.com/creativeprojects/resticprofile/term" "github.com/creativeprojects/resticprofile/util" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -53,8 +52,8 @@ func TestFileHandler(t *testing.T) { require.NoError(t, err) defer handler.Close() - require.Implements(t, (*term.Flusher)(nil), writer) - flusher := writer.(term.Flusher) + require.Implements(t, (*util.Flusher)(nil), writer) + flusher := writer.(util.Flusher) log := func(line string) { assert.NoError(t, handler.LogEntry(clog.LogEntry{Level: clog.LevelInfo, Format: line})) diff --git a/main.go b/main.go index d0ea2e37c..8e34d5858 100644 --- a/main.go +++ b/main.go @@ -84,6 +84,9 @@ func main() { return } + // Configure terminal color + term.EnableColorableOutput(!flags.noAnsi) + // setting up the logger - we can start logging right after if flags.isChild { // use a remote logger diff --git a/schedule/schedules_test.go b/schedule/schedules_test.go index 5d3712470..b613b0bea 100644 --- a/schedule/schedules_test.go +++ b/schedule/schedules_test.go @@ -1,8 +1,6 @@ package schedule import ( - "bytes" - "os" "os/exec" "runtime" "testing" @@ -38,12 +36,11 @@ func TestDisplayParseSchedules(t *testing.T) { events, err := parseSchedules([]string{"daily"}) assert.NoError(t, err) - buffer := &bytes.Buffer{} - term.SetOutput(buffer) - defer term.SetOutput(os.Stdout) + term.StartRecording(term.RecordOutput) + defer term.StopRecording() displayParsedSchedules("command", events) - output := buffer.String() + output := term.ReadRecording() assert.Contains(t, output, "Original form: daily\n") assert.Contains(t, output, "Normalized form: *-*-* 00:00:00\n") } @@ -52,12 +49,11 @@ func TestDisplayParseSchedulesIndexAndTotal(t *testing.T) { events, err := parseSchedules([]string{"daily", "monthly", "yearly"}) assert.NoError(t, err) - buffer := &bytes.Buffer{} - term.SetOutput(buffer) - defer term.SetOutput(os.Stdout) + term.StartRecording(term.RecordOutput) + defer term.StopRecording() displayParsedSchedules("command", events) - output := buffer.String() + output := term.ReadRecording() assert.Contains(t, output, "schedule 1/3") assert.Contains(t, output, "schedule 2/3") assert.Contains(t, output, "schedule 3/3") @@ -74,14 +70,13 @@ func TestDisplaySystemdSchedules(t *testing.T) { t.Skip("systemd-analyze not available") } - buffer := &bytes.Buffer{} - term.SetOutput(buffer) - defer term.SetOutput(os.Stdout) + term.StartRecording(term.RecordOutput) + defer term.StopRecording() err = displaySystemdSchedules("command", []string{"daily"}) assert.NoError(t, err) - output := buffer.String() + output := term.ReadRecording() assert.Contains(t, output, "Original form: daily") assert.Contains(t, output, "Normalized form: *-*-* 00:00:00") } diff --git a/term/term.go b/term/term.go index 6077963db..6392ee6ce 100644 --- a/term/term.go +++ b/term/term.go @@ -2,25 +2,151 @@ package term import ( "bufio" + "bytes" "fmt" "io" "os" "strings" "sync" + "sync/atomic" + "time" + "github.com/creativeprojects/resticprofile/util" + "github.com/creativeprojects/resticprofile/util/ansi" "github.com/mattn/go-colorable" "golang.org/x/crypto/ssh/terminal" ) var ( - terminalOutput io.Writer = os.Stdout - errorOutput io.Writer = os.Stderr + termOutput atomic.Pointer[io.Writer] + errorOutput atomic.Pointer[io.Writer] + colorOutput atomic.Pointer[io.Writer] + enableColors atomic.Bool + statusChannel = make(chan []string) + statusWaitChannel = make(chan chan bool) ) -// Flusher allows a Writer to declare it may buffer content that can be flushed -type Flusher interface { - // Flush writes any pending bytes to output - Flush() error +const ( + StatusFPS = 10 +) + +func init() { + enableColors.Store(true) + go handleStatus() + // must be last + { + setOutput(os.Stdout) + setErrorOutput(os.Stderr) + } +} + +func handleStatus() { + ticker := time.NewTicker(time.Second / StatusFPS) + defer ticker.Stop() + + var waiting []chan bool + respondWaiting := func(result bool) { + for _, request := range waiting { + request <- result + close(request) + } + waiting = nil + } + defer respondWaiting(false) + + var newStatus, status []string + buffer := &bytes.Buffer{} + for { + select { + case lines := <-statusChannel: + newStatus = lines + + case request := <-statusWaitChannel: + waiting = append(waiting, request) + + case <-ticker.C: + if status != nil && OutputIsTerminal() { + width, height := OsStdoutTerminalSize() + noAnsi := !IsColorableOutput() + if height < 1 { + continue + } else if noAnsi { + newStatus = newStatus[1:] // strip first empty line + height = 1 + } + if width >= 60 { + width -= 2 + } else if width >= 80 { + width -= 4 // right margin + } + + last := truncate(status, height) + printable := truncate(newStatus, height) + removedLines := len(last) - len(printable) + if removedLines > 0 { + filler := make([]string, removedLines, removedLines+len(printable)) + printable = append(filler, printable...) + } + + if len(printable) > 0 { + buffer.Reset() + for index, line := range printable { + runes := []rune(strings.ReplaceAll(line, "\n", " ")) + _, maxIndex := ansi.RunesLength(runes, width) + runes = truncate(runes, maxIndex) + + if noAnsi { + if remaining := width - len(runes); remaining > 0 { + for remaining > 0 { + runes = append(runes, ' ') + remaining-- + } + } + _, _ = fmt.Fprintf(buffer, "\r%s\r", string(runes)) + } else { + eol := "\n" + if index+1 == len(printable) { + eol = "\r" + } + _, _ = fmt.Fprintf(buffer, "\r%s%s%s%s", ansi.ClearLine, string(runes), ansi.Reset, eol) + } + } + + if !noAnsi { + buffer.WriteString(ansi.CursorUpLeftN(len(printable) - 1)) + } + + _, _ = buffer.WriteTo(GetColorableOutput()) + buffer.Reset() + } + } + status = newStatus + respondWaiting(true) + } + } +} + +func truncate[E any](src []E, maxLength int) []E { + if len(src) > maxLength { + return src[:maxLength] + } + return src +} + +// SetStatus sets a status line(s) that is printed when the output is an interactive terminal +func SetStatus(line []string) { + // Clone lines and add empty line on top (= cursor position after printing status) + if line != nil { + line = append([]string{""}, line...) + } + statusChannel <- line +} + +// WaitForStatus blocks until the previously provided status was applied +func WaitForStatus() bool { + request := make(chan bool, 1) + statusWaitChannel <- request + return <-request } // AskYesNo prompts the user for a message asking for a yes/no answer @@ -37,7 +163,7 @@ func AskYesNo(reader io.Reader, message string, defaultAnswer bool) bool { question = "(y/N)" input = "n" } - fmt.Printf("%s %s: ", message, question) + _, _ = Printf("%s %s: ", message, question) scanner := bufio.NewScanner(reader) if scanner.Scan() { input = strings.TrimSpace(strings.ToLower(scanner.Text())) @@ -82,11 +208,18 @@ func ReadLine() (string, error) { // OsStdoutIsTerminal returns true as os.Stdout is a terminal session func OsStdoutIsTerminal() bool { - fd := int(os.Stdout.Fd()) + return isTerminal(os.Stdout) +} + +func isTerminal(file *os.File) bool { + if file == nil { + return false + } + fd := int(file.Fd()) return terminal.IsTerminal(fd) } -// OsStdoutIsTerminal returns true as os.Stdout is a terminal session +// OsStdoutTerminalSize returns the width and height of the terminal session func OsStdoutTerminalSize() (width, height int) { fd := int(os.Stdout.Fd()) var err error @@ -97,87 +230,184 @@ func OsStdoutTerminalSize() (width, height int) { return } -type LockedWriter struct { - writer io.Writer - mutex *sync.Mutex -} - -func (w *LockedWriter) Write(p []byte) (n int, err error) { - w.mutex.Lock() - defer w.mutex.Unlock() - return w.writer.Write(p) +// OutputIsTerminal returns true if GetOutput sends to an interactive terminal +func OutputIsTerminal() bool { + return GetOutput() == os.Stdout && OsStdoutIsTerminal() } -func (w *LockedWriter) Flush() (err error) { - w.mutex.Lock() - defer w.mutex.Unlock() - if f, ok := w.writer.(Flusher); ok { - err = f.Flush() +// SetOutput changes the default output for the Print* functions +func SetOutput(w io.Writer) { + if w == os.Stdout && isTerminal(os.Stdout) { + setOutput(os.Stdout) + } else { + setOutput(util.NewSyncWriter(w)) } - return } -// SetOutput changes the default output for the Print* functions -func SetOutput(w io.Writer) { - terminalOutput = &LockedWriter{writer: w, mutex: new(sync.Mutex)} +func setOutput(w io.Writer) { + if w == nil { + w = io.Discard + } + termOutput.Store(util.CopyRef[io.Writer](w)) + colorOutput.Store(nil) + SetStatus(nil) } // GetOutput returns the default output of the Print* functions -func GetOutput() io.Writer { - return terminalOutput +func GetOutput() (out io.Writer) { + if v := termOutput.Load(); v != nil { + out = *v + } + return } // GetColorableOutput returns an output supporting ANSI color if output is a terminal -func GetColorableOutput() io.Writer { - out := GetOutput() - if out == os.Stdout && OsStdoutIsTerminal() { - return colorable.NewColorable(os.Stdout) +func GetColorableOutput() (out io.Writer) { + if v := colorOutput.Load(); v != nil { + out = *v + } + if out == nil { + if IsColorableOutput() { + out = colorable.NewColorable(os.Stdout) + } else { + out = colorable.NewNonColorable(GetOutput()) + } + colorOutput.Store(util.CopyRef[io.Writer](out)) } - return colorable.NewNonColorable(out) + return out +} + +// EnableColorableOutput toggles whether GetColorableOutput supports ANSI color or discards ANSI +func EnableColorableOutput(enable bool) { + if enableColors.CompareAndSwap(!enable, enable) { + colorOutput.Store(nil) + } +} + +// IsColorableOutput tells whether GetColorableOutput supports ANSI color (and control characters) or discards ANSI +func IsColorableOutput() bool { + return enableColors.Load() && OutputIsTerminal() } // SetErrorOutput changes the error output for the Print* functions func SetErrorOutput(w io.Writer) { - errorOutput = &LockedWriter{writer: w, mutex: new(sync.Mutex)} + if w == os.Stderr && isTerminal(os.Stderr) { + setErrorOutput(os.Stderr) + } else { + setErrorOutput(util.NewSyncWriter(w)) + } +} + +func setErrorOutput(w io.Writer) { + if w == nil { + w = io.Discard + } + errorOutput.Store(util.CopyRef[io.Writer](w)) } // GetErrorOutput returns the error output of the Print* functions -func GetErrorOutput() io.Writer { - return errorOutput +func GetErrorOutput() (out io.Writer) { + if v := errorOutput.Load(); v != nil { + out = *v + } + return } // SetAllOutput changes the default and error output for the Print* functions func SetAllOutput(w io.Writer) { - single := new(sync.Mutex) - terminalOutput = &LockedWriter{writer: w, mutex: single} - errorOutput = &LockedWriter{writer: w, mutex: single} + SetOutput(w) + setErrorOutput(GetOutput()) } // FlushAllOutput flushes all buffered output (if supported by the underlying Writer). func FlushAllOutput() { - for _, writer := range []io.Writer{terminalOutput, errorOutput} { - if f, ok := writer.(Flusher); ok { - _ = f.Flush() + for _, writer := range []io.Writer{GetOutput(), GetErrorOutput()} { + _, _ = util.FlushWriter(writer) + } +} + +var recording = struct { + lock sync.Mutex + buffer *bytes.Buffer + writer io.Writer + output, error io.Writer +}{} + +type RecordMode uint8 + +const ( + RecordOutput RecordMode = iota + RecordError + RecordBoth +) + +func StartRecording(mode RecordMode) { + recording.lock.Lock() + defer recording.lock.Unlock() + if recording.buffer != nil { + return + } + + recording.buffer = new(bytes.Buffer) + recording.writer = util.NewSyncWriterMutex(recording.buffer, &recording.lock) + + if mode != RecordError { + recording.output = GetOutput() + setOutput(recording.writer) + } + if mode != RecordOutput { + recording.error = GetErrorOutput() + setErrorOutput(recording.writer) + } +} + +func ReadRecording() (content string) { + recording.lock.Lock() + defer recording.lock.Unlock() + if recording.buffer != nil { + content = recording.buffer.String() + recording.buffer.Reset() + } + return +} + +func StopRecording() (content string) { + recording.lock.Lock() + defer recording.lock.Unlock() + if recording.buffer != nil { + if recording.output != nil && recording.writer == GetOutput() { + setOutput(recording.output) + recording.output = nil } + + if recording.error != nil && recording.writer == GetErrorOutput() { + setErrorOutput(recording.error) + recording.error = nil + } + + content = recording.buffer.String() + recording.writer = nil + recording.buffer = nil } + return } // Print formats using the default formats for its operands and writes to standard output. // Spaces are added between operands when neither is a string. // It returns the number of bytes written and any write error encountered. func Print(a ...interface{}) (n int, err error) { - return fmt.Fprint(terminalOutput, a...) + return fmt.Fprint(GetColorableOutput(), a...) } // Println formats using the default formats for its operands and writes to standard output. // Spaces are always added between operands and a newline is appended. // It returns the number of bytes written and any write error encountered. func Println(a ...interface{}) (n int, err error) { - return fmt.Fprintln(terminalOutput, a...) + return fmt.Fprintln(GetColorableOutput(), a...) } // Printf formats according to a format specifier and writes to standard output. // It returns the number of bytes written and any write error encountered. func Printf(format string, a ...interface{}) (n int, err error) { - return fmt.Fprintf(terminalOutput, format, a...) + return fmt.Fprintf(GetColorableOutput(), format, a...) } diff --git a/term/term_test.go b/term/term_test.go index d8f720383..913ca9224 100644 --- a/term/term_test.go +++ b/term/term_test.go @@ -2,6 +2,7 @@ package term import ( "bytes" + "fmt" "os" "testing" @@ -60,22 +61,45 @@ func TestAskYesNo(t *testing.T) { {"no\r\n", false, false}, } for _, testItem := range testData { + StartRecording(RecordOutput) result := AskYesNo( bytes.NewBufferString(testItem.input), "message", testItem.defaultAnswer, ) - assert.Equalf(t, testItem.expected, result, "when input was %q", testItem.input) + assert.Contains(t, StopRecording(), "message? (") + assert.Equal(t, testItem.expected, result, "when input was %q", testItem.input) } } -func ExamplePrint() { +func TestExamplePrint(t *testing.T) { SetOutput(os.Stdout) Print("ExamplePrint") // Output: ExamplePrint } +func TestOutputCapture(t *testing.T) { + SetOutput(os.Stdout) + SetErrorOutput(os.Stderr) + + StartRecording(RecordOutput) + _, _ = Print("ExamplePrint") + assert.Equal(t, "ExamplePrint", ReadRecording()) + _, _ = Print("1") + assert.Equal(t, "1", StopRecording()) + + StartRecording(RecordError) + _, _ = fmt.Fprintf(GetErrorOutput(), "ExamplePrint") + assert.Equal(t, "ExamplePrint", StopRecording()) + + StartRecording(RecordBoth) + _, _ = fmt.Fprintf(GetOutput(), "Info") + _, _ = fmt.Fprintf(GetErrorOutput(), "Error") + assert.Equal(t, "InfoError", StopRecording()) +} + func TestCanRedirectTermOutput(t *testing.T) { + defer SetOutput(os.Stdout) message := "TestCanRedirectTermOutput" buffer := &bytes.Buffer{} SetOutput(buffer) diff --git a/util/ansi/colors.go b/util/ansi/colors.go new file mode 100644 index 000000000..87f624fc3 --- /dev/null +++ b/util/ansi/colors.go @@ -0,0 +1,41 @@ +package ansi + +import ( + "strings" + + "github.com/fatih/color" +) + +var ( + bold = color.New(color.Bold) + Bold = bold.SprintFunc() + blue = color.New(color.FgBlue) + Blue = bold.SprintFunc() + cyan = color.New(color.FgCyan) + Cyan = cyan.SprintFunc() + gray = New256FgColor(243) + Gray = gray.SprintFunc() + green = color.New(color.FgGreen) + Green = green.SprintFunc() + yellow = color.New(color.FgYellow) + Yellow = yellow.SprintFunc() + underline = color.New(color.Underline) + Underline = underline.Sprint() +) + +// New256FgColor return a new xterm 256 (8bit) foreground color +func New256FgColor(code uint8) *color.Color { + return color.New(38, 5, color.Attribute(code)) +} + +// New256BgColor return a new xterm 256 (8bit) background color +func New256BgColor(code uint8) *color.Color { + return color.New(48, 5, color.Attribute(code)) +} + +func ColorSequence(fn func(a ...interface{}) string) (start, stop string) { + s := fn("||") + d := strings.Index(s, "||") + start, stop = s[:d], s[d+2:] + return +} diff --git a/util/ansi/colors_test.go b/util/ansi/colors_test.go new file mode 100644 index 000000000..03513d578 --- /dev/null +++ b/util/ansi/colors_test.go @@ -0,0 +1,19 @@ +package ansi + +import ( + "strings" + "testing" + + "github.com/fatih/color" + "github.com/stretchr/testify/assert" +) + +func Test256Colors(t *testing.T) { + test := func(color *color.Color, expected string) { + color.EnableColor() + seq := strings.Split(color.Sprint("||"), "||")[0] + assert.Equal(t, expected, seq) + } + test(New256FgColor(10), Sequence('m', 38, 5, 10)) + test(New256BgColor(10), Sequence('m', 48, 5, 10)) +} diff --git a/util/ansi/escape.go b/util/ansi/escape.go new file mode 100644 index 000000000..5ca148314 --- /dev/null +++ b/util/ansi/escape.go @@ -0,0 +1,36 @@ +package ansi + +import ( + "fmt" + "strings" +) + +const ( + EscapeByte = 0x1b + Escape = "\x1b" + ClearLine = Escape + "[2K" + Reset = Escape + "[0m" +) + +// Sequence builds an arbitrary escape sequence +func Sequence(terminator byte, attributes ...any) string { + seq := strings.Builder{} + seq.WriteString(Escape) + seq.WriteByte('[') + for i, attribute := range attributes { + if i > 0 { + seq.WriteByte(';') + } + _, _ = fmt.Fprint(&seq, attribute) + } + seq.WriteByte(terminator) + return seq.String() +} + +// CursorUpLeftN creates the escape sequence to move the cursor left and up N lines +func CursorUpLeftN(lines int) string { + if lines < 0 { + lines = 0 + } + return Sequence('F', lines) +} diff --git a/util/ansi/escape_test.go b/util/ansi/escape_test.go new file mode 100644 index 000000000..4b25be8f3 --- /dev/null +++ b/util/ansi/escape_test.go @@ -0,0 +1,14 @@ +package ansi + +import ( + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestCursorUpLeftN(t *testing.T) { + assert.Equal(t, Escape+"[0F", CursorUpLeftN(-1)) + assert.Equal(t, Escape+"[0F", CursorUpLeftN(0)) + assert.Equal(t, Escape+"[1F", CursorUpLeftN(1)) + assert.Equal(t, Escape+"[2F", CursorUpLeftN(2)) +} diff --git a/util/ansi/linewriter.go b/util/ansi/linewriter.go new file mode 100644 index 000000000..217ad370b --- /dev/null +++ b/util/ansi/linewriter.go @@ -0,0 +1,110 @@ +package ansi + +import ( + "io" + "unicode/utf8" +) + +type lineLengthWriter struct { + writer io.Writer + tokens []byte + maxLineLength, lastWhite, breakLength, lineLength int + invisibleLength, lastWhiteInvisibleLength int + inAnsi bool +} + +// NewLineLengthWriter return an io.Writer that limits the max line length, adding line breaks ('\n') as needed. +// The writer detects the right most column (consecutive whitespace) and aligns content if possible. +// UTF sequences are counted as single character and ANSI escape sequences are not counted at all. +func NewLineLengthWriter(writer io.Writer, maxLineLength int) io.Writer { + return &lineLengthWriter{ + tokens: []byte{' ', '\n'}, + writer: writer, + maxLineLength: maxLineLength, + } +} + +func (l *lineLengthWriter) visibleLineLength() int { return l.lineLength - l.invisibleLength } + +func (l *lineLengthWriter) Write(p []byte) (n int, err error) { + written := 0 + offset := l.lineLength + + for i := 0; i < len(p); i++ { + l.lineLength++ + ws := p[i] == l.tokens[0] // whitespace + br := p[i] == l.tokens[1] // linebreak + + // don't count ansi control sequences + if l.inAnsi = l.inAnsi || p[i] == EscapeByte; l.inAnsi { + terminator := (p[i] >= 'a' && p[i] <= 'z') || (p[i] >= 'A' && p[i] <= 'Z') + l.inAnsi = !terminator + l.invisibleLength++ + continue + } + + // count UTF sequence as one character + if p[i] >= utf8.RuneSelf { + if !utf8.RuneStart(p[i]) { + l.invisibleLength++ + } + continue + } + + if !br && l.visibleLineLength() > l.maxLineLength && l.lastWhite-offset > 0 { + lastWhiteIndex := l.lastWhite - offset - 1 + remainder := i - lastWhiteIndex + + if written, err = l.writer.Write(p[:lastWhiteIndex]); err == nil { + p = p[lastWhiteIndex+1:] + i = remainder - 1 + n += written + 1 + + _, _ = l.writer.Write(l.tokens[1:]) // write break (instead of WS at lastWhiteIndex) + for j := 0; j < l.breakLength; j++ { + _, _ = l.writer.Write(l.tokens[0:1]) // fill spaces for alignment + } + + l.lineLength = l.breakLength + remainder + l.lastWhite = l.breakLength + offset = l.breakLength + + l.invisibleLength -= l.lastWhiteInvisibleLength + l.lastWhiteInvisibleLength = 0 + } else { + return + } + } + + if ws { + if l.lastWhite == l.lineLength-1 && l.visibleLineLength() < l.maxLineLength*2/3 { + l.breakLength = l.visibleLineLength() + } + l.lastWhite = l.lineLength + l.lastWhiteInvisibleLength = l.invisibleLength + + } else if br { + if written, err = l.writer.Write(p[:i+1]); err == nil { + p = p[i+1:] + i = -1 + n += written + + l.lineLength = 0 + l.lastWhite = 0 + l.breakLength = 0 + offset = 0 + + l.invisibleLength = 0 + l.lastWhiteInvisibleLength = 0 + } else { + return + } + } + } + + // write remainder + if written, err = l.writer.Write(p); err == nil { + n += written + } + return +} diff --git a/util/ansi/linewriter_test.go b/util/ansi/linewriter_test.go new file mode 100644 index 000000000..f25f350ec --- /dev/null +++ b/util/ansi/linewriter_test.go @@ -0,0 +1,283 @@ +package ansi + +import ( + "bytes" + "fmt" + "strings" + "testing" + + "github.com/fatih/color" + "github.com/stretchr/testify/assert" +) + +var ansiColor = func() (c *color.Color) { + c = color.New(color.FgCyan) + c.EnableColor() + return +}() + +var colored = ansiColor.SprintFunc() + +func TestLineLengthWriter(t *testing.T) { + tests := []struct { + input, expected string + chunks, scale int + }{ + // test non-breakable + {input: strings.Repeat("-", 50), expected: strings.Repeat("-", 50), chunks: 15}, + + // test breakable without columns + { + input: strings.Repeat("word ", 20), + expected: "" + + strings.TrimSpace(strings.Repeat("word ", 8)) + "\n" + + strings.TrimSpace(strings.Repeat("word ", 8)) + "\n" + + strings.Repeat("word ", 4), + chunks: 5, scale: 6, + }, + + // test breakable with ANSI color + { + input: strings.Repeat(colored("word "), 20), + expected: "" + + strings.Repeat(colored("word "), 7) + colored("word\n") + + strings.Repeat(colored("word "), 7) + colored("word\n") + + strings.Repeat(colored("word "), 4), + }, + + // test breakable with 2 columns + { + input: "word word word word " + + strings.Repeat("word ", 20), + expected: "" + + "word word word word " + + "word word word\n" + + strings.Repeat(" word word word\n", 5) + + " word word ", + chunks: 3, scale: 15, + }, + + // test breakable with 2 columns and ANSI color + { + input: colored("word word word word ") + + strings.Repeat(colored("word "), 20), + expected: "" + + colored("word word word word ") + + colored("word ") + colored("word ") + colored("word\n ") + + strings.Repeat(colored("word ")+colored("word ")+colored("word\n "), 5) + + colored("word ") + colored("word "), + }, + + // test breakable with 2 columns and unicode character + { + input: "w😁rd wo😁d wor😁 😁ord 😁😁😁😁 w😁rd wo😁d wor😁 😁ord 😁😁😁😁", + expected: "w😁rd wo😁d wor😁 😁ord 😁😁😁😁 w😁rd wo😁d \n" + + " wor😁 😁ord 😁😁😁😁", + }, + { + input: "word word word word word word word word word word", + expected: "word word word word word word word \n" + + " word word word", + }, + + // test breakable with 2 columns, colors and unicode character + { + input: colored("w😁rd wo😁d wor😁 😁ord ") + + strings.Repeat(colored("wor😁 ")+colored("😁ord "), 2), + expected: "" + + colored("w😁rd wo😁d wor😁 😁ord ") + + colored("wor😁 ") + colored("😁ord ") + colored("wor😁\n ") + + colored("😁ord "), + }, + + // test real-world content + { + input: ` +Usage of resticprofile: + resticprofile [resticprofile flags] [profile name.][restic command] [restic flags] + resticprofile [resticprofile flags] [profile name.][resticprofile command] [command specific flags] + +resticprofile flags: + -c, --config string configuration file (default "profiles") + --dry-run display the restic commands instead of running them + -f, --format string file format of the configuration (default is to use the file extension) + -h, --help display this help + --lock-wait duration wait up to duration to acquire a lock (syntax "1h5m30s") + -l, --log string logs to a target instead of the console + -n, --name string profile name (default "default") + --no-ansi disable ansi control characters (disable console colouring) + --no-lock skip profile lock file + --no-prio don't set any priority on load: used when started from a service that has already set the priority + -q, --quiet display only warnings and errors + --theme string console colouring theme (dark, light, none) (default "light") + --trace display even more debugging information + -v, --verbose display some debugging information + -w, --wait wait at the end until the user presses the enter key + + +resticprofile own commands: + help display help (run in verbose mode for detailed information) + version display version (run in verbose mode for detailed information) + self-update update to latest resticprofile (use -q/--quiet flag to update without confirmation) + profiles display profile names from the configuration file + show show all the details of the current profile + schedule schedule jobs from a profile (use --all flag to schedule all jobs of all profiles) + unschedule remove scheduled jobs of a profile (use --all flag to unschedule all profiles) + status display the status of scheduled jobs (use --all flag for all profiles) + generate generate resources (--random-key [size], --bash-completion & --zsh-completion) + +Documentation available at https://creativeprojects.github.io/resticprofile/ +`, + expected: ` +Usage of resticprofile: + resticprofile [resticprofile flags] + [profile name.][restic command] + [restic flags] + resticprofile [resticprofile flags] + [profile name.][resticprofile + command] [command specific flags] + +resticprofile flags: + -c, --config string + configuration + file (default + "profiles") + --dry-run display + the restic + commands + instead of + running them + -f, --format string file + format of the + configuration + (default is to + use the file + extension) + -h, --help display + this help + --lock-wait duration wait up to + duration to acquire a lock + (syntax "1h5m30s") + -l, --log string logs to a + target instead + of the console + -n, --name string profile + name (default + "default") + --no-ansi disable + ansi control + characters + (disable + console + colouring) + --no-lock skip + profile lock + file + --no-prio don't set + any priority + on load: used + when started + from a service + that has + already set + the priority + -q, --quiet display + only warnings + and errors + --theme string console + colouring + theme (dark, + light, none) + (default + "light") + --trace display + even more + debugging + information + -v, --verbose display + some debugging + information + -w, --wait wait at + the end until + the user + presses the + enter key + + +resticprofile own commands: + help display help (run in + verbose mode for + detailed information) + version display version (run + in verbose mode for + detailed information) + self-update update to latest + resticprofile (use + -q/--quiet flag to + update without + confirmation) + profiles display profile names + from the configuration + file + show show all the details + of the current profile + schedule schedule jobs from a + profile (use --all + flag to schedule all + jobs of all profiles) + unschedule remove scheduled jobs + of a profile (use + --all flag to + unschedule all + profiles) + status display the status of + scheduled jobs (use + --all flag for all + profiles) + generate generate resources + (--random-key [size], + --bash-completion & + --zsh-completion) + +Documentation available at +https://creativeprojects.github.io/resticprofile/ +`, + }, + } + + for i, test := range tests { + if test.scale == 0 { + test.scale = 1 + } + for chunkSize := 0; chunkSize <= test.chunks; chunkSize++ { + t.Run(fmt.Sprintf("%d-%d", i, chunkSize), func(t *testing.T) { + buffer := bytes.Buffer{} + writer := NewLineLengthWriter(&buffer, 40) + input := []byte(test.input) + + var ( + n int + err error + ) + switch chunkSize { + case 0: + n, err = writer.Write(input) + assert.Equal(t, len(input), n) + default: + for len(input) > 0 && err == nil { + length := test.scale * chunkSize + if length > len(input) { + length = len(input) + } + n, err = writer.Write(input[:length]) + assert.Equal(t, length, n) + input = input[length:] + } + } + + assert.Nil(t, err) + assert.Equal(t, test.expected, buffer.String()) + }) + } + } +} diff --git a/util/ansi/runes.go b/util/ansi/runes.go new file mode 100644 index 000000000..da5788424 --- /dev/null +++ b/util/ansi/runes.go @@ -0,0 +1,26 @@ +package ansi + +// RunesLength returns the visible content length (and index at the length) +func RunesLength(src []rune, maxLength int) (length, index int) { + esc := rune(Escape[0]) + inEsc := false + index = -1 + for i, r := range src { + if r == esc { + inEsc = true + } else if inEsc { + if (r >= 'a' && r <= 'z') || (r >= 'A' && r <= 'Z') { + inEsc = false + } + } else { + if length == maxLength { + index = i + } + length++ + } + } + if index < 0 { + index = len(src) + } + return +} diff --git a/util/ansi/runes_test.go b/util/ansi/runes_test.go new file mode 100644 index 000000000..c00452b24 --- /dev/null +++ b/util/ansi/runes_test.go @@ -0,0 +1,40 @@ +package ansi + +import ( + "fmt" + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestRunesLength(t *testing.T) { + tests := []struct { + input []rune + max, index, length int + }{ + {input: []rune{}, index: 0, length: 0, max: -1}, + {input: []rune(""), index: 0, length: 0, max: -1}, + {input: []rune(ClearLine + ""), index: len(ClearLine), length: 0, max: -1}, + {input: []rune(ClearLine + "" + ClearLine), index: 2 * len(ClearLine), length: 0, max: -1}, + {input: []rune(ClearLine + "β—·" + ClearLine), index: 1 + 2*len(ClearLine), length: 1, max: -1}, + + {input: []rune(ClearLine + "β—·β—·β—·" + ClearLine), index: len(ClearLine), length: 3, max: 0}, + {input: []rune(ClearLine + "β—·β—·β—·" + ClearLine), index: 1 + len(ClearLine), length: 3, max: 1}, + {input: []rune(ClearLine + "β—·β—·β—·" + ClearLine), index: 2 + len(ClearLine), length: 3, max: 2}, + {input: []rune(ClearLine + "β—·β—·β—·" + ClearLine), index: 3 + 2*len(ClearLine), length: 3, max: 3}, + + {input: []rune(ClearLine + "β—·β—·β—·" + ClearLine + "123"), index: 3 + 2*len(ClearLine), length: 6, max: 3}, + {input: []rune(ClearLine + "β—·β—·β—·" + ClearLine + "123"), index: 4 + 2*len(ClearLine), length: 6, max: 4}, + {input: []rune(ClearLine + "β—·β—·β—·" + ClearLine + "123"), index: 5 + 2*len(ClearLine), length: 6, max: 5}, + {input: []rune(ClearLine + "β—·β—·β—·" + ClearLine + "123"), index: 6 + 2*len(ClearLine), length: 6, max: 6}, + {input: []rune(ClearLine + "β—·β—·β—·" + ClearLine + "123"), index: 6 + 2*len(ClearLine), length: 6, max: 7}, + {input: []rune(ClearLine + "β—·β—·β—·" + ClearLine + "123"), index: 6 + 2*len(ClearLine), length: 6, max: -1}, + } + for idx, test := range tests { + t.Run(fmt.Sprintf("%d", idx), func(t *testing.T) { + length, index := RunesLength(test.input, test.max) + assert.Equal(t, test.length, length, "length") + assert.Equal(t, test.index, index, "index") + }) + } +} diff --git a/util/filewriter.go b/util/filewriter.go new file mode 100644 index 000000000..1e1fb6fc8 --- /dev/null +++ b/util/filewriter.go @@ -0,0 +1,222 @@ +package util + +import ( + "io" + "os" + "sync" + "time" + + "github.com/creativeprojects/resticprofile/platform" +) + +// AsyncFileWriterAppendFunc is called for every input byte when appending it to the output buffer (is similar to buf = append(buf, byte)) +type AsyncFileWriterAppendFunc func(dst []byte, c byte) []byte + +type asyncFileWriterOption func(writer *asyncFileWriter) + +// WithAsyncWriteInterval sets the interval at which writes happen at least when data is pending +func WithAsyncWriteInterval(duration time.Duration) asyncFileWriterOption { + return func(writer *asyncFileWriter) { writer.interval = duration } +} + +// WithAsyncFileKeepOpen toggles whether the file is kept open between writes. Defaults to true for all OS except Windows. +func WithAsyncFileKeepOpen(keepOpen bool) asyncFileWriterOption { + return func(writer *asyncFileWriter) { writer.keepOpen = keepOpen } +} + +// WithAsyncFileAppendFunc sets AsyncFileWriterAppendFunc. Default is to not use a custom appender. +func WithAsyncFileAppendFunc(appender AsyncFileWriterAppendFunc) asyncFileWriterOption { + return func(writer *asyncFileWriter) { writer.appender = appender } +} + +// WithAsyncFilePerm sets file perms to apply when creating the file +func WithAsyncFilePerm(perm os.FileMode) asyncFileWriterOption { + return func(writer *asyncFileWriter) { writer.perm = perm } +} + +// WithAsyncFileFlag sets file open flags +func WithAsyncFileFlag(flag int) asyncFileWriterOption { + return func(writer *asyncFileWriter) { writer.flag = flag } +} + +// WithAsyncFileTruncate enables that existing files are truncated +func WithAsyncFileTruncate() asyncFileWriterOption { + return func(writer *asyncFileWriter) { writer.flag |= os.O_TRUNC } +} + +const ( + asyncWriterDataChanSize = 64 + asyncWriterBlockSize = 4 * 1024 + asyncWriterMaxBlockSize = asyncWriterDataChanSize * asyncWriterBlockSize +) + +var ( + asyncWriterBufferPool = sync.Pool{ + New: func() any { return make([]byte, asyncWriterBlockSize) }, + } +) + +func asyncWriterReturnToPool(data []byte) { + if cap(data) == asyncWriterBlockSize { + asyncWriterBufferPool.Put(data[:0]) + } +} + +// NewAsyncFileWriter creates a file writer that accumulates Write requests and writes them at a fixed rate (every 250 ms by default) +func NewAsyncFileWriter(filename string, options ...asyncFileWriterOption) (io.WriteCloser, error) { + w := &asyncFileWriter{ + flush: make(chan chan error), + done: make(chan chan error), + data: make(chan []byte, asyncWriterDataChanSize), + perm: 0644, + flag: os.O_WRONLY | os.O_APPEND | os.O_CREATE, + interval: 250 * time.Millisecond, + keepOpen: !platform.IsWindows(), + } + for _, option := range options { + option(w) + } + + var ( + buffer []byte + lastError error + file *os.File + ) + + closeFile := func() { + if file != nil { + lastError = file.Close() + file = nil + } + } + + flush := func(alsoEmpty, whenTooBig bool) { + if len(buffer) == 0 && !alsoEmpty { + return + } + if len(buffer) < asyncWriterMaxBlockSize && whenTooBig { + return + } + if file == nil { + file, lastError = os.OpenFile(filename, w.flag, w.perm) + } + if file != nil { + var written int + written, lastError = file.Write(buffer) + if remaining := len(buffer) - written; remaining > 0 { + copy(buffer, buffer[written:]) + buffer = buffer[:remaining] + } else { + buffer = buffer[:0] + } + } + if w.keepOpen { + _ = file.Sync() + } else { + closeFile() + } + } + + // test if we can create the file + buffer = make([]byte, 0, asyncWriterBlockSize) + flush(true, false) + + // data appending + addToBuffer := func(data []byte) { + buffer = append(buffer, data...) // fast path + asyncWriterReturnToPool(data) + flush(false, true) + } + if w.appender != nil { + addToBuffer = func(data []byte) { + for _, c := range data { + buffer = w.appender(buffer, c) + } + asyncWriterReturnToPool(data) + flush(false, true) + } + } + + addPendingData := func(max int) { + for ; max > 0; max-- { + select { + case data, ok := <-w.data: + if ok { + addToBuffer(data) + } else { + return // closed + } + default: + return // no-more-data + } + } + } + + // data transport + go func() { + ticker := time.NewTicker(w.interval) + defer ticker.Stop() + defer closeFile() + + for { + select { + case data := <-w.data: + addToBuffer(data) + case <-ticker.C: + flush(false, false) + case req := <-w.flush: + addPendingData(1024) + flush(false, false) + req <- lastError + case req := <-w.done: + defer func(response chan error) { + response <- lastError + }(req) + close(w.done) + close(w.flush) + close(w.data) + addPendingData(1024) + flush(false, false) + closeFile() + return + } + } + }() + + return w, lastError +} + +type asyncFileWriter struct { + done, flush chan chan error + data chan []byte + appender AsyncFileWriterAppendFunc + flag int + perm os.FileMode + keepOpen bool + interval time.Duration +} + +func (w *asyncFileWriter) Close() error { + req := make(chan error) + w.done <- req + return <-req +} + +func (w *asyncFileWriter) Flush() error { + req := make(chan error) + w.flush <- req + return <-req +} + +func (w *asyncFileWriter) Write(data []byte) (n int, _ error) { + var buffer []byte + if len(data) <= asyncWriterBlockSize { + buffer = asyncWriterBufferPool.Get().([]byte)[:len(data)] + } else { + buffer = make([]byte, len(data)) + } + + n = copy(buffer, data) + w.data <- buffer + return +} diff --git a/util/filewriter_test.go b/util/filewriter_test.go new file mode 100644 index 000000000..02679ab3a --- /dev/null +++ b/util/filewriter_test.go @@ -0,0 +1,3 @@ +package util + +// TODO diff --git a/util/reader.go b/util/reader.go new file mode 100644 index 000000000..e819ed5c3 --- /dev/null +++ b/util/reader.go @@ -0,0 +1,94 @@ +package util + +import ( + "io" + "sync" +) + +// ReadFunc is the callback in NewFilterReader & NewFilterReadCloser for io.Reader.Read. +type ReadFunc func(bytes []byte) (n int, err error) + +type filterReader struct { + read ReadFunc +} + +func (f *filterReader) Read(bytes []byte) (n int, err error) { + if f.read == nil { + err = io.EOF + return + } + return f.read(bytes) +} + +// NewFilterReader creates a new io.Reader redirects all read calls to ReadFunc +func NewFilterReader(read ReadFunc) io.Reader { + return &filterReader{read} +} + +// CloseFunc is the callback in NewFilterReadCloser for io.Closer.Close. It is guaranteed to be called once. +type CloseFunc func() (err error) + +type filterReadCloser struct { + filterReader + close CloseFunc +} + +func (c filterReadCloser) Close() error { + defer func() { + c.close = nil + c.read = nil + }() + if c.close == nil { + return nil + } + return c.close() +} + +// NewFilterReadCloser creates a new io.ReadCloser redirects all calls to ReadFunc and CloseFunc +func NewFilterReadCloser(read ReadFunc, close CloseFunc) io.ReadCloser { + return &filterReadCloser{*NewFilterReader(read).(*filterReader), close} +} + +// NewSyncReader creates a new reader that is safe for concurrent use +func NewSyncReader[R io.Reader](reader R) SyncReader[R] { + mutex := new(sync.Mutex) + return NewSyncReaderMutex(reader, mutex, mutex) +} + +// NewSyncReaderMutex creates a new reader that is safe for concurrent use and synced with the specified sync.Mutex +func NewSyncReaderMutex[R io.Reader](reader R, mutex, closeMutex *sync.Mutex) SyncReader[R] { + return &syncReader[R]{reader: reader, mutex: mutex, closeMutex: closeMutex} +} + +// SyncReader implements an io.ReadCloser that is safe for concurrent use +type SyncReader[R io.Reader] interface { + io.ReadCloser + // Locked provides sync.Mutex locked access to the underlying reader + Locked(func(R) error) error +} + +type syncReader[R io.Reader] struct { + reader io.Reader + mutex, closeMutex *sync.Mutex +} + +func (w *syncReader[R]) Locked(fn func(reader R) error) error { + w.mutex.Lock() + defer w.mutex.Unlock() + return fn(w.reader.(R)) +} + +func (w *syncReader[R]) Read(p []byte) (n int, err error) { + w.mutex.Lock() + defer w.mutex.Unlock() + return w.reader.Read(p) +} + +func (w *syncReader[R]) Close() (err error) { + w.closeMutex.Lock() + defer w.closeMutex.Unlock() + if f, ok := w.reader.(io.Closer); ok { + err = f.Close() + } + return +} diff --git a/util/reader_test.go b/util/reader_test.go new file mode 100644 index 000000000..02679ab3a --- /dev/null +++ b/util/reader_test.go @@ -0,0 +1,3 @@ +package util + +// TODO diff --git a/util/writer.go b/util/writer.go new file mode 100644 index 000000000..c910ee195 --- /dev/null +++ b/util/writer.go @@ -0,0 +1,73 @@ +package util + +import ( + "io" + "sync" +) + +// Flusher allows a Writer to declare it may buffer content that can be flushed +type Flusher interface { + // Flush writes any pending bytes to output + Flush() error +} + +// FlushWriter attempts to flush a writer if it implements Flusher +func FlushWriter(writer io.Writer) (flushable bool, err error) { + var f Flusher + if f, flushable = writer.(Flusher); flushable { + err = f.Flush() + } + return +} + +// NewSyncWriter creates a new writer that is safe for concurrent use +func NewSyncWriter[W io.Writer](writer W) SyncWriter[W] { + return NewSyncWriterMutex(writer, new(sync.Mutex)) +} + +// NewSyncWriterMutex creates a new writer that is safe for concurrent use and synced with the specified sync.Mutex +func NewSyncWriterMutex[W io.Writer](writer W, mutex *sync.Mutex) SyncWriter[W] { + return &syncWriter[W]{writer: writer, mutex: mutex} +} + +// SyncWriter implements an io.Writer that is safe for concurrent use +type SyncWriter[W io.Writer] interface { + io.Writer + // Locked provides sync.Mutex locked access to the underlying writer + Locked(func(W) error) error +} + +type syncWriter[W io.Writer] struct { + writer io.Writer + mutex *sync.Mutex +} + +func (w *syncWriter[W]) Locked(fn func(writer W) error) error { + w.mutex.Lock() + defer w.mutex.Unlock() + return fn(w.writer.(W)) +} + +func (w *syncWriter[W]) Write(p []byte) (n int, err error) { + w.mutex.Lock() + defer w.mutex.Unlock() + return w.writer.Write(p) +} + +func (w *syncWriter[W]) Flush() (err error) { + w.mutex.Lock() + defer w.mutex.Unlock() + if f, ok := w.writer.(Flusher); ok { + err = f.Flush() + } + return +} + +func (w *syncWriter[W]) Close() (err error) { + w.mutex.Lock() + defer w.mutex.Unlock() + if f, ok := w.writer.(io.Closer); ok { + err = f.Close() + } + return +} diff --git a/util/writer_test.go b/util/writer_test.go new file mode 100644 index 000000000..02679ab3a --- /dev/null +++ b/util/writer_test.go @@ -0,0 +1,3 @@ +package util + +// TODO diff --git a/wrapper_streamsource.go b/wrapper_streamsource.go index 76760aae7..a222e23a6 100644 --- a/wrapper_streamsource.go +++ b/wrapper_streamsource.go @@ -7,13 +7,14 @@ import ( "io" "os" "os/signal" - "runtime" "sync" "syscall" "time" "github.com/creativeprojects/clog" + "github.com/creativeprojects/resticprofile/platform" "github.com/creativeprojects/resticprofile/term" + "github.com/creativeprojects/resticprofile/util" ) func (r *resticWrapper) prepareStreamSource() (io.ReadCloser, error) { @@ -34,22 +35,25 @@ func (r *resticWrapper) prepareStdinStreamSource() (io.ReadCloser, error) { return nil, fmt.Errorf("stdin was already consumed. cannot read it twice") } - totalBytes := int64(0) - - readCloser := &readerWrapper{ - reader: r.stdin, - read: func(w *readerWrapper, bytes []byte) (n int, err error) { - n, err = w.reader.Read(bytes) - totalBytes += int64(n) - return - }, - close: func(w *readerWrapper) error { - if totalBytes > 0 && r.stdin != nil { - r.stdin = nil - w.close = nil - } - return nil - }, + var readCloser io.ReadCloser + { + totalBytes := int64(0) + reader := r.stdin + readCloser = util.NewSyncReader(util.NewFilterReadCloser( + // Read + func(bytes []byte) (n int, err error) { + n, err = reader.Read(bytes) + totalBytes += int64(n) + return + }, + // Close + func() error { + if totalBytes > 0 && r.stdin != nil { + r.stdin = nil + } + return nil + }, + )) } return readCloser, nil @@ -113,55 +117,34 @@ func (r *resticWrapper) prepareCommandStreamSource() (io.ReadCloser, error) { } } - readCloser := &readerWrapper{ - reader: io.MultiReader(initialReader, pipeReader), - - read: func(w *readerWrapper, bytes []byte) (n int, err error) { - n, err = w.reader.Read(bytes) - - // Stopping restic when stream source command fails while producing content - if err != nil && err != io.EOF { - clog.Errorf("interrupting '%s' after stdin read error: %s", r.command, err) - if runtime.GOOS == "windows" { - return // that will close stdin and stops restic - } else if r.sigChan != nil { - r.sigChan <- os.Interrupt - } - // Wait for the signal to arrive before allowing further read from stdin - time.Sleep(750 * time.Millisecond) - } - return - }, - - close: func(w *readerWrapper) error { - w.close = nil - return closePipe() - }, + var readCloser io.ReadCloser + { + var readLock, closeLock sync.Mutex + reader := io.MultiReader(initialReader, pipeReader) + readCloser = util.NewSyncReaderMutex( + util.NewFilterReadCloser( + // Read + func(bytes []byte) (n int, err error) { + n, err = reader.Read(bytes) + + // Stopping restic when stream source command fails while producing content + if err != nil && err != io.EOF { + clog.Errorf("interrupting '%s' after stdin read error: %s", r.command, err) + if platform.IsWindows() { + return // that will close stdin and stops restic + } else if r.sigChan != nil { + r.sigChan <- os.Interrupt + } + // Wait for the signal to arrive before allowing further read from stdin + time.Sleep(750 * time.Millisecond) + } + return + }, + // Close + closePipe, + ), &readLock, &closeLock, + ) } return readCloser, nil } - -type readerWrapper struct { - reader io.Reader - readLock, closeLock sync.Mutex - read func(w *readerWrapper, bytes []byte) (n int, err error) - close func(w *readerWrapper) error -} - -func (w *readerWrapper) Read(bytes []byte) (n int, err error) { - w.readLock.Lock() - defer w.readLock.Unlock() - - return w.read(w, bytes) -} - -func (w *readerWrapper) Close() error { - w.closeLock.Lock() - defer w.closeLock.Unlock() - - if w.close != nil { - return w.close(w) - } - return nil -} diff --git a/wrapper_test.go b/wrapper_test.go index 344ab117c..1127aa731 100644 --- a/wrapper_test.go +++ b/wrapper_test.go @@ -1,7 +1,6 @@ package main import ( - "bytes" "errors" "fmt" "io" @@ -263,95 +262,95 @@ func Example_runProfile() { } func TestRunRedirectOutputOfEchoProfile(t *testing.T) { - buffer := &bytes.Buffer{} - term.SetOutput(buffer) + term.StartRecording(term.RecordOutput) + defer term.StopRecording() profile := config.NewProfile(nil, "name") wrapper := newResticWrapper(nil, "echo", false, profile, "test", nil, nil) err := wrapper.runProfile() assert.NoError(t, err) - assert.Equal(t, "test", strings.TrimSpace(buffer.String())) + assert.Equal(t, "test", strings.TrimSpace(term.ReadRecording())) } func TestDryRun(t *testing.T) { - buffer := &bytes.Buffer{} - term.SetOutput(buffer) + term.StartRecording(term.RecordOutput) + defer term.StopRecording() profile := config.NewProfile(nil, "name") wrapper := newResticWrapper(nil, "echo", true, profile, "test", nil, nil) err := wrapper.runProfile() assert.NoError(t, err) - assert.Equal(t, "", buffer.String()) + assert.Equal(t, "", term.ReadRecording()) } func TestEnvProfileName(t *testing.T) { - buffer := &bytes.Buffer{} - term.SetOutput(buffer) + term.StartRecording(term.RecordOutput) + defer term.StopRecording() profile := config.NewProfile(nil, "TestEnvProfileName") profile.RunBefore = []string{"echo profile name = $PROFILE_NAME"} wrapper := newResticWrapper(nil, "echo", false, profile, "test", nil, nil) err := wrapper.runProfile() assert.NoError(t, err) - assert.Equal(t, "profile name = TestEnvProfileName\ntest\n", strings.ReplaceAll(buffer.String(), "\r\n", "\n")) + assert.Equal(t, "profile name = TestEnvProfileName\ntest\n", strings.ReplaceAll(term.ReadRecording(), "\r\n", "\n")) } func TestEnvProfileCommand(t *testing.T) { - buffer := &bytes.Buffer{} - term.SetOutput(buffer) + term.StartRecording(term.RecordOutput) + defer term.StopRecording() profile := config.NewProfile(nil, "name") profile.RunBefore = []string{"echo profile command = $PROFILE_COMMAND"} wrapper := newResticWrapper(nil, "echo", false, profile, "test-command", nil, nil) err := wrapper.runProfile() assert.NoError(t, err) - assert.Equal(t, "profile command = test-command\ntest-command\n", strings.ReplaceAll(buffer.String(), "\r\n", "\n")) + assert.Equal(t, "profile command = test-command\ntest-command\n", strings.ReplaceAll(term.ReadRecording(), "\r\n", "\n")) } func TestEnvError(t *testing.T) { - buffer := &bytes.Buffer{} - term.SetOutput(buffer) + term.StartRecording(term.RecordOutput) + defer term.StopRecording() profile := config.NewProfile(nil, "name") profile.RunAfterFail = []string{"echo error: $ERROR_MESSAGE"} wrapper := newResticWrapper(nil, "exit", false, profile, "1", nil, nil) err := wrapper.runProfile() assert.Error(t, err) - assert.Equal(t, "error: 1 on profile 'name': exit status 1\n", strings.ReplaceAll(buffer.String(), "\r\n", "\n")) + assert.Equal(t, "error: 1 on profile 'name': exit status 1\n", strings.ReplaceAll(term.ReadRecording(), "\r\n", "\n")) } func TestEnvErrorCommandLine(t *testing.T) { - buffer := &bytes.Buffer{} - term.SetOutput(buffer) + term.StartRecording(term.RecordOutput) + defer term.StopRecording() profile := config.NewProfile(nil, "name") profile.RunAfterFail = []string{"echo cmd: $ERROR_COMMANDLINE"} wrapper := newResticWrapper(nil, "exit", false, profile, "1", nil, nil) err := wrapper.runProfile() assert.Error(t, err) - assert.Equal(t, "cmd: \"exit\" \"1\"\n", strings.ReplaceAll(buffer.String(), "\r\n", "\n")) + assert.Equal(t, "cmd: \"exit\" \"1\"\n", strings.ReplaceAll(term.ReadRecording(), "\r\n", "\n")) } func TestEnvErrorExitCode(t *testing.T) { - buffer := &bytes.Buffer{} - term.SetOutput(buffer) + term.StartRecording(term.RecordOutput) + defer term.StopRecording() profile := config.NewProfile(nil, "name") profile.RunAfterFail = []string{"echo exit-code: $ERROR_EXIT_CODE"} wrapper := newResticWrapper(nil, "exit", false, profile, "5", nil, nil) err := wrapper.runProfile() assert.Error(t, err) - assert.Equal(t, "exit-code: 5\n", strings.ReplaceAll(buffer.String(), "\r\n", "\n")) + assert.Equal(t, "exit-code: 5\n", strings.ReplaceAll(term.ReadRecording(), "\r\n", "\n")) } func TestEnvStderr(t *testing.T) { - buffer := &bytes.Buffer{} - term.SetOutput(buffer) + term.StartRecording(term.RecordOutput) + defer term.StopRecording() profile := config.NewProfile(nil, "name") profile.RunAfterFail = []string{"echo stderr: $ERROR_STDERR"} wrapper := newResticWrapper(nil, mockBinary, false, profile, "command", []string{"--stderr", "error_message", "--exit", "1"}, nil) err := wrapper.runProfile() assert.Error(t, err) - assert.Equal(t, "stderr: error_message", strings.TrimSpace(strings.ReplaceAll(buffer.String(), "\r\n", "\n"))) + assert.Equal(t, "stderr: error_message", strings.TrimSpace(strings.ReplaceAll(term.ReadRecording(), "\r\n", "\n"))) } func TestRunProfileWithSetPIDCallback(t *testing.T) { @@ -663,8 +662,8 @@ func TestRunShellCommands(t *testing.T) { } func TestRunStreamErrorHandler(t *testing.T) { - buffer := &bytes.Buffer{} - term.SetOutput(buffer) + term.StartRecording(term.RecordOutput) + defer term.StopRecording() errorCommand := `echo "detected error in $PROFILE_COMMAND"` @@ -675,7 +674,7 @@ func TestRunStreamErrorHandler(t *testing.T) { err := wrapper.runProfile() require.NoError(t, err) - assert.Contains(t, buffer.String(), "detected error in backup") + assert.Contains(t, term.ReadRecording(), "detected error in backup") } func TestRunStreamErrorHandlerDoesNotBreakCommand(t *testing.T) { From 117f6f8686787016736ef02b2192f285b780ed18 Mon Sep 17 00:00:00 2001 From: Juergen Kellerer Date: Mon, 1 May 2023 16:21:57 +0200 Subject: [PATCH 2/2] Output: Support extended parsing and redirection Also adds a status monitor when run in console mode --- config/flag.go | 5 +- config/flag_test.go | 2 +- config/info.go | 3 +- config/info_customizer.go | 25 ++ config/info_customizer_test.go | 31 +++ config/profile.go | 55 +++- constants/command.go | 1 + constants/parameter.go | 1 + main.go | 2 + monitor/console/progress.go | 459 +++++++++++++++++++++++++++++++ monitor/console/progress_test.go | 118 ++++++++ monitor/provider.go | 64 +++++ monitor/receiver.go | 3 + monitor/status.go | 16 +- monitor/status/profile.go | 43 +-- monitor/summary.go | 22 +- shell/analyser.go | 23 +- shell/command.go | 48 +++- shell/json_summary.go | 171 ++++++++---- shell/json_summary_test.go | 140 +++++----- shell/plain_summary.go | 74 +++-- shell/plain_summary_test.go | 120 +++++--- shell/summary.go | 16 ++ shell/summary_test.go | 47 +++- shell/util.go | 48 ++++ shell_command.go | 2 + wrapper.go | 46 +++- wrapper_stdout.go | 15 + wrapper_test.go | 4 + 29 files changed, 1340 insertions(+), 264 deletions(-) create mode 100644 monitor/console/progress.go create mode 100644 monitor/console/progress_test.go create mode 100644 monitor/provider.go create mode 100644 shell/summary.go create mode 100644 shell/util.go create mode 100644 wrapper_stdout.go diff --git a/config/flag.go b/config/flag.go index af5268b2b..bb44a3933 100644 --- a/config/flag.go +++ b/config/flag.go @@ -205,7 +205,10 @@ func stringify(value reflect.Value, onlySimplyValues bool) ([]string, bool) { sort.Strings(flatMap) return flatMap, len(flatMap) > 0 - case reflect.Interface: + case reflect.Interface, reflect.Pointer: + if value.IsNil() { + return emptyStringArray, false + } return stringify(value.Elem(), onlySimplyValues) default: diff --git a/config/flag_test.go b/config/flag_test.go index 2db4369a8..26d0cc131 100644 --- a/config/flag_test.go +++ b/config/flag_test.go @@ -13,7 +13,7 @@ func TestPointerValueShouldReturnErrorMessage(t *testing.T) { concrete := "test" value := &concrete argValue, _ := stringifyValueOf(value) - assert.Equal(t, []string{"ERROR: unexpected type ptr"}, argValue) + assert.Equal(t, []string{"test"}, argValue) } func TestNilValueFlag(t *testing.T) { diff --git a/config/info.go b/config/info.go index e3adf8ac8..444fbd1a9 100644 --- a/config/info.go +++ b/config/info.go @@ -659,11 +659,10 @@ func NewProfileInfoForRestic(resticVersion string, withDefaultOptions bool) Prof // Building initial set including generic sections (from data model) profileSet := propertySetFromType(infoTypes.profile) { - genericSection := propertySetFromType(infoTypes.genericSection) for _, name := range infoTypes.genericSectionNames { pi := new(propertyInfo) pi.nested = &namedPropertySet{ - propertySet: genericSection, + propertySet: propertySetFromType(infoTypes.genericSection), name: name, } profileSet.properties[name] = pi diff --git a/config/info_customizer.go b/config/info_customizer.go index 2538eab4f..6d520e371 100644 --- a/config/info_customizer.go +++ b/config/info_customizer.go @@ -119,6 +119,31 @@ func init() { } }) + // Profile: "stdout-hidden" default values + redirectOutput, noRedirectOutput := &RedirectOutputSection{StdoutFile: []string{""}}, &RedirectOutputSection{} + registerPropertyInfoCustomizer(func(sectionName, propertyName string, property accessibleProperty) { + if propertyName == constants.ParameterStdoutHidden { + property.basic().addDescriptionFilter(func(desc string) string { + var def string + if redirectOutput.IsOutputHidden(sectionName, false) == HideOutput { + def = `Default is "true" when redirected` + } else if noRedirectOutput.IsOutputHidden(sectionName, false) == HideOutput { + def = `Default is "true"` + } else if noRedirectOutput.IsOutputHidden(sectionName, true) == HideOutput { + if sectionName == constants.CommandBackup { + def = `Default is "true" when "extended-status" is set` + } else { + def = `Default is "true" when "json" is requested` + } + } + if def != "" { + desc = fmt.Sprintf("%s. %s", strings.TrimSuffix(strings.TrimSpace(desc), "."), def) + } + return desc + }) + } + }) + // Profile: exclude "help" (--help flag doesn't need to be in the reference) ExcludeProfileProperty("*", "help") } diff --git a/config/info_customizer_test.go b/config/info_customizer_test.go index 232ec3372..9f1c338b4 100644 --- a/config/info_customizer_test.go +++ b/config/info_customizer_test.go @@ -171,6 +171,37 @@ func TestDeprecatedSection(t *testing.T) { require.True(t, set.PropertyInfo("schedule").IsDeprecated()) } +func TestStdoutHiddenProperty(t *testing.T) { + var testType = struct { + RedirectOutputSection `mapstructure:",squash"` + }{} + + var tests = []struct { + section string + expected string + }{ + {section: constants.CommandCat, expected: `Default is "true" when redirected`}, + {section: constants.CommandDump, expected: `Default is "true" when redirected`}, + {section: constants.CommandCopy, expected: ``}, + {section: constants.CommandBackup, expected: ``}, // Default is "true" when "extended-status" is set + } + + for i, test := range tests { + t.Run(fmt.Sprintf("%d", i), func(t *testing.T) { + set := propertySetFromType(reflect.TypeOf(testType)) + require.NotNil(t, set.PropertyInfo(constants.ParameterStdoutHidden)) + + base := set.PropertyInfo(constants.ParameterStdoutHidden).Description() + assert.NotEmpty(t, base) + + customizeProperties(test.section, set.properties) + assert.Equal(t, + strings.TrimSuffix(strings.TrimSpace(fmt.Sprintf("%s. %s", base, test.expected)), "."), + set.PropertyInfo(constants.ParameterStdoutHidden).Description()) + }) + } +} + func TestHelpIsExcluded(t *testing.T) { assert.True(t, isExcluded("*", "help")) assert.False(t, isExcluded("*", "any-other")) diff --git a/config/profile.go b/config/profile.go index ad6394008..e82330d6a 100644 --- a/config/profile.go +++ b/config/profile.go @@ -42,6 +42,21 @@ type RunShellCommands interface { GetRunShellCommands() *RunShellCommandsSection } +type OutputHidden int + +const ( + ShowOutput = OutputHidden(iota) + HideJsonOutput + HideOutput +) + +// RedirectOutput provides access to output redirection settings +type RedirectOutput interface { + IsOutputHidden(commandName string, jsonRequested bool) OutputHidden + IsOutputRedirected() bool + GetRedirectOutput() *RedirectOutputSection +} + // OtherFlags provides access to dynamic commandline flags type OtherFlags interface { GetOtherFlags() map[string]any @@ -106,6 +121,7 @@ type Profile struct { type GenericSection struct { OtherFlagsSection `mapstructure:",squash"` RunShellCommandsSection `mapstructure:",squash"` + RedirectOutputSection `mapstructure:",squash"` } func (g *GenericSection) IsEmpty() bool { return g == nil } @@ -155,6 +171,7 @@ func (i *InitSection) getCommandFlags(profile *Profile) (flags *shell.Args) { type BackupSection struct { SectionWithScheduleAndMonitoring `mapstructure:",squash"` RunShellCommandsSection `mapstructure:",squash"` + RedirectOutputSection `mapstructure:",squash"` unresolvedSource []string CheckBefore bool `mapstructure:"check-before" description:"Check the repository before starting the backup command"` CheckAfter bool `mapstructure:"check-after" description:"Check the repository after the backup command succeeded"` @@ -165,7 +182,7 @@ type BackupSection struct { Iexclude []string `mapstructure:"iexclude" argument:"iexclude" argument-type:"no-glob"` ExcludeFile []string `mapstructure:"exclude-file" argument:"exclude-file"` FilesFrom []string `mapstructure:"files-from" argument:"files-from"` - ExtendedStatus bool `mapstructure:"extended-status" argument:"json"` + ExtendedStatus *bool `mapstructure:"extended-status" argument:"json"` NoErrorOnWarning bool `mapstructure:"no-error-on-warning" description:"Do not fail the backup when some files could not be read"` } @@ -176,6 +193,10 @@ func (b *BackupSection) resolve(p *Profile) { if len(b.StdinCommand) > 0 { b.UseStdin = true } + // Enable ExtendedStatus if unset and required for full functionality + if bools.IsUndefined(b.ExtendedStatus) && len(p.StatusFile)+len(p.PrometheusSaveToFile)+len(p.PrometheusPush) != 0 { + b.ExtendedStatus = bools.True() + } // Resolve source paths if b.unresolvedSource == nil { b.unresolvedSource = b.Source @@ -247,6 +268,7 @@ func (s *ScheduleBaseSection) GetSchedule() *ScheduleBaseSection { return s } type CopySection struct { SectionWithScheduleAndMonitoring `mapstructure:",squash"` RunShellCommandsSection `mapstructure:",squash"` + RedirectOutputSection `mapstructure:",squash"` Initialize bool `mapstructure:"initialize" description:"Initialize the secondary repository if missing"` InitializeCopyChunkerParams *bool `mapstructure:"initialize-copy-chunker-params" default:"true" description:"Copy chunker parameters when initializing the secondary repository"` Repository ConfidentialValue `mapstructure:"repository" description:"Destination repository to copy snapshots to"` @@ -392,6 +414,37 @@ type SendMonitoringHeader struct { Value ConfidentialValue `mapstructure:"value" examples:"\"Bearer ...\";\"Basic ...\";\"no-cache\";\"attachment;; filename=stats.txt\";\"application/json\";\"text/plain\";\"text/xml\"" description:"Value of the header"` } +// RedirectOutputSection contains settings to redirect restic command output +type RedirectOutputSection struct { + StdoutHidden *bool `mapstructure:"stdout-hidden" description:"Toggles whether stdout is hidden in console & log"` + StdoutFile []string `mapstructure:"stdout-file" description:"Redirect restic stdout to file(s)"` + StdoutCommand []string `mapstructure:"stdout-command" description:"Pipe restic stdout to shell command(s)"` +} + +func (r *RedirectOutputSection) GetRedirectOutput() *RedirectOutputSection { return r } + +func (r *RedirectOutputSection) IsOutputRedirected() bool { + return r != nil && + (len(r.StdoutFile) > 0 || len(r.StdoutCommand) > 0) +} + +func (r *RedirectOutputSection) IsOutputHidden(commandName string, jsonRequested bool) (hidden OutputHidden) { + if r != nil { + if bools.IsTrue(r.StdoutHidden) { + hidden = HideOutput + } else if !bools.IsStrictlyFalse(r.StdoutHidden) { + if commandName == constants.CommandDump || commandName == constants.CommandCat { + if r.IsOutputRedirected() { + hidden = HideOutput + } + } else if commandName == constants.CommandBackup && jsonRequested { + hidden = HideJsonOutput + } + } + } + return +} + // OtherFlagsSection contains additional restic command line flags type OtherFlagsSection struct { OtherFlags map[string]any `mapstructure:",remain"` diff --git a/constants/command.go b/constants/command.go index 7eabe2c88..ce72a9d52 100644 --- a/constants/command.go +++ b/constants/command.go @@ -10,6 +10,7 @@ const ( CommandSnapshots = "snapshots" CommandUnlock = "unlock" CommandMount = "mount" + CommandCat = "cat" CommandCopy = "copy" CommandDump = "dump" CommandFind = "find" diff --git a/constants/parameter.go b/constants/parameter.go index 39da9e902..bcffe0fd7 100644 --- a/constants/parameter.go +++ b/constants/parameter.go @@ -22,4 +22,5 @@ const ( ParameterPasswordFile = "password-file" ParameterPasswordCommand = "password-command" ParameterKeyHint = "key-hint" + ParameterStdoutHidden = "stdout-hidden" ) diff --git a/main.go b/main.go index 8e34d5858..44c416f9f 100644 --- a/main.go +++ b/main.go @@ -14,6 +14,7 @@ import ( "github.com/creativeprojects/resticprofile/config" "github.com/creativeprojects/resticprofile/constants" "github.com/creativeprojects/resticprofile/filesearch" + "github.com/creativeprojects/resticprofile/monitor/console" "github.com/creativeprojects/resticprofile/monitor/prom" "github.com/creativeprojects/resticprofile/monitor/status" "github.com/creativeprojects/resticprofile/preventsleep" @@ -403,6 +404,7 @@ func runProfile( } // add progress receivers if necessary + wrapper.addProgress(console.NewProgress(profile)) if profile.StatusFile != "" { wrapper.addProgress(status.NewProgress(profile, status.NewStatus(profile.StatusFile))) } diff --git a/monitor/console/progress.go b/monitor/console/progress.go new file mode 100644 index 000000000..70a666935 --- /dev/null +++ b/monitor/console/progress.go @@ -0,0 +1,459 @@ +package console + +import ( + "bytes" + "fmt" + "math" + "os" + "path/filepath" + "sort" + "strconv" + "strings" + "text/tabwriter" + "time" + + "github.com/creativeprojects/clog" + "github.com/creativeprojects/resticprofile/config" + "github.com/creativeprojects/resticprofile/constants" + "github.com/creativeprojects/resticprofile/monitor" + "github.com/creativeprojects/resticprofile/term" + "github.com/creativeprojects/resticprofile/util/ansi" + "golang.org/x/exp/slices" +) + +const ( + asciiBarStyle = 0 + defaultBarStyle = 6 + slimDefaultBarStyle = 4 + minBarLength = 3 + maxBarLength = 18 + maxFilesInStatus = 7 +) + +type Progress struct { + profile *config.Profile + command string + files []string + frame int +} + +func NewProgress(profile *config.Profile) *Progress { + return &Progress{ + profile: profile, + } +} + +func (p *Progress) Start(command string) { + p.command = command + p.frame = 0 +} + +func (p *Progress) Summary(command string, summary monitor.Summary, stderr string, result error) { + defer func() { p.command = "" }() + + term.SetStatus(nil) + term.WaitForStatus() + + if !summary.Extended || p.command != command { + return + } + + buffer := &bytes.Buffer{} + switch command { + case constants.CommandBackup: + p.createBackupSummary(buffer, summary, result) + } + + if buffer.Len() > 0 { + if result == nil { + clog.Infof("%s on profile '%s' succeeded:\n\n%s", command, p.profile.Name, buffer.String()) + } else { + clog.Errorf("%s on profile '%s' failed:\n\n%s", command, p.profile.Name, buffer.String()) + } + } +} + +func (p *Progress) createBackupSummary(buffer *bytes.Buffer, summary monitor.Summary, result error) { + tw := tabwriter.NewWriter(buffer, 4, 4, 1, ' ', 0) + defer tw.Flush() + + addOp := "Added" + if summary.DryRun { + addOp = "Would add" + } + + stats := "%s:\t%5d new,\t%5d changed,\t%5d unmodified\n" + _, _ = fmt.Fprintf(tw, stats, "Files", summary.FilesNew, summary.FilesChanged, summary.FilesUnmodified) + _, _ = fmt.Fprintf(tw, stats, "Dirs", summary.DirsNew, summary.DirsChanged, summary.DirsUnmodified) + if summary.BytesStored > 0 { + _, _ = fmt.Fprintf(tw, "%s to the repository: %s (%s stored)\n", addOp, formatBytes(summary.BytesAdded), formatBytes(summary.BytesStored)) + } else { + _, _ = fmt.Fprintf(tw, "%s to the repository: %s\n", addOp, formatBytes(summary.BytesAdded)) + } + _, _ = fmt.Fprintf(tw, "processed %d files, %s in %s\n", summary.FilesTotal, formatBytes(summary.BytesTotal), formatDuration(summary.Duration)) + if summary.SnapshotID != "" { + _, _ = fmt.Fprintf(tw, "snapshot %s saved\n", summary.SnapshotID) + } + if result != nil { + _, _ = fmt.Fprintf(tw, "error: %s\n", result.Error()) + } +} + +func (p *Progress) Status(status monitor.Status) { + if !term.OutputIsTerminal() { + return + } + + width, height := term.OsStdoutTerminalSize() + withAnsi := term.IsColorableOutput() + lines := p.createStatus(withAnsi, width, height, &status) + term.SetStatus(lines) + + p.frame++ + if p.frame >= 16 { + p.frame = 0 + } +} + +func (p *Progress) createStatus(withAnsi bool, width, height int, status *monitor.Status) (lines []string) { + if withAnsi && height > 4 && canUnicode { + // multiline version + height-- + if height > 7 { + lines = append(lines, p.createStatusHeaderLine(width/3*2, status)) + height-- + } + lines = append(lines, "") + lines = append(lines, p.createMultilineFilesStatus(width, height-3, status)...) + lines = append(lines, "") + lines = append(lines, p.createStatusLine(withAnsi, false, width, status)) + } else { + // slim version + withFiles := width >= 40 + lines = append(lines, p.createStatusLine(withAnsi, withFiles, width, status)) + } + return +} + +func (p *Progress) createFramedLine(width int, content, prefix, suffix, trailer []rune) string { + line := strings.Builder{} + contentLen := 0 + + if content != nil && prefix != nil && suffix != nil { + cl, _ := ansi.RunesLength(content, -1) + pl, _ := ansi.RunesLength(prefix, -1) + sl, _ := ansi.RunesLength(suffix, -1) + contentLen = cl + pl + sl + + line.WriteString(ansi.Gray(string(prefix))) + line.WriteString(string(content)) + line.WriteString(ansi.Gray(string(suffix))) + } + + // trailer + { + gray, notGray := ansi.ColorSequence(ansi.Gray) + line.WriteString(gray) + tr := string(trailer) + tl, _ := ansi.RunesLength(trailer, -1) + for remaining := width - contentLen; remaining >= tl; remaining -= tl { + line.WriteString(tr) + } + line.WriteString(notGray) + } + + return line.String() +} + +var ( + utfHeaderPrefix = []rune("β•Œβ•ŒβŸͺ ") + utfHeaderSuffix = []rune(" βŸ«β•Œβ•Œ") + utfHeaderTail = []rune(" ") + utfDelimiter = []rune(" ᜢ ") + asciiDelimiter = " | " +) + +func (p *Progress) createStatusHeaderLine(width int, status *monitor.Status) string { + if status.TotalFiles > 0 { + d := string(utfDelimiter) + header := fmt.Sprintf("%s %s %s %s %s", + ansi.Bold(status.TotalFiles), + ansi.Gray("files total "+d), + ansi.Bold(formatBytes(status.TotalBytes)), + ansi.Gray(" "+d+" elapsed "), + ansi.Bold(formatDuration(time.Second*time.Duration(status.SecondsElapsed))), + ) + return p.createFramedLine(width, []rune(header), utfHeaderPrefix, utfHeaderSuffix, utfHeaderTail) + } + return p.createFramedLine(width, nil, nil, nil, utfHeaderTail) +} + +var spinnerFrames = []rune("β—œβ—œβ—β—β—žβ—žβ—Ÿβ—Ÿ") + +func (p *Progress) createStatusLine(withAnsi, files bool, width int, status *monitor.Status) string { + line := strings.Builder{} + + remaining := width + filesReserved := width / 3 + if files && width > 30 { + remaining -= filesReserved + } + + // select delimiter + ansiDelimiter, delimiterLen := "", 0 + { + d := asciiDelimiter + if canUnicode { + d = string(utfDelimiter) + if remaining > 40 { + d = " " + d + " " + } + } + delimiterLen, _ = ansi.RunesLength([]rune(d), -1) + ansiDelimiter = ansi.Gray(d) + } + + // progress + barWidth := int(math.Max(minBarLength, math.Min(maxBarLength, float64(remaining)/3))) + bar := formatProgress(barStyle, barWidth, withAnsi, status.PercentDone) + if canUnicode && width > 40 { + var spinner string + if status.PercentDone < 0.999 { + spinner = string(spinnerFrames[p.frame%len(spinnerFrames)]) + } else { + spinner = ansi.Green("βœ”") + } + bar = ansi.Gray(string(utfHeaderPrefix)) + spinner + " " + bar + } + remaining -= len(bar) + delimiterLen + line.WriteString(bar) + + // volume & throughput + if remaining > 10 { + line.WriteString(ansiDelimiter) + processed := fmt.Sprintf("%s, %d errors", formatBytes(status.BytesDone), status.ErrorCount) + remaining -= len(processed) + delimiterLen + line.WriteString(processed) + } + if remaining > 10 && status.SecondsElapsed > 0 { + line.WriteString(ansiDelimiter) + speed := fmt.Sprintf("%s/s", formatBytes(status.BytesDone/uint64(status.SecondsElapsed))) + remaining -= len(speed) + delimiterLen + line.WriteString(speed) + } + + // time + if remaining > 10 && status.SecondsElapsed > 5 && status.SecondsRemaining < 7*24*60*60 { + line.WriteString(ansiDelimiter) + timeRemaining := "ETA " + formatDuration(time.Second*time.Duration(status.SecondsRemaining)) + remaining -= len(timeRemaining) + delimiterLen + line.WriteString(timeRemaining) + } + + // current files (if enabled for status line) + remaining += filesReserved + if remaining > 16 && files { + line.WriteString(ansiDelimiter) + + fileCount := len(status.CurrentFiles) + _, _ = fmt.Fprintf(&line, "[%d] ", fileCount) + remaining -= 4 + + if fileCount > 0 { + fileLen := remaining / fileCount + if fileCount > 1 { + fileLen -= delimiterLen + } + if fileLen < 20-delimiterLen { + fileLen = 20 - delimiterLen + } + for i, file := range status.CurrentFiles { + if len(file) > fileLen { + file = file[len(file)-fileLen:] + } + if i > 0 && remaining > 0 { + remaining -= delimiterLen + line.WriteString(ansiDelimiter) + } + if remaining <= 0 { + break + } + line.WriteString(file) + } + } + } + + line.WriteString(ansi.Gray(" ⟫")) + + return line.String() +} + +func (p *Progress) createMultilineFilesStatus(width, height int, status *monitor.Status) (lines []string) { + filesCount := height + if filesCount > maxFilesInStatus { + filesCount = maxFilesInStatus + } + + // sort and truncate + p.files = append(p.files, status.CurrentFiles...) + sort.Strings(p.files) + p.files = slices.Compact(p.files) + if len(p.files) > filesCount { + p.files = p.files[len(p.files)-filesCount:] + } + + // format output + maxFileLen := 0 + for _, file := range p.files { + if file = filepath.Base(file); len(file) > maxFileLen { + maxFileLen = len(file) + } + } + lineFormat := fmt.Sprintf(" %%s %%-%ds %%s ", maxFileLen) + + previousDir := "|initial|" + lines = make([]string, 0, len(p.files)) + current := make([]string, 0, len(status.CurrentFiles)) + for _, file := range p.files { + inCurrent := slices.Contains(status.CurrentFiles, file) + + dir := filepath.Dir(file) + file = filepath.Base(file) + if dir == previousDir { + dir = "" + } else { + previousDir = dir + } + + if pathLen := 11 + maxFileLen + len(dir); pathLen > width { + dir = dir[len(dir)-(pathLen-width):] + if width >= 30 { + dir = "..." + dir[3:] + } + } + if dir != "" { + dir = fmt.Sprintf("[ %s ]", dir) + } + + if inCurrent { + current = append(current, fmt.Sprintf(lineFormat, ansi.Bold(ansi.Cyan(">")), file, ansi.Gray(dir))) + } else { + lines = append(lines, ansi.Gray(fmt.Sprintf(lineFormat, " ", file, dir))) + } + } + lines = append(lines, current...) + return +} + +var byteUnits = []string{"Bytes", "KiB", "MiB", "GiB", "TiB"} + +func formatBytes(bytes uint64) string { + value := float64(bytes) + unit := 0 + for ; unit < len(byteUnits)-1; unit++ { + if value < 1024 { + break + } else { + value /= 1024 + } + } + format := "%4.0f %s" + if unit > 0 { + digits := int(math.Max(0, math.Ceil(3-math.Log10(value))-1)) + if digits > 0 { + format = fmt.Sprintf("%%.%df %%s", digits) + } + } + return fmt.Sprintf(format, value, byteUnits[unit]) +} + +func formatDuration(duration time.Duration) string { + const TimeOnly = "15:04:05" // use time.TimeOnly when go 1.20 is min ver + tf := time.UnixMilli(duration.Milliseconds()).UTC().Format(TimeOnly) + if days := math.Floor(duration.Hours() / 24); days >= 1 { + return fmt.Sprintf("%dd %s", int(days), tf) + } + return strings.TrimPrefix(tf, "00:") +} + +var barStyles = [][]rune{ + []rune(" -+*#"), // ASCII only + []rune(" β–‘β–’β–“β–ˆ"), + []rune(" β–β–Žβ–β–Œβ–‹β–Šβ–‰β–ˆ"), + []rune(" β–β–‚β–ƒβ–„β–…β–†β–‡β–ˆ"), + []rune(" β‘€β‘„β‘†β‘‡β‘β‘Ÿβ‘Ώβ£Ώ"), // slim-default + []rune(" ⑀⣀⣠⣀⣦⣢⣾⣿"), + []rune(" β „β †β ‡β β Ÿβ Ώ"), // default + []rune(" β „β €β ΄β Άβ ·β Ώ"), +} + +var barStyle = func() int { + idx, err := strconv.Atoi(os.Getenv("RESTICPROFILE_PROGRESS_BAR_STYLE")) + if err != nil { + idx = asciiBarStyle + if term.IsColorableOutput() { + idx = defaultBarStyle + } + } + return idx +}() + +var canUnicode = barStyle > 0 + +func formatProgress(style, width int, withAnsi bool, progress float64) string { + out := strings.Builder{} + remaining := width + + if style >= 0 && style < len(barStyles) { + if width > 11 { + remaining = 6 + width -= 6 + } else { + if style == defaultBarStyle { + style = slimDefaultBarStyle + } + remaining = 0 + } + + chars := barStyles[style] + ticks := len(chars) * width + lit := int(math.Round(float64(ticks) * progress)) + + for i := 0; i < width; i++ { + idx := 0 + if lit >= len(chars) { + idx = len(chars) - 1 + lit -= len(chars) + } else if lit > 0 { + idx = lit - 1 + lit = 0 + } + out.WriteRune(chars[idx]) + } + + if withAnsi { + greenBar := ansi.Green(out.String()) + out.Reset() + out.WriteString(greenBar) + } + } + + if remaining >= 4 { + if out.Len() > 0 && remaining > 4 { + out.WriteString(" ") + remaining-- + } + format := "%4.1f%%" + if remaining < 5 { + format = "%3.0f%%" + } else if progress >= .999 { + format = "%4.0f%%" + } + _, _ = fmt.Fprintf(&out, format, progress*100) + } + + return out.String() +} + +// Verify interface +var _ monitor.Receiver = &Progress{} diff --git a/monitor/console/progress_test.go b/monitor/console/progress_test.go new file mode 100644 index 000000000..10828554f --- /dev/null +++ b/monitor/console/progress_test.go @@ -0,0 +1,118 @@ +package console + +import ( + "fmt" + "testing" + "time" + + "github.com/stretchr/testify/assert" +) + +func TestFormatBytes(t *testing.T) { + tests := []struct { + expected string + bytes uint64 + }{ + {expected: " 0 Bytes", bytes: 0}, + {expected: " 500 Bytes", bytes: 500}, + {expected: "1000 Bytes", bytes: 1000}, + {expected: "1.00 KiB", bytes: 1024}, + {expected: "1023 KiB", bytes: 1023 * 1024}, + {expected: "1.00 MiB", bytes: 1024 * 1024}, + {expected: "1.01 MiB", bytes: 10*1024 + 1024*1024}, + {expected: " 512 MiB", bytes: 512 * 1024 * 1024}, + {expected: "64.0 MiB", bytes: 64 * 1024 * 1024}, + {expected: "64.1 MiB", bytes: 100*1024 + 64*1024*1024}, + {expected: "1.00 GiB", bytes: 1024 * 1024 * 1024}, + {expected: "1.00 TiB", bytes: 1024 * 1024 * 1024 * 1024}, + {expected: "2.00 TiB", bytes: 2 * 1024 * 1024 * 1024 * 1024}, + {expected: "1.50 TiB", bytes: 1.5 * 1024 * 1024 * 1024 * 1024}, + } + for idx, test := range tests { + t.Run(fmt.Sprintf("%d", idx), func(t *testing.T) { + assert.Equal(t, test.expected, formatBytes(test.bytes)) + }) + } +} + +func TestFormatDuration(t *testing.T) { + tests := []struct { + duration time.Duration + expected string + }{ + {expected: "00:00", duration: 0}, + {expected: "00:01", duration: time.Second}, + {expected: "01:00", duration: time.Minute}, + {expected: "01:01", duration: time.Minute + time.Second}, + {expected: "59:59", duration: 59*time.Minute + 59*time.Second}, + {expected: "01:00:00", duration: time.Hour}, + {expected: "01:01:00", duration: time.Hour + time.Minute}, + {expected: "01:01:01", duration: time.Hour + time.Minute + time.Second}, + {expected: "23:59:00", duration: 23*time.Hour + 59*time.Minute}, + {expected: "23:59:59", duration: 24*time.Hour - 1}, + {expected: "1d 00:00:00", duration: 24 * time.Hour}, + {expected: "1d 01:00:00", duration: 25 * time.Hour}, + {expected: "2d 00:00:00", duration: 48 * time.Hour}, + {expected: "2d 01:00:00", duration: 49 * time.Hour}, + } + for idx, test := range tests { + t.Run(fmt.Sprintf("%d", idx), func(t *testing.T) { + assert.Equal(t, test.expected, formatDuration(test.duration)) + }) + } +} + +func TestFormatProgress(t *testing.T) { + tests := []struct { + style, width int + progress float64 + expected string + }{ + {expected: " ", style: 0, width: 8, progress: 0}, + {expected: "## ", style: 0, width: 8, progress: 0.25}, + {expected: "#### ", style: 0, width: 8, progress: 0.5}, + {expected: "###### ", style: 0, width: 8, progress: 0.75}, + {expected: "########", style: 0, width: 8, progress: 1}, + + {expected: " ", style: 0, width: 2, progress: 1 * 1. / 9}, + {expected: "- ", style: 0, width: 2, progress: 2 * 1. / 9}, + {expected: "+ ", style: 0, width: 2, progress: 3 * 1. / 9}, + {expected: "* ", style: 0, width: 2, progress: 4 * 1. / 9}, + {expected: "# ", style: 0, width: 2, progress: 5 * 1. / 9}, + {expected: "#-", style: 0, width: 2, progress: 6 * 1. / 9}, + {expected: "#+", style: 0, width: 2, progress: 7 * 1. / 9}, + {expected: "#*", style: 0, width: 2, progress: 8 * 1. / 9}, + {expected: "##", style: 0, width: 2, progress: 9 * 1. / 9}, + + {expected: " ", style: 0, width: 2, progress: 0.5 * 1. / 9}, + {expected: " ", style: 0, width: 2, progress: 1.0 * 1. / 9}, + {expected: "- ", style: 0, width: 2, progress: 1.5 * 1. / 9}, + {expected: "- ", style: 0, width: 2, progress: 2.0 * 1. / 9}, + {expected: "+ ", style: 0, width: 2, progress: 2.5 * 1. / 9}, + + {expected: "⑇", style: defaultBarStyle, width: 1, progress: 0.5}, + {expected: "β£Ώ ", style: defaultBarStyle, width: 2, progress: 0.5}, + {expected: "⣿⑇ ", style: defaultBarStyle, width: 3, progress: 0.5}, + {expected: "β£Ώβ£Ώ ", style: defaultBarStyle, width: 4, progress: 0.5}, + {expected: "β Ώβ Ώβ Ώ 50.0%", style: defaultBarStyle, width: 12, progress: 0.5}, + + {expected: "β–ˆβ–’ 25.0%", style: 1, width: 12, progress: 0.25}, + {expected: "β–ˆβ–ˆβ–ˆ 50.0%", style: 1, width: 12, progress: 0.5}, + {expected: "β–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆ 99.5%", style: 1, width: 12, progress: 0.995}, + {expected: "β–ˆβ–ˆβ–ˆβ–ˆβ–ˆβ–ˆ 100%", style: 1, width: 12, progress: 1}, + + {expected: " 50%", style: -1, width: 4, progress: 0.5}, + {expected: "100%", style: -1, width: 4, progress: 1}, + + {expected: "50.0%", style: -1, width: 5, progress: 0.5}, + {expected: " 100%", style: -1, width: 5, progress: 1}, + {expected: "50.0%", style: -1, width: 10, progress: 0.5}, + {expected: " 100%", style: -1, width: 10, progress: 1}, + } + for idx, test := range tests { + t.Run(fmt.Sprintf("%d", idx), func(t *testing.T) { + actual := formatProgress(test.style, test.width, false, test.progress) + assert.Equalf(t, test.expected, actual, "progress: %.2f", test.progress) + }) + } +} diff --git a/monitor/provider.go b/monitor/provider.go new file mode 100644 index 000000000..09ad98e05 --- /dev/null +++ b/monitor/provider.go @@ -0,0 +1,64 @@ +package monitor + +import ( + "sync" +) + +// Provider declares callbacks to provide status and final summary of restic commands +type Provider interface { + // ProvideStatus is called by an output scanner when restic provided the current status. + // The status update must happen inside the callback function which may run under a mutex + ProvideStatus(func(status *Status)) + // UpdateSummary is called by an output scanner when restic provided an update to the final summary. + // The summary update must happen inside the callback function which may run under a mutex + UpdateSummary(func(summary *Summary)) + // CurrentSummary returns a copy of the current known summary + CurrentSummary() Summary + // ProvideSummary is called when the restic command finished to finalize the summary. + ProvideSummary(command string, stderr string, result error) +} + +// NewProvider creates a new provider that forwards status and summary to the specified receivers +func NewProvider(receiver ...Receiver) Provider { + return &provider{receiver: receiver} +} + +type provider struct { + mutex sync.Mutex + summary Summary + receiver []Receiver + final bool +} + +func (p *provider) ProvideStatus(fn func(status *Status)) { + status := new(Status) + fn(status) + for _, receiver := range p.receiver { + receiver.Status(*status) + } +} + +func (p *provider) UpdateSummary(fn func(summary *Summary)) { + p.mutex.Lock() + defer p.mutex.Unlock() + if !p.final { + fn(&p.summary) + } +} + +func (p *provider) CurrentSummary() Summary { + p.mutex.Lock() + defer p.mutex.Unlock() + return p.summary +} + +func (p *provider) ProvideSummary(command string, stderr string, result error) { + p.mutex.Lock() + defer p.mutex.Unlock() + if !p.final { + p.final = true + for _, receiver := range p.receiver { + receiver.Summary(command, p.summary, stderr, result) + } + } +} diff --git a/monitor/receiver.go b/monitor/receiver.go index 5e4291aaa..32201411b 100644 --- a/monitor/receiver.go +++ b/monitor/receiver.go @@ -1,5 +1,8 @@ package monitor +// Receiver is an interface for implementations interested in the restic command status and summary +// +//go:generate mockery --name=Receiver type Receiver interface { // Start of a command Start(command string) diff --git a/monitor/status.go b/monitor/status.go index 955c22b0d..e29aeaf7d 100644 --- a/monitor/status.go +++ b/monitor/status.go @@ -1,11 +1,13 @@ package monitor type Status struct { - PercentDone float64 - TotalFiles int - FilesDone int - TotalBytes int64 - BytesDone int64 - ErrorCount int - CurrentFiles []string + PercentDone float64 + SecondsElapsed int + SecondsRemaining int + TotalFiles int64 + FilesDone int64 + TotalBytes uint64 + BytesDone uint64 + ErrorCount int64 + CurrentFiles []string } diff --git a/monitor/status/profile.go b/monitor/status/profile.go index a7064128e..84f4830a2 100644 --- a/monitor/status/profile.go +++ b/monitor/status/profile.go @@ -30,26 +30,22 @@ type CommandStatus struct { // BackupStatus contains the last backup status type BackupStatus struct { CommandStatus - FilesNew int `json:"files_new"` - FilesChanged int `json:"files_changed"` - FilesUnmodified int `json:"files_unmodified"` - DirsNew int `json:"dirs_new"` - DirsChanged int `json:"dirs_changed"` - DirsUnmodified int `json:"dirs_unmodified"` - FilesTotal int `json:"files_total"` + FilesNew int64 `json:"files_new"` + FilesChanged int64 `json:"files_changed"` + FilesUnmodified int64 `json:"files_unmodified"` + DirsNew int64 `json:"dirs_new"` + DirsChanged int64 `json:"dirs_changed"` + DirsUnmodified int64 `json:"dirs_unmodified"` + FilesTotal int64 `json:"files_total"` BytesAdded uint64 `json:"bytes_added"` BytesTotal uint64 `json:"bytes_total"` + SnapshotID string `json:"snapshot_id"` } // BackupSuccess indicates the last backup was successful func (p *Profile) BackupSuccess(summary monitor.Summary, stderr string) *Profile { p.Backup = &BackupStatus{ - CommandStatus: CommandStatus{ - Success: true, - Time: time.Now(), - Duration: int64(math.Ceil(summary.Duration.Seconds())), - Stderr: stderr, - }, + CommandStatus: *newSuccess(summary.Duration, stderr), FilesNew: summary.FilesNew, FilesChanged: summary.FilesChanged, FilesUnmodified: summary.FilesUnmodified, @@ -59,30 +55,15 @@ func (p *Profile) BackupSuccess(summary monitor.Summary, stderr string) *Profile FilesTotal: summary.FilesTotal, BytesAdded: summary.BytesAdded, BytesTotal: summary.BytesTotal, + SnapshotID: summary.SnapshotID, } return p } // BackupError sets the error of the last backup func (p *Profile) BackupError(err error, summary monitor.Summary, stderr string) *Profile { - p.Backup = &BackupStatus{ - CommandStatus: CommandStatus{ - Success: false, - Time: time.Now(), - Error: err.Error(), - Duration: int64(math.Ceil(summary.Duration.Seconds())), - Stderr: stderr, - }, - FilesNew: 0, - FilesChanged: 0, - FilesUnmodified: 0, - DirsNew: 0, - DirsChanged: 0, - DirsUnmodified: 0, - FilesTotal: 0, - BytesAdded: 0, - BytesTotal: 0, - } + p.BackupSuccess(summary, stderr) + p.Backup.CommandStatus = *newError(err, summary.Duration, stderr) return p } diff --git a/monitor/summary.go b/monitor/summary.go index baf05b0a0..6a8e945d6 100644 --- a/monitor/summary.go +++ b/monitor/summary.go @@ -5,15 +5,20 @@ import "time" // Summary of the profile run type Summary struct { Duration time.Duration - FilesNew int - FilesChanged int - FilesUnmodified int - DirsNew int - DirsChanged int - DirsUnmodified int - FilesTotal int + FilesNew int64 + FilesChanged int64 + FilesUnmodified int64 + DirsNew int64 + DirsChanged int64 + DirsUnmodified int64 + FilesTotal int64 BytesAdded uint64 + BytesStored uint64 BytesTotal uint64 + Compression float64 + SnapshotID string + Extended bool + DryRun bool OutputAnalysis OutputAnalysis } @@ -28,4 +33,7 @@ type OutputAnalysis interface { // GetRemoteLockedBy returns who locked the remote lock, if available. GetRemoteLockedBy() (string, bool) + + // GetFailedFiles returns a list of files that failed to get processed. + GetFailedFiles() []string } diff --git a/shell/analyser.go b/shell/analyser.go index 05320fbcc..dd6e1c223 100644 --- a/shell/analyser.go +++ b/shell/analyser.go @@ -11,6 +11,7 @@ import ( "github.com/creativeprojects/clog" "github.com/creativeprojects/resticprofile/monitor" + "golang.org/x/exp/slices" ) type analyserCallback struct { @@ -36,9 +37,10 @@ type OutputAnalyser struct { } var outputAnalyserPatterns = map[string]*regexp.Regexp{ - "lock-failure,who": regexp.MustCompile("unable to create lock.+already locked.+?by (.+)$"), - "lock-failure,age": regexp.MustCompile("lock was created at.+\\(([^()]+)\\s+ago\\)"), - "lock-failure,stale": regexp.MustCompile("the\\W+unlock\\W+command can be used to remove stale locks"), + "lock-failure,who": regexp.MustCompile("unable to create lock.+already locked.+?by (.+)$"), + "lock-failure,age": regexp.MustCompile("lock was created at.+\\(([^()]+)\\s+ago\\)"), + "lock-failure,stale": regexp.MustCompile("the\\W+unlock\\W+command can be used to remove stale locks"), + "file-read,archival,keep": regexp.MustCompile(`^\{"message_type":"error",.+,"during":"archival","item":"([^"]+)".*}$`), } func NewOutputAnalyser() *OutputAnalyser { @@ -160,6 +162,12 @@ func (a OutputAnalyser) GetRemoteLockedBy() (string, bool) { return "", false } +func (a OutputAnalyser) GetFailedFiles() []string { + a.lock.Lock() + defer a.lock.Unlock() + return slices.Clone(a.matches["file-read,archival,keep"]) +} + func (a OutputAnalyser) AnalyseStringLines(output string) error { return a.AnalyseLines(strings.NewReader(output)) } @@ -187,9 +195,14 @@ func (a OutputAnalyser) analyseLine(line string) (err error) { for _, pattern := range a.patterns { match := pattern.expression.FindStringSubmatch(line) if match != nil { - a.matches[pattern.name] = match + name := strings.Split(pattern.name, ",") + if name[len(name)-1] == "keep" { + a.matches[pattern.name] = append(a.matches[pattern.name], match[1:]...) + } else { + a.matches[pattern.name] = match + } - baseName := strings.Split(pattern.name, ",")[0] + baseName := name[0] a.counts[baseName]++ if err == nil { diff --git a/shell/command.go b/shell/command.go index e8c7d1023..0c0f08600 100644 --- a/shell/command.go +++ b/shell/command.go @@ -29,7 +29,7 @@ type SetPID func(pid int) // ScanOutput is a callback to scan the default output of the command // The implementation is expected to send everything read from the reader back to the writer -type ScanOutput func(r io.Reader, summary *monitor.Summary, w io.Writer) error +type ScanOutput func(r io.Reader, provider monitor.Provider, w io.Writer) error // Command holds the configuration to run a shell command type Command struct { @@ -43,6 +43,7 @@ type Command struct { Stderr io.Writer SetPID SetPID ScanStdout ScanOutput + Receivers []monitor.Receiver sigChan chan os.Signal done chan interface{} analyser *OutputAnalyser @@ -80,11 +81,14 @@ func (c *Command) Run() (monitor.Summary, string, error) { var err error var stdout, stderr io.ReadCloser - summary := monitor.Summary{OutputAnalysis: c.analyser.Reset()} + provider := monitor.NewProvider(c.Receivers...) + provider.UpdateSummary(func(summary *monitor.Summary) { + summary.OutputAnalysis = c.analyser.Reset() + }) command, args, err := c.GetShellCommand() if err != nil { - return summary, "", err + return provider.CurrentSummary(), "", err } // clog.Tracef("command: %s %q", command, args) @@ -94,7 +98,7 @@ func (c *Command) Run() (monitor.Summary, string, error) { // install a pipe for scanning the output stdout, err = cmd.StdoutPipe() if err != nil { - return summary, "", err + return provider.CurrentSummary(), "", err } } else { cmd.Stdout = c.Stdout @@ -116,7 +120,7 @@ func (c *Command) Run() (monitor.Summary, string, error) { // spawn the child process if err = cmd.Start(); err != nil { - return summary, "", err + return provider.CurrentSummary(), "", err } if c.SetPID != nil { // send the PID back (to write down in a lockfile) @@ -132,18 +136,24 @@ func (c *Command) Run() (monitor.Summary, string, error) { c.propagateSignal(cmd.Process) // close stdin (if possible) to unblock Wait on cmd.Process if in, canClose := cmd.Stdin.(io.Closer); canClose && in != nil { - in.Close() + _ = in.Close() } }() } - // output scanner - if stdout != nil { - err = c.ScanStdout(stdout, &summary, c.Stdout) - if err != nil { - return summary, "", err + // run output scanner (async) + scanResult := make(chan error, 1) // must be buffered chan (to not block on panic in ScanStdout) + go func() { + var err error + defer func() { + scanResult <- err + close(scanResult) + }() + if stdout != nil { + err = c.ScanStdout(stdout, provider, c.Stdout) + _, _ = io.Copy(c.Stdout, stdout) // copy remaining } - } + }() // handle command errors errors := &bytes.Buffer{} @@ -167,10 +177,20 @@ func (c *Command) Run() (monitor.Summary, string, error) { err = cmd.Wait() } + // wait for output scanner + if scanErr := <-scanResult; scanErr != nil { + clog.Errorf("failed scanning stdout from command: %s ; Cause: %s", command, scanErr.Error()) + if err == nil { + err = scanErr + } + } + // finish summary - summary.Duration = time.Since(start) + provider.UpdateSummary(func(summary *monitor.Summary) { + summary.Duration = time.Since(start) + }) errorText := errors.String() - return summary, errorText, err + return provider.CurrentSummary(), errorText, err } // GetShellCommand transforms the command line and arguments to be launched via a shell (sh or cmd.exe) diff --git a/shell/json_summary.go b/shell/json_summary.go index 0a4aad35d..07ef31223 100644 --- a/shell/json_summary.go +++ b/shell/json_summary.go @@ -4,69 +4,146 @@ import ( "bufio" "bytes" "encoding/json" - "io" - "runtime" - + "github.com/creativeprojects/clog" "github.com/creativeprojects/resticprofile/monitor" + "io" + "math" + "time" ) -type ResticJsonSummary struct { - MessageType string `json:"message_type"` - FilesNew int `json:"files_new"` - FilesChanged int `json:"files_changed"` - FilesUnmodified int `json:"files_unmodified"` - DirsNew int `json:"dirs_new"` - DirsChanged int `json:"dirs_changed"` - DirsUnmodified int `json:"dirs_unmodified"` - DataBlobs int `json:"data_blobs"` - TreeBlobs int `json:"tree_blobs"` +type resticJsonMessage struct { + MessageType string `json:"message_type"` +} + +type resticJsonBackupSummary struct { + resticJsonMessage // "summary" + FilesNew int64 `json:"files_new"` + FilesChanged int64 `json:"files_changed"` + FilesUnmodified int64 `json:"files_unmodified"` + DirsNew int64 `json:"dirs_new"` + DirsChanged int64 `json:"dirs_changed"` + DirsUnmodified int64 `json:"dirs_unmodified"` + DataBlobs int64 `json:"data_blobs"` + TreeBlobs int64 `json:"tree_blobs"` DataAdded uint64 `json:"data_added"` - TotalFilesProcessed int `json:"total_files_processed"` + TotalFilesProcessed int64 `json:"total_files_processed"` TotalBytesProcessed uint64 `json:"total_bytes_processed"` TotalDuration float64 `json:"total_duration"` SnapshotID string `json:"snapshot_id"` + DryRun bool `json:"dry_run"` } -// ScanBackupJson should populate the backup summary values from the output of the --json flag -var ScanBackupJson ScanOutput = func(r io.Reader, summary *monitor.Summary, w io.Writer) error { - bogusPrefix := []byte("\r\x1b[2K") - jsonPrefix := []byte(`{"message_type":"`) - summaryPrefix := []byte(`{"message_type":"summary",`) - jsonSuffix := []byte("}") - eol := "\n" - if runtime.GOOS == "windows" { - eol = "\r\n" - } - scanner := bufio.NewScanner(r) +type resticJsonBackupStatus struct { + resticJsonMessage // "status" + Action string `json:"action"` + ActionDuration float64 `json:"duration"` + SecondsElapsed int `json:"seconds_elapsed"` + SecondsRemaining int `json:"seconds_remaining"` + PercentDone float64 `json:"percent_done"` + TotalFiles int64 `json:"total_files"` + FilesDone int64 `json:"files_done"` + TotalBytes uint64 `json:"total_bytes"` + BytesDone uint64 `json:"bytes_done"` + ErrorCount int64 `json:"error_count"` + CurrentFiles []string `json:"current_files"` +} + +type resticJsonBackupVerboseStatus struct { + resticJsonMessage // "verbose_status" + Action string `json:"action"` + Item string `json:"item"` + Duration float64 `json:"duration"` // in seconds + DataSize uint64 `json:"data_size"` + DataSizeInRepo uint64 `json:"data_size_in_repo"` + MetadataSize uint64 `json:"metadata_size"` + MetadataSizeInRepo uint64 `json:"metadata_size_in_repo"` + TotalFiles int64 `json:"total_files"` +} + +var ( + jsonPrefix = []byte(`{"message_type":"`) + jsonSummaryPrefix = []byte(`{"message_type":"summary",`) + jsonStatusPrefix = []byte(`{"message_type":"status",`) + jsonVerboseStatusPrefix = []byte(`{"message_type":"verbose_status",`) + jsonSuffix = []byte("}") +) + +// scanBackupJson should populate the backup summary values from the output of the --json flag +var scanBackupJson ScanOutput = func(r io.Reader, provider monitor.Provider, w io.Writer) error { + scanner := bufio.NewScanner(io.TeeReader(r, w)) + stored, added := uint64(0), uint64(0) + compressed, uncompressed := uint64(0), uint64(0) + for scanner.Scan() { line := scanner.Bytes() line = bytes.TrimPrefix(line, bogusPrefix) + if bytes.HasPrefix(line, jsonPrefix) && bytes.HasSuffix(line, jsonSuffix) { - if bytes.HasPrefix(line, summaryPrefix) { - jsonSummary := ResticJsonSummary{} - err := json.Unmarshal(line, &jsonSummary) - if err != nil { - continue + clog.Infof(string(line)) + + var err error + if bytes.HasPrefix(line, jsonVerboseStatusPrefix) { + parsed := new(resticJsonBackupVerboseStatus) + if err = json.Unmarshal(line, &parsed); err == nil { + switch parsed.Action { + case "new": + stored += parsed.DataSizeInRepo + parsed.MetadataSizeInRepo + added += parsed.DataSize + parsed.MetadataSize + case "modified": + compressed += parsed.DataSizeInRepo + parsed.MetadataSizeInRepo + uncompressed += parsed.DataSize + parsed.MetadataSize + } + } + } else if bytes.HasPrefix(line, jsonStatusPrefix) { + parsed := new(resticJsonBackupStatus) + if err = json.Unmarshal(line, &parsed); err == nil && parsed.Action == "" { + provider.ProvideStatus(func(status *monitor.Status) { + status.TotalBytes = parsed.TotalBytes + status.BytesDone = parsed.BytesDone + status.TotalFiles = parsed.TotalFiles + status.CurrentFiles = parsed.CurrentFiles + status.FilesDone = parsed.FilesDone + status.ErrorCount = parsed.ErrorCount + status.PercentDone = math.Min(1, math.Max(0, parsed.PercentDone)) + status.SecondsElapsed = parsed.SecondsElapsed + status.SecondsRemaining = parsed.SecondsRemaining + }) } - summary.FilesNew = jsonSummary.FilesNew - summary.FilesChanged = jsonSummary.FilesChanged - summary.FilesUnmodified = jsonSummary.FilesUnmodified - summary.DirsNew = jsonSummary.DirsNew - summary.DirsChanged = jsonSummary.DirsChanged - summary.DirsUnmodified = jsonSummary.DirsUnmodified - summary.FilesTotal = jsonSummary.TotalFilesProcessed - summary.BytesAdded = jsonSummary.DataAdded - summary.BytesTotal = jsonSummary.TotalBytesProcessed + } else if bytes.HasPrefix(line, jsonSummaryPrefix) { + parsed := new(resticJsonBackupSummary) + if err = json.Unmarshal(line, &parsed); err == nil { + provider.UpdateSummary(func(summary *monitor.Summary) { + summary.DryRun = parsed.DryRun + summary.Extended = true + summary.FilesNew = parsed.FilesNew + summary.FilesChanged = parsed.FilesChanged + summary.FilesUnmodified = parsed.FilesUnmodified + summary.DirsNew = parsed.DirsNew + summary.DirsChanged = parsed.DirsChanged + summary.DirsUnmodified = parsed.DirsUnmodified + summary.FilesTotal = parsed.TotalFilesProcessed + summary.BytesAdded = parsed.DataAdded + summary.BytesStored = stored + summary.BytesTotal = parsed.TotalBytesProcessed + summary.Duration = time.Duration(math.Round(float64(time.Second) * parsed.TotalDuration)) + summary.SnapshotID = parsed.SnapshotID + if added+uncompressed > 0 && stored+compressed > 0 { + summary.Compression = float64(stored+compressed) / float64(added+uncompressed) + } + }) + } + } + if err != nil { + clog.Trace("parsing failed with %q for line:\n%s", err.Error(), string(line)) } - continue } - // write to the output if the line wasn't a json message - _, _ = w.Write(line) - _, _ = w.Write([]byte(eol)) } + return scanner.Err() +} - if err := scanner.Err(); err != nil { - return err - } - return nil +func HideJson(output io.Writer) io.WriteCloser { + return LineOutputFilter(output, func(line []byte) bool { + line = bytes.TrimPrefix(line, bogusPrefix) + return !bytes.HasPrefix(line, jsonPrefix) || !bytes.HasSuffix(line, jsonSuffix) + }) } diff --git a/shell/json_summary_test.go b/shell/json_summary_test.go index 562361a7f..a6f5a875a 100644 --- a/shell/json_summary_test.go +++ b/shell/json_summary_test.go @@ -1,70 +1,81 @@ package shell import ( - "os" - "runtime" - "strings" - "testing" - "github.com/creativeprojects/resticprofile/monitor" + "github.com/creativeprojects/resticprofile/monitor/mocks" + "github.com/creativeprojects/resticprofile/platform" + "github.com/creativeprojects/resticprofile/util" "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/mock" "github.com/stretchr/testify/require" -) - -const ( - summary = `{"message_type":"summary","files_new":10,"files_changed":11,"files_unmodified":211,"dirs_new":0,"dirs_changed":12,"dirs_unmodified":58,"data_blobs":6,"tree_blobs":7,"data_added":8,"total_files_processed":232,"total_bytes_processed":362946952,"total_duration":0.220900201,"snapshot_id":"196f3b36"}` + "io" + "math" + "strings" + "testing" + "time" ) func TestScanJsonSummary(t *testing.T) { // example of restic output (beginning and end of the output) resticOutput := `{"message_type":"status","percent_done":0,"total_files":1,"total_bytes":10244} {"message_type":"status","percent_done":0.028711419769115988,"total_files":213,"files_done":13,"total_bytes":362948126,"bytes_done":10420756,"current_files":["/go/src/github.com/creativeprojects/resticprofile/build/restic","/go/src/github.com/creativeprojects/resticprofile/build/resticprofile"]} -{"message_type":"status","percent_done":0.9763572825280271,"total_files":213,"files_done":163,"total_bytes":362948126,"bytes_done":354367046,"current_files":["/go/src/github.com/creativeprojects/resticprofile/resticprofile_darwin","/go/src/github.com/creativeprojects/resticprofile/resticprofile_linux"]} -{"message_type":"status","seconds_elapsed":1,"percent_done":1,"total_files":213,"files_done":212,"total_bytes":362948126,"bytes_done":362948126,"current_files":["/go/src/github.com/creativeprojects/resticprofile/resticprofile_linux"]} +{"message_type":"status","percent_done":0.9763572825280271,"error_count":1,"total_files":213,"files_done":163,"total_bytes":362948126,"bytes_done":354367046,"current_files":["/go/src/github.com/creativeprojects/resticprofile/resticprofile_darwin","/go/src/github.com/creativeprojects/resticprofile/resticprofile_linux"]} +{"message_type":"status","seconds_elapsed":1,"percent_done":1,"error_count":2,"total_files":213,"files_done":212,"total_bytes":362948126,"bytes_done":362948126,"current_files":["/go/src/github.com/creativeprojects/resticprofile/resticprofile_linux"]} {"message_type":"summary","files_new":213,"files_changed":11,"files_unmodified":12,"dirs_new":58,"dirs_changed":2,"dirs_unmodified":3,"data_blobs":402,"tree_blobs":59,"data_added":296530781,"total_files_processed":236,"total_bytes_processed":362948126,"total_duration":1.009156009,"snapshot_id":"6daa8ef6"} ` - if runtime.GOOS == "windows" { + if platform.IsWindows() { // change the source resticOutput = strings.ReplaceAll(resticOutput, "\n", eol) } - reader, writer, err := os.Pipe() - require.NoError(t, err) - - // Start writing into the pipe, line by line - go func() { - lines := strings.Split(resticOutput, "\n") - for _, line := range lines { - line = strings.TrimRight(line, "\r") - if runtime.GOOS == "windows" { - // https://github.com/restic/restic/issues/3111 - writer.WriteString("\r\x1b[2K") - } - writer.WriteString(line + eol) - } - writer.Close() - }() + reader, writer := io.Pipe() + defer reader.Close() + go writeLinesToFile(resticOutput, writer) // Read the stream and send back to output buffer - summary := &monitor.Summary{} - output := &strings.Builder{} - err = ScanBackupJson(reader, summary, output) + var status monitor.Status + receiver := mocks.NewReceiver(t) + receiver.EXPECT().Status(mock.Anything).Run(func(s monitor.Status) { + status = s + }).Times(4) + provider := monitor.NewProvider(receiver) + output := util.NewSyncWriter(&strings.Builder{}) + + err := scanBackupJson(reader, provider, HideJson(output)) require.NoError(t, err) - // Check what we read back is right (should be empty) - assert.Equal(t, eol, output.String()) - - // Check the values found are right - assert.Equal(t, 213, summary.FilesNew) - assert.Equal(t, 11, summary.FilesChanged) - assert.Equal(t, 12, summary.FilesUnmodified) - assert.Equal(t, 58, summary.DirsNew) - assert.Equal(t, 2, summary.DirsChanged) - assert.Equal(t, 3, summary.DirsUnmodified) + // Check what we read back is right (should be trailing newline only) + _ = output.Locked(func(out *strings.Builder) error { + assert.Equal(t, eol, out.String()) + return nil + }) + + // Check the status + assert.Equal(t, []string{"/go/src/github.com/creativeprojects/resticprofile/resticprofile_linux"}, status.CurrentFiles) + assert.Equal(t, int64(2), status.ErrorCount) + assert.Equal(t, float64(1), status.PercentDone) + assert.Equal(t, int64(213), status.TotalFiles) + assert.Equal(t, uint64(362948126), status.TotalBytes) + assert.Equal(t, int64(212), status.FilesDone) + assert.Equal(t, uint64(362948126), status.BytesDone) + assert.Equal(t, 1, status.SecondsElapsed) + assert.Equal(t, 0, status.SecondsRemaining) + + // Check the summary + summary := provider.CurrentSummary() + assert.Equal(t, int64(213), summary.FilesNew) + assert.Equal(t, int64(11), summary.FilesChanged) + assert.Equal(t, int64(12), summary.FilesUnmodified) + assert.Equal(t, int64(58), summary.DirsNew) + assert.Equal(t, int64(2), summary.DirsChanged) + assert.Equal(t, int64(3), summary.DirsUnmodified) assert.Equal(t, uint64(296530781), summary.BytesAdded) assert.Equal(t, uint64(362948126), summary.BytesTotal) - assert.Equal(t, 236, summary.FilesTotal) + assert.Equal(t, int64(236), summary.FilesTotal) + assert.Equal(t, "6daa8ef6", summary.SnapshotID) + assert.True(t, summary.Extended) + assert.Equal(t, time.Duration(math.Round(1.009156009*float64(time.Second))), summary.Duration) } func TestScanJsonError(t *testing.T) { @@ -72,41 +83,38 @@ func TestScanJsonError(t *testing.T) { Is there a repository at the following location? /Volumes/RAMDisk/self ` - if runtime.GOOS == "windows" { + if platform.IsWindows() { // change the source resticOutput = strings.ReplaceAll(resticOutput, "\n", eol) } - reader, writer, err := os.Pipe() - require.NoError(t, err) - - // Start writing into the pipe, line by line - go func() { - lines := strings.Split(resticOutput, "\n") - for _, line := range lines { - line = strings.TrimRight(line, "\r") - writer.WriteString(line + eol) - } - writer.Close() - }() + reader, writer := io.Pipe() + defer reader.Close() + go writeLinesToFile(resticOutput, writer) // Read the stream and send back to output buffer - summary := &monitor.Summary{} - output := &strings.Builder{} - err = ScanBackupJson(reader, summary, output) + provider := monitor.NewProvider() + output := util.NewSyncWriter(&strings.Builder{}) + err := scanBackupJson(reader, provider, HideJson(output)) require.NoError(t, err) // Check what we read back is right - assert.Equal(t, resticOutput+eol, output.String()) + _ = output.Locked(func(out *strings.Builder) error { + assert.Equal(t, resticOutput+eol, out.String()) + return nil + }) // Check the values found are right - assert.Equal(t, 0, summary.FilesNew) - assert.Equal(t, 0, summary.FilesChanged) - assert.Equal(t, 0, summary.FilesUnmodified) - assert.Equal(t, 0, summary.DirsNew) - assert.Equal(t, 0, summary.DirsChanged) - assert.Equal(t, 0, summary.DirsUnmodified) + summary := provider.CurrentSummary() + assert.Equal(t, int64(0), summary.FilesNew) + assert.Equal(t, int64(0), summary.FilesChanged) + assert.Equal(t, int64(0), summary.FilesUnmodified) + assert.Equal(t, int64(0), summary.DirsNew) + assert.Equal(t, int64(0), summary.DirsChanged) + assert.Equal(t, int64(0), summary.DirsUnmodified) assert.Equal(t, uint64(0), summary.BytesAdded) assert.Equal(t, uint64(0), summary.BytesTotal) - assert.Equal(t, 0, summary.FilesTotal) + assert.Equal(t, int64(0), summary.FilesTotal) + assert.Equal(t, "", summary.SnapshotID) + assert.False(t, summary.Extended) } diff --git a/shell/plain_summary.go b/shell/plain_summary.go index 3b9d05d63..ad512ae42 100644 --- a/shell/plain_summary.go +++ b/shell/plain_summary.go @@ -5,41 +5,63 @@ import ( "fmt" "io" "math" - "runtime" "strings" + "time" "github.com/creativeprojects/resticprofile/monitor" ) -// ScanBackupPlain should populate the backup summary values from the standard output -var ScanBackupPlain ScanOutput = func(r io.Reader, summary *monitor.Summary, w io.Writer) error { - eol := "\n" - if runtime.GOOS == "windows" { - eol = "\r\n" - } - rawBytes, unit, duration := 0.0, "", "" - scanner := bufio.NewScanner(r) +// scanBackupPlain should populate the backup summary values from the standard output +var scanBackupPlain ScanOutput = func(r io.Reader, provider monitor.Provider, w io.Writer) error { + scanner := bufio.NewScanner(io.TeeReader(r, w)) for scanner.Scan() { - w.Write([]byte(scanner.Text() + eol)) + line := scanner.Text() + // scan content - it's all right if the line does not match - _, _ = fmt.Sscanf(scanner.Text(), "Files: %d new, %d changed, %d unmodified", &summary.FilesNew, &summary.FilesChanged, &summary.FilesUnmodified) - _, _ = fmt.Sscanf(scanner.Text(), "Dirs: %d new, %d changed, %d unmodified", &summary.DirsNew, &summary.DirsChanged, &summary.DirsUnmodified) - - n, err := fmt.Sscanf(scanner.Text(), "Added to the repo: %f %3s", &rawBytes, &unit) - if n == 2 && err == nil { - summary.BytesAdded = unformatBytes(rawBytes, unit) - } - - n, err = fmt.Sscanf(scanner.Text(), "processed %d files, %f %3s in %s", &summary.FilesTotal, &rawBytes, &unit, &duration) - if n == 4 && err == nil { - summary.BytesTotal = unformatBytes(rawBytes, unit) - } - } + provider.UpdateSummary(func(summary *monitor.Summary) { + _, _ = fmt.Sscanf(line, "Files: %d new, %d changed, %d unmodified", &summary.FilesNew, &summary.FilesChanged, &summary.FilesUnmodified) + _, _ = fmt.Sscanf(line, "Dirs: %d new, %d changed, %d unmodified", &summary.DirsNew, &summary.DirsChanged, &summary.DirsUnmodified) + _, _ = fmt.Sscanf(line, "snapshot %s saved", &summary.SnapshotID) + + // restic < 14 + bytes, unit := 0.0, "" + n, _ := fmt.Sscanf(line, "Added to the repo: %f %3s", &bytes, &unit) + if n == 2 { + summary.BytesAdded = unformatBytes(bytes, unit) + } + + // restic >=14 + storedBytes, storedUnit, addVerb := 0.0, "", "" + n, _ = fmt.Sscanf(line, "%s to the repository: %f %3s (%f %3s stored)", &addVerb, &bytes, &unit, &storedBytes, &storedUnit) + if n >= 3 && addVerb == "Added" || addVerb == "Would add" { + summary.DryRun = strings.HasPrefix(addVerb, "Would") + summary.BytesAdded = unformatBytes(bytes, unit) + if n == 5 { + summary.BytesStored = unformatBytes(storedBytes, storedUnit) + } + } + + duration := "" + n, _ = fmt.Sscanf(line, "processed %d files, %f %3s in %s", &summary.FilesTotal, &bytes, &unit, &duration) + if n == 4 { + summary.BytesTotal = unformatBytes(bytes, unit) - if err := scanner.Err(); err != nil { - return err + duration = strings.TrimSpace(duration) + if len(duration) == 4 || len(duration) == 6 { + duration = "0" + duration + } + if len(duration) == 5 { + duration = "00:" + duration + } + const TimeOnly = "15:04:05" // use time.TimeOnly when go 1.20 is min ver + if p, err := time.Parse(TimeOnly, duration); err == nil { + summary.Duration = p.Sub( + time.Date(p.Year(), p.Month(), p.Day(), 0, 0, 0, 0, p.Location())) + } + } + }) } - return nil + return scanner.Err() } func unformatBytes(value float64, unit string) uint64 { diff --git a/shell/plain_summary_test.go b/shell/plain_summary_test.go index 0dcaea68b..f55abea6a 100644 --- a/shell/plain_summary_test.go +++ b/shell/plain_summary_test.go @@ -1,63 +1,97 @@ package shell import ( - "os" - "runtime" - "strings" - "testing" - + "fmt" "github.com/creativeprojects/resticprofile/monitor" + "github.com/creativeprojects/resticprofile/platform" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" + "io" + "strings" + "testing" + "time" ) func TestPipeScanBackup(t *testing.T) { - source := `repository 2e92db7f opened successfully, password is correct + sources := []string{` +repository 2e92db7f opened successfully, password is correct created new cache in /Users/home/Library/Caches/restic Files: 209 new, 2 changed, 12 unmodified Dirs: 58 new, 1 changed, 11 unmodified Added to the repo: 282.768 MiB -processed 223 files, 346.107 MiB in 0:00 +processed 223 files, 346.107 MiB in 0:02 +snapshot 07ab30a5 saved + `, ` +repository 2e92db7f opened successfully, password is correct +created new cache in /Users/home/Library/Caches/restic + +Files: 209 new, 2 changed, 12 unmodified +Dirs: 58 new, 1 changed, 11 unmodified +Added to the repository: 282.768 MiB + +processed 223 files, 346.107 MiB in 0:02 snapshot 07ab30a5 saved -` + `, ` +repository 2e92db7f opened successfully, password is correct +created new cache in /Users/home/Library/Caches/restic - if runtime.GOOS == "windows" { - // change the source - source = strings.ReplaceAll(source, "\n", eol) +Files: 209 new, 2 changed, 12 unmodified +Dirs: 58 new, 1 changed, 11 unmodified +Added to the repository: 282.768 MiB (140.641 MiB stored) + +processed 223 files, 346.107 MiB in 0:02 +snapshot 07ab30a5 saved + `} + + for i, source := range sources { + t.Run(fmt.Sprintf("%d", i), func(t *testing.T) { + + if platform.IsWindows() { + // change the source + source = strings.ReplaceAll(source, "\n", eol) + } + + reader, writer := io.Pipe() + defer reader.Close() + go writeLinesToFile(source, writer) + + // Read the stream and send back to output buffer + provider := monitor.NewProvider() + output := &strings.Builder{} + err := scanBackupPlain(reader, provider, output) + require.NoError(t, err) + + // Check what we read back is right + assert.Equal(t, source+eol, output.String()) + + // Check the values found are right + summary := provider.CurrentSummary() + assert.Equal(t, int64(209), summary.FilesNew) + assert.Equal(t, int64(2), summary.FilesChanged) + assert.Equal(t, int64(12), summary.FilesUnmodified) + assert.Equal(t, int64(58), summary.DirsNew) + assert.Equal(t, int64(1), summary.DirsChanged) + assert.Equal(t, int64(11), summary.DirsUnmodified) + assert.Equal(t, unformatBytes(282.768, "MiB"), summary.BytesAdded) + if i == 2 { + assert.Equal(t, unformatBytes(140.641, "MiB"), summary.BytesStored) + } + assert.Equal(t, unformatBytes(346.107, "MiB"), summary.BytesTotal) + assert.Equal(t, int64(223), summary.FilesTotal) + assert.Equal(t, "07ab30a5", summary.SnapshotID) + assert.False(t, summary.Extended) + assert.Equal(t, time.Second*2, summary.Duration) + }) } +} - reader, writer, err := os.Pipe() - require.NoError(t, err) - - // Start writing into the pipe, line by line - go func() { - lines := strings.Split(source, "\n") - for _, line := range lines { - line = strings.TrimRight(line, "\r") - writer.WriteString(line + eol) - } - writer.Close() - }() - - // Read the stream and send back to output buffer - summary := &monitor.Summary{} - output := &strings.Builder{} - err = ScanBackupPlain(reader, summary, output) - require.NoError(t, err) - - // Check what we read back is right - assert.Equal(t, source+eol, output.String()) - - // Check the values found are right - assert.Equal(t, 209, summary.FilesNew) - assert.Equal(t, 2, summary.FilesChanged) - assert.Equal(t, 12, summary.FilesUnmodified) - assert.Equal(t, 58, summary.DirsNew) - assert.Equal(t, 1, summary.DirsChanged) - assert.Equal(t, 11, summary.DirsUnmodified) - assert.Equal(t, uint64(296503738), summary.BytesAdded) - assert.Equal(t, uint64(362919494), summary.BytesTotal) - assert.Equal(t, 223, summary.FilesTotal) +func TestUnformatBytes(t *testing.T) { + assert.Equal(t, uint64(1), unformatBytes(1, "Bytes")) + assert.Equal(t, uint64(1024), unformatBytes(1, "KiB")) + assert.Equal(t, uint64(512), unformatBytes(0.5, "KiB")) + assert.Equal(t, uint64(1024*1024), unformatBytes(1, "MiB")) + assert.Equal(t, uint64(1024*1024*1024), unformatBytes(1, "GiB")) + assert.Equal(t, uint64(1024*1024*1024*1024), unformatBytes(1, "TiB")) } diff --git a/shell/summary.go b/shell/summary.go new file mode 100644 index 000000000..258ad6135 --- /dev/null +++ b/shell/summary.go @@ -0,0 +1,16 @@ +package shell + +import ( + "github.com/creativeprojects/resticprofile/constants" +) + +func GetOutputScanner(commandName string, jsonOutput bool) ScanOutput { + switch commandName { + case constants.CommandBackup: + if jsonOutput { + return scanBackupJson + } + return scanBackupPlain + } + return nil +} diff --git a/shell/summary_test.go b/shell/summary_test.go index de0edf5c0..0c6645a88 100644 --- a/shell/summary_test.go +++ b/shell/summary_test.go @@ -1,13 +1,56 @@ package shell -import "runtime" +import ( + "fmt" + "github.com/creativeprojects/resticprofile/constants" + "github.com/creativeprojects/resticprofile/platform" + "github.com/stretchr/testify/assert" + "io" + "strings" + "testing" +) var ( eol = "\n" ) func init() { - if runtime.GOOS == "windows" { + if platform.IsWindows() { eol = "\r\n" } } + +func writeLinesToFile(input string, output io.WriteCloser) { + defer func() { _ = output.Close() }() + + json := strings.Contains(input, "{") && + strings.Contains(input, "}") + + for _, line := range strings.Split(input, "\n") { + line = strings.TrimRight(line, "\r") + if platform.IsWindows() && json { + // https://github.com/restic/restic/issues/3111 + _, _ = fmt.Fprint(output, "\r\x1b[2K") + } + _, _ = fmt.Fprint(output, line, eol) + } +} + +func TestGetOutputScanner(t *testing.T) { + tests := []struct { + command string + plain, json ScanOutput + }{ + {command: "any", plain: nil, json: nil}, + {command: constants.CommandBackup, plain: scanBackupPlain, json: scanBackupJson}, + } + + ref := func(t any) string { return fmt.Sprintf("%p%#v", t, t) } + + for _, test := range tests { + t.Run(test.command, func(t *testing.T) { + assert.Equal(t, ref(GetOutputScanner(test.command, false)), ref(test.plain)) + assert.Equal(t, ref(GetOutputScanner(test.command, true)), ref(test.json)) + }) + } +} diff --git a/shell/util.go b/shell/util.go new file mode 100644 index 000000000..04e927aa7 --- /dev/null +++ b/shell/util.go @@ -0,0 +1,48 @@ +package shell + +import ( + "bufio" + "bytes" + "io" + + "github.com/creativeprojects/resticprofile/platform" +) + +var ( + bogusPrefix = []byte("\r\x1b[2K") +) + +func LineOutputFilter(output io.Writer, included func(line []byte) bool) io.WriteCloser { + eol := []byte("\n") + if platform.IsWindows() { + eol = []byte("\r\n") + } + + reader, writer := io.Pipe() + + go func() { + var err error + defer func() { + _ = reader.CloseWithError(err) + }() + + scanner := bufio.NewScanner(reader) + for err == nil && scanner.Scan() { + line := bytes.TrimPrefix(scanner.Bytes(), bogusPrefix) + if !included(line) { + continue + } + if err == nil { + _, err = output.Write(line) + } + if err == nil { + _, err = output.Write(eol) + } + } + if err == nil { + err = scanner.Err() + } + }() + + return writer +} diff --git a/shell_command.go b/shell_command.go index 229307750..9474570f8 100644 --- a/shell_command.go +++ b/shell_command.go @@ -25,6 +25,7 @@ type shellCommandDefinition struct { sigChan chan os.Signal setPID shell.SetPID scanOutput shell.ScanOutput + receivers []monitor.Receiver streamError []config.StreamErrorSection } @@ -88,6 +89,7 @@ func runShellCommand(command shellCommandDefinition) (summary monitor.Summary, s // scan output if command.scanOutput != nil { shellCmd.ScanStdout = command.scanOutput + shellCmd.Receivers = command.receivers } // stderr callbacks diff --git a/wrapper.go b/wrapper.go index 179d08f54..2aa3f046e 100644 --- a/wrapper.go +++ b/wrapper.go @@ -8,6 +8,7 @@ import ( "os" "os/exec" "path/filepath" + "regexp" "sort" "strconv" "strings" @@ -22,6 +23,7 @@ import ( "github.com/creativeprojects/resticprofile/restic" "github.com/creativeprojects/resticprofile/shell" "github.com/creativeprojects/resticprofile/term" + "github.com/creativeprojects/resticprofile/util/bools" "github.com/creativeprojects/resticprofile/util/collect" "golang.org/x/exp/slices" ) @@ -472,19 +474,10 @@ func (r *resticWrapper) runCommand(command string) error { } rCommand := r.prepareCommand(command, args, true) + jsonRequested := slices.Contains(rCommand.args, "--json") if command == constants.CommandBackup && r.profile.Backup != nil { - // Add output scanners - if len(r.progress) > 0 { - if r.profile.Backup.ExtendedStatus { - rCommand.scanOutput = shell.ScanBackupJson - } else if !term.OsStdoutIsTerminal() { - // restic detects its output is not a terminal and no longer displays the monitor. - // Scan plain output only if resticprofile is not run from a terminal (e.g. schedule) - rCommand.scanOutput = shell.ScanBackupPlain - } - } - + jsonRequested = jsonRequested || bools.IsTrue(r.profile.Backup.ExtendedStatus) // Redirect a stream source to stdin of restic if configured if source, err := r.prepareStreamSource(); err == nil { if source != nil { @@ -496,6 +489,37 @@ func (r *resticWrapper) runCommand(command string) error { } } + // Add output scanner + if len(r.progress) > 0 { + rCommand.scanOutput = shell.GetOutputScanner(command, jsonRequested) + rCommand.receivers = r.progress + + if term.OutputIsTerminal() && !jsonRequested { + clog.Warningf("%d modules configured to receive restic status but \"extended-status\" not set. Status won't be forwarded when run from terminal console") + rCommand.scanOutput = nil + } + + // Set how often the current progress is reported to the terminal per second (for supported restic commands) + if rCommand.scanOutput != nil && + term.OutputIsTerminal() && + !slices.ContainsFunc(rCommand.env, regexp.MustCompile(`^RESTIC_PROGRESS_FPS=.*`).MatchString) { + rCommand.env = append(rCommand.env, fmt.Sprintf("RESTIC_PROGRESS_FPS=%d", term.StatusFPS)) + } + } + + // Add output redirection / filter + if redirect, ok := config.GetSectionWith[config.RedirectOutput](r.profile, command); ok { + switch redirect.IsOutputHidden(command, jsonRequested) { + case config.HideOutput: + rCommand.stdout = io.Discard + case config.HideJsonOutput: + rCommand.stdout = shell.HideJson(rCommand.stdout) + } + if redirect.IsOutputRedirected() { + // TODO: Setup + } + } + summary, stderr, err := runShellCommand(rCommand) r.executionTime += summary.Duration r.summary(r.command, summary, stderr, err) diff --git a/wrapper_stdout.go b/wrapper_stdout.go new file mode 100644 index 000000000..bc361bf5f --- /dev/null +++ b/wrapper_stdout.go @@ -0,0 +1,15 @@ +package main + +import "io" + +func (r *resticWrapper) prepareStdout() (io.WriteCloser, error) { + + if r.profile.Backup != nil && r.profile.Backup.UseStdin { + if len(r.profile.Backup.StdinCommand) > 0 { + //return r.prepareCommandStreamSource() + } else { + //return r.prepareStdinStreamSource() + } + } + return nil, nil +} diff --git a/wrapper_test.go b/wrapper_test.go index 1127aa731..548936948 100644 --- a/wrapper_test.go +++ b/wrapper_test.go @@ -715,6 +715,10 @@ func (m *mockOutputAnalysis) GetRemoteLockedBy() (string, bool) { return m.lockWho, len(m.lockWho) > 1 } +func (m *mockOutputAnalysis) GetFailedFiles() []string { + return nil +} + func TestCanRetryAfterRemoteStaleLockFailure(t *testing.T) { mockOutput := &mockOutputAnalysis{lockWho: "TestCanRetryAfterRemoteStaleLockFailure"}