From cd012d8fbcd2c4ac0593aee6463c679c3ea0e873 Mon Sep 17 00:00:00 2001 From: Jarek Kowalski Date: Mon, 22 Aug 2016 21:58:04 -0700 Subject: [PATCH] code cleanup, logging --- cmd/kopia/command_backup.go | 14 ++---- cmd/kopia/command_backups.go | 13 ++---- cmd/kopia/command_ls.go | 10 ++--- cmd/kopia/command_mount.go | 7 +-- cmd/kopia/command_show.go | 18 ++++---- cmd/kopia/command_status.go | 18 +++----- cmd/kopia/command_vault_list.go | 7 +-- cmd/kopia/command_vault_rm.go | 5 +-- cmd/kopia/config.go | 26 ++++++++++++ repo/repository.go | 9 ++-- storage/logging/logging_storage.go | 68 ++++++++++++++++++++---------- 11 files changed, 102 insertions(+), 93 deletions(-) diff --git a/cmd/kopia/command_backup.go b/cmd/kopia/command_backup.go index ebfb87e9c..a1960030a 100644 --- a/cmd/kopia/command_backup.go +++ b/cmd/kopia/command_backup.go @@ -52,16 +52,8 @@ func runBackupCommand(context *kingpin.ParseContext) error { repoOptions = append(repoOptions, repo.WriteBack(*backupWriteBack)) } - vlt, err := openVault() - if err != nil { - return err - } - - mgr, err := vlt.OpenRepository(repoOptions...) - if err != nil { - return err - } - defer mgr.Close() + vlt, r := mustOpenVaultAndRepository() + defer r.Close() var options []fs.UploaderOption @@ -69,7 +61,7 @@ func runBackupCommand(context *kingpin.ParseContext) error { options = append(options, fs.EnableBundling()) } - bgen, err := backup.NewGenerator(mgr, options...) + bgen, err := backup.NewGenerator(r, options...) if err != nil { return err } diff --git a/cmd/kopia/command_backups.go b/cmd/kopia/command_backups.go index 0ed9f3d3b..66b0f0199 100644 --- a/cmd/kopia/command_backups.go +++ b/cmd/kopia/command_backups.go @@ -57,19 +57,12 @@ func findBackups(vlt *vault.Vault, path string) ([]string, string, error) { } func runBackupsCommand(context *kingpin.ParseContext) error { - vlt, err := openVault() - if err != nil { - return err - } - - mgr, err := vlt.OpenRepository() - if err != nil { - return err - } - defer mgr.Close() + vlt, r := mustOpenVaultAndRepository() + defer r.Close() var previous []string var relPath string + var err error if *backupsPath != "" { path, err := filepath.Abs(*backupsPath) diff --git a/cmd/kopia/command_ls.go b/cmd/kopia/command_ls.go index 1707be395..66540b5e6 100644 --- a/cmd/kopia/command_ls.go +++ b/cmd/kopia/command_ls.go @@ -18,11 +18,9 @@ ) func runLSCommand(context *kingpin.ParseContext) error { - vlt := mustOpenVault() - mgr, err := vlt.OpenRepository() - if err != nil { - return err - } + vlt, r := mustOpenVaultAndRepository() + defer vlt.Close() + defer r.Close() oid, err := parseObjectID(*lsCommandPath, vlt) if err != nil { @@ -37,7 +35,7 @@ func runLSCommand(context *kingpin.ParseContext) error { } } - dir := fs.NewDirectory(mgr, oid) + dir := fs.NewDirectory(r, oid) entries, err := dir.Readdir() if err != nil { return err diff --git a/cmd/kopia/command_mount.go b/cmd/kopia/command_mount.go index de77eeca6..ef7e8e4cf 100644 --- a/cmd/kopia/command_mount.go +++ b/cmd/kopia/command_mount.go @@ -27,12 +27,7 @@ func (r *root) Root() (fusefs.Node, error) { } func runMountCommand(context *kingpin.ParseContext) error { - vlt := mustOpenVault() - - r, err := vlt.OpenRepository() - if err != nil { - return err - } + vlt, r := mustOpenVaultAndRepository() fuseConnection, err := fuse.Mount( *mountPoint, diff --git a/cmd/kopia/command_show.go b/cmd/kopia/command_show.go index 48bbec8eb..5b17b9caa 100644 --- a/cmd/kopia/command_show.go +++ b/cmd/kopia/command_show.go @@ -20,11 +20,9 @@ ) func runShowCommand(context *kingpin.ParseContext) error { - vlt := mustOpenVault() - mgr, err := vlt.OpenRepository() - if err != nil { - return err - } + vlt, r := mustOpenVaultAndRepository() + defer vlt.Close() + defer r.Close() for _, oidString := range *showObjectIDs { oid, err := parseObjectID(oidString, vlt) @@ -32,7 +30,7 @@ func runShowCommand(context *kingpin.ParseContext) error { return err } - if err := showObject(mgr, oid); err != nil { + if err := showObject(r, oid); err != nil { return err } } @@ -40,14 +38,14 @@ func runShowCommand(context *kingpin.ParseContext) error { return nil } -func showObject(mgr repo.Repository, oid repo.ObjectID) error { - r, err := mgr.Open(oid) +func showObject(r repo.Repository, oid repo.ObjectID) error { + rd, err := r.Open(oid) if err != nil { return err } - defer r.Close() + defer rd.Close() - rawdata, err := ioutil.ReadAll(r) + rawdata, err := ioutil.ReadAll(rd) if err != nil { return err } diff --git a/cmd/kopia/command_status.go b/cmd/kopia/command_status.go index 4cf2557eb..23e70582b 100644 --- a/cmd/kopia/command_status.go +++ b/cmd/kopia/command_status.go @@ -17,21 +17,18 @@ func init() { } func runRepositoryInfoCommand(context *kingpin.ParseContext) error { - v, err := openVault() - if err != nil { - return err - } + vlt, r := mustOpenVaultAndRepository() - vf := v.Format() + vf := vlt.Format() fmt.Println("Vault:") fmt.Println(" Version: ", vf.Version) fmt.Println(" Unique ID: ", hex.EncodeToString(vf.UniqueID)) fmt.Println(" Encryption: ", vf.Encryption) fmt.Println(" Checksum: ", vf.Checksum) - fmt.Println(" Storage: ", v.Storage()) + fmt.Println(" Storage: ", vlt.Storage()) fmt.Println() - f := v.RepositoryFormat() + f := vlt.RepositoryFormat() fmt.Println("Repository:") fmt.Println(" Version: ", f.Version) @@ -43,12 +40,7 @@ func runRepositoryInfoCommand(context *kingpin.ParseContext) error { fmt.Println(" ID Format: ", f.ObjectFormat) fmt.Println(" Blob Size: ", f.MaxBlockSize/1024, "KB") fmt.Println(" Inline Blob Size:", f.MaxInlineContentLength/1024, "KB") - r, err := v.OpenRepository() - if err == nil { - fmt.Println(" Storage: ", r.Storage()) - } else { - fmt.Println(" WARNING: Cannot open repository.") - } + fmt.Println(" Storage: ", r.Storage()) return nil } diff --git a/cmd/kopia/command_vault_list.go b/cmd/kopia/command_vault_list.go index 912445b6a..1b86b26b7 100644 --- a/cmd/kopia/command_vault_list.go +++ b/cmd/kopia/command_vault_list.go @@ -16,12 +16,9 @@ func init() { } func listVaultContents(context *kingpin.ParseContext) error { - v, err := openVault() - if err != nil { - return err - } + vlt := mustOpenVault() - entries, err := v.List(*vaultListPrefix) + entries, err := vlt.List(*vaultListPrefix) if err != nil { return err } diff --git a/cmd/kopia/command_vault_rm.go b/cmd/kopia/command_vault_rm.go index 3f48c478b..6217039b8 100644 --- a/cmd/kopia/command_vault_rm.go +++ b/cmd/kopia/command_vault_rm.go @@ -12,10 +12,7 @@ func init() { } func removeVaultItem(context *kingpin.ParseContext) error { - vlt, err := openVault() - if err != nil { - return err - } + vlt := mustOpenVault() for _, v := range *vaultRemoveItems { if err := vlt.Remove(v); err != nil { diff --git a/cmd/kopia/config.go b/cmd/kopia/config.go index 5a91cc8e7..48d289368 100644 --- a/cmd/kopia/config.go +++ b/cmd/kopia/config.go @@ -11,6 +11,7 @@ "strings" "github.com/bgentry/speakeasy" + "github.com/kopia/kopia/repo" "github.com/kopia/kopia/vault" ) @@ -38,6 +39,31 @@ func mustOpenVault() *vault.Vault { return s } +func mustOpenRepository(extraOptions ...repo.RepositoryOption) repo.Repository { + _, r := mustOpenVaultAndRepository(extraOptions...) + return r +} + +func mustOpenVaultAndRepository(extraOptions ...repo.RepositoryOption) (*vault.Vault, repo.Repository) { + v := mustOpenVault() + r, err := v.OpenRepository(repositoryOptionsFromFlags(extraOptions)...) + failOnError(err) + return v, r +} + +func repositoryOptionsFromFlags(extraOptions []repo.RepositoryOption) []repo.RepositoryOption { + var opts []repo.RepositoryOption + + for _, o := range extraOptions { + opts = append(opts, o) + } + + if *traceStorage { + opts = append(opts, repo.EnableLogging()) + } + return opts +} + func getHomeDir() string { if runtime.GOOS == "windows" { home := os.Getenv("HOMEDRIVE") + os.Getenv("HOMEPATH") diff --git a/repo/repository.go b/repo/repository.go index 8b3b10df1..2ba5fee32 100644 --- a/repo/repository.go +++ b/repo/repository.go @@ -84,19 +84,16 @@ type repository struct { } func (r *repository) Close() error { - if err := r.Flush(); err != nil { + if err := r.storage.Close(); err != nil { return err } r.bufferManager.close() + return nil } func (r *repository) Flush() error { - if f, ok := r.storage.(storage.Flusher); ok { - return f.Flush() - } - - return nil + return r.storage.Flush() } func (r *repository) Stats() RepositoryStats { diff --git a/storage/logging/logging_storage.go b/storage/logging/logging_storage.go index 155835e6a..af199f6b9 100644 --- a/storage/logging/logging_storage.go +++ b/storage/logging/logging_storage.go @@ -3,71 +3,95 @@ import ( "log" + "time" "github.com/kopia/kopia/storage" ) -// Printfer supports emitting formatted strings to arbitrary outputs. -// The formatting language must be compatible with fmt.Sprintf(). -type Printfer interface { - Printf(fmt string, args ...interface{}) -} - type loggingStorage struct { base storage.Storage printf func(string, ...interface{}) } func (s *loggingStorage) BlockExists(id string) (bool, error) { + t0 := time.Now() result, err := s.base.BlockExists(id) - s.printf("BlockExists(%#v)=%#v,%#v", id, result, err) + dt := time.Since(t0) + s.printf(s.prefix()+"BlockExists(%#v)=%#v,%#v took %v", id, result, err, dt) return result, err } func (s *loggingStorage) GetBlock(id string) ([]byte, error) { + t0 := time.Now() result, err := s.base.GetBlock(id) + dt := time.Since(t0) if len(result) < 20 { - s.printf("GetBlock(%#v)=(%#v, %#v)", id, result, err) + s.printf(s.prefix()+"GetBlock(%#v)=(%#v, %#v) took %v", id, result, err, dt) } else { - s.printf("GetBlock(%#v)=({%#v bytes}, %#v)", id, len(result), err) + s.printf(s.prefix()+"GetBlock(%#v)=({%#v bytes}, %#v) took %v", id, len(result), err, dt) } return result, err } func (s *loggingStorage) PutBlock(id string, data storage.ReaderWithLength, options storage.PutOptions) error { + t0 := time.Now() l := data.Len() err := s.base.PutBlock(id, data, options) - s.printf("PutBlock(%#v, options=%v, len=%v)=%#v", id, options, l, err) + dt := time.Since(t0) + s.printf(s.prefix()+"PutBlock(%#v, options=%v, len=%v)=%#v took %v", id, options, l, err, dt) return err } func (s *loggingStorage) DeleteBlock(id string) error { + t0 := time.Now() err := s.base.DeleteBlock(id) - s.printf("DeleteBlock(%#v)=%#v", id, err) + dt := time.Since(t0) + s.printf(s.prefix()+"DeleteBlock(%#v)=%#v took %v", id, err, dt) return err } func (s *loggingStorage) ListBlocks(prefix string) chan (storage.BlockMetadata) { - s.printf("ListBlocks(%#v)", prefix) - return s.base.ListBlocks(prefix) + t0 := time.Now() + ch := s.base.ListBlocks(prefix) + dt := time.Since(t0) + s.printf(s.prefix()+"ListBlocks(%#v) took %v", prefix, dt) + return ch } func (s *loggingStorage) Flush() error { - s.printf("Flush()") - return s.base.Flush() + t0 := time.Now() + err := s.base.Flush() + dt := time.Since(t0) + s.printf(s.prefix()+"Flush()=%#v took %v", err, dt) + return err } func (s *loggingStorage) Close() error { - s.printf("Close()") - return s.base.Close() + t0 := time.Now() + err := s.base.Close() + dt := time.Since(t0) + s.printf(s.prefix()+"Close()=%#v took %v", err, dt) + return err } +func (s *loggingStorage) prefix() string { + return "[STORAGE] " +} + +type Option func(s *loggingStorage) + // NewWrapper returns a Storage wrapper that logs all storage commands. -func NewWrapper(wrapped storage.Storage) storage.Storage { - return &loggingStorage{base: wrapped, printf: log.Printf} +func NewWrapper(wrapped storage.Storage, options ...Option) storage.Storage { + s := &loggingStorage{base: wrapped, printf: log.Printf} + for _, o := range options { + o(s) + } + return s } -// NewWrapperWithLogger returns a Storage wrapper that logs all storage commands to the specified logger. -func NewWrapperWithLogger(wrapped storage.Storage, printfer Printfer) storage.Storage { - return &loggingStorage{base: wrapped, printf: printfer.Printf} +// Output is a logging storage option that causes all output to be sent to a given function instead of log.Printf() +func Output(outputFunc func(fmt string, args ...interface{})) Option { + return func(s *loggingStorage) { + s.printf = outputFunc + } }