diff --git a/cmd/backup_tar.go b/cmd/backup_tar.go index b1309b293..5d19b4ba3 100644 --- a/cmd/backup_tar.go +++ b/cmd/backup_tar.go @@ -2,12 +2,13 @@ package cmd import ( + "io" + "github.com/molecula/featurebase/v3/ctl" - "github.com/molecula/featurebase/v3/logger" "github.com/spf13/cobra" ) -func newBackupTarCommand(logdest logger.Logger) *cobra.Command { +func newBackupTarCommand(logdest io.Writer) *cobra.Command { cmd := ctl.NewBackupTarCommand(logdest) ccmd := &cobra.Command{ Use: "backuptar", diff --git a/cmd/root.go b/cmd/root.go index 10611c038..6453cc511 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -92,7 +92,7 @@ at https://docs.molecula.cloud/. rc.AddCommand(newChkSumCommand(logdest)) rc.AddCommand(newBackupCommand(logdest)) rc.AddCommand(newRestoreCommand(logdest)) - rc.AddCommand(newBackupTarCommand(logdest)) + rc.AddCommand(newBackupTarCommand(stderr)) rc.AddCommand(newRestoreTarCommand(logdest)) rc.AddCommand(newConfigCommand(stderr)) rc.AddCommand(newExportCommand(logdest)) diff --git a/ctl/backup_tar.go b/ctl/backup_tar.go index d89fcb665..b94062850 100644 --- a/ctl/backup_tar.go +++ b/ctl/backup_tar.go @@ -21,7 +21,6 @@ import ( "github.com/molecula/featurebase/v3/encoding/proto" "github.com/molecula/featurebase/v3/logger" "github.com/molecula/featurebase/v3/server" - "github.com/molecula/featurebase/v3/vprint" "github.com/pkg/errors" ) @@ -52,7 +51,8 @@ type BackupTarCommand struct { // nolint: maligned client *pilosa.InternalClient // Standard input/output - logDest logger.Logger + logwriter io.Writer + logDest logger.Logger TLS server.TLSConfig @@ -65,9 +65,10 @@ func (cmd *BackupTarCommand) Logger() logger.Logger { } // NewBackupTarCommand returns a new instance of BackupCommand. -func NewBackupTarCommand(logdest logger.Logger) *BackupTarCommand { +func NewBackupTarCommand(logwriter io.Writer) *BackupTarCommand { return &BackupTarCommand{ - logDest: logdest, + logwriter: logwriter, + logDest: logger.NewStandardLogger(logwriter), RetryPeriod: time.Minute, HeaderTimeout: time.Second * 3, Pprof: "localhost:0", @@ -76,18 +77,24 @@ func NewBackupTarCommand(logdest logger.Logger) *BackupTarCommand { // Run executes the main program execution. func (cmd *BackupTarCommand) Run(ctx context.Context) (err error) { - logger := cmd.Logger() - close, err := startProfilingServer(cmd.Pprof, logger) - if err != nil { - return errors.Wrap(err, "starting profiling server") - } - defer close() - + logdest := cmd.Logger() // Validate arguments. if cmd.OutputPath == "" { return fmt.Errorf("%w: -o flag required", UsageError) } useStdout := cmd.OutputPath == "-" + if useStdout && cmd.logwriter == os.Stdout { + logdest = logger.NewStandardLogger(os.Stderr) + } + + // This was the very first thing in the function, but since logging to stdout causes file corruption + // if the tarfile is also going to stdout, we need to check that before we can safely send anything + // to the logger. + close, err := startProfilingServer(cmd.Pprof, logdest) + if err != nil { + return errors.Wrap(err, "starting profiling server") + } + defer close() if cmd.HeaderTimeoutStr != "" { if dur, err := time.ParseDuration(cmd.HeaderTimeoutStr); err != nil { @@ -137,6 +144,13 @@ func (cmd *BackupTarCommand) Run(ctx context.Context) (err error) { var w io.Writer if useStdout { w = os.Stdout + // if writing tarfile to stdout, the logs can't also go there or the file ends up corrupt + // redirect to stderr and log a message there to avoid this + // commented out for testing + //if dest := logger.Logger(); dest.Writer() == os.Stdout { + // dest.SetOutput(os.Stderr) + // logger.Printf("redirected logs to stderr to avoid file corruption") + //} } else { f, err := os.Create(cmd.OutputPath + ".tmp") if err != nil { @@ -171,7 +185,7 @@ func (cmd *BackupTarCommand) Run(ctx context.Context) (err error) { // Move data file to final location. if !useStdout { - logger.Printf("writing backup: %s", cmd.OutputPath) + logdest.Printf("writing backup: %s", cmd.OutputPath) if err := os.Rename(cmd.OutputPath+".tmp", cmd.OutputPath); err != nil { return err } @@ -359,7 +373,7 @@ func (cmd *BackupTarCommand) backupTarShardDataframe(ctx context.Context, tw *ta } filename := filepath.Join("indexes", indexName, "dataframe", fmt.Sprintf("%04d", shard)) - vprint.VV("wrting %v", filename) + logger.Printf("writing %v", filename) var buf bytes.Buffer if _, err := buf.ReadFrom(resp.Body); err != nil { return fmt.Errorf("copying shard data to memory: %w", err) diff --git a/ctl/backup_tar_test.go b/ctl/backup_tar_test.go index 80f1cfbf8..356e8c13b 100644 --- a/ctl/backup_tar_test.go +++ b/ctl/backup_tar_test.go @@ -1,14 +1,13 @@ package ctl import ( + "bytes" "context" - "io" - "net/http" + "os" "path/filepath" - "strings" "testing" - "github.com/molecula/featurebase/v3/logger" + pilosa "github.com/molecula/featurebase/v3" "github.com/molecula/featurebase/v3/test" ) @@ -16,27 +15,54 @@ func TestBackupTarCommand_Run(t *testing.T) { cluster := test.MustRunCluster(t, 1) defer cluster.Close() cmd := cluster.GetNode(0) + indexName := "backuptar" - cmLog := logger.NewStandardLogger(io.Discard) - cm := NewBackupTarCommand(cmLog) + // this might produce some annoying spam in tests but we need to make sure log messages to + // stdout are being redirected properly when the tarfile is also going to stdout + cm := NewBackupTarCommand(os.Stdout) hostport := cmd.API.Node().URI.HostPort() cm.Host = hostport dir := t.TempDir() cm.OutputPath = filepath.Join(dir, "backuptest.tar") - resp, err := http.DefaultClient.Do(test.MustNewHTTPRequest("POST", "http://"+hostport+"/index/i", strings.NewReader(""))) + _, err := cmd.API.CreateIndex(context.Background(), indexName, pilosa.IndexOptions{Keys: true, TrackExistence: true}) if err != nil { - t.Fatalf("making http request: %v", err) + t.Fatalf("creating test index: %v", err) } - resp.Body.Close() - resp, err = http.DefaultClient.Do(test.MustNewHTTPRequest("POST", "http://"+hostport+"/index/i/field/f", strings.NewReader(""))) + _, err = cmd.API.CreateField(context.Background(), indexName, "f", pilosa.OptFieldKeys()) if err != nil { - t.Fatalf("making http request: %v", err) + t.Fatalf("creating test field: %v", err) } - resp.Body.Close() - cm.Index = "i" + cm.Index = indexName if err := cm.Run(context.Background()); err != nil { t.Fatalf("BackupTarCommand Run error: %s", err) } + + oldpath := cm.OutputPath + cm.OutputPath = "-" + cfpath := filepath.Join(dir, "stdouttest.tar") //capture file + cf, err := os.Create(cfpath) + if err != nil { + t.Fatalf("opening file to compare file and stdout outputs: %v", err) + } + defer cf.Close() + // I don't like this at all but it's all i'm really finding for capturing os.Stdout + old := os.Stdout + defer func() { os.Stdout = old }() + os.Stdout = cf + if err := cm.Run(context.Background()); err != nil { + t.Fatalf("BackupTarCommand Run error: %s", err) + } + fdata, err := os.ReadFile(oldpath) + if err != nil { + t.Fatalf("unable to read from direct-to-file backup: %v", err) + } + cdata, err := os.ReadFile(cfpath) + if err != nil { + t.Fatalf("unable to read from captured stdout backup: %v", err) + } + if !bytes.Equal(fdata, cdata) { + t.Fatalf("backing up to file and to stdout produced different results") + } }