diff --git a/cmd/litestream/replicate.go b/cmd/litestream/replicate.go index e593e1f..6dfb9a1 100644 --- a/cmd/litestream/replicate.go +++ b/cmd/litestream/replicate.go @@ -5,8 +5,10 @@ import ( "errors" "flag" "fmt" + "log" "net" "net/http" + _ "net/http/pprof" "os" "os/signal" @@ -25,6 +27,7 @@ type ReplicateCommand struct { // Run loads all databases specified in the configuration. func (c *ReplicateCommand) Run(ctx context.Context, args []string) (err error) { fs := flag.NewFlagSet("litestream-replicate", flag.ContinueOnError) + verbose := fs.Bool("v", false, "verbose logging") registerConfigFlag(fs, &c.ConfigPath) fs.Usage = c.Usage if err := fs.Parse(args); err != nil { @@ -40,6 +43,11 @@ func (c *ReplicateCommand) Run(ctx context.Context, args []string) (err error) { return err } + // Enable trace logging. + if *verbose { + litestream.Tracef = log.Printf + } + // Setup signal handler. ctx, cancel := context.WithCancel(ctx) ch := make(chan os.Signal, 1) @@ -119,5 +127,8 @@ Arguments: -config PATH Specifies the configuration file. Defaults to %s + -v + Enable verbose logging output. + `[1:], DefaultConfigPath) } diff --git a/db.go b/db.go index 09ed776..d9a8e82 100644 --- a/db.go +++ b/db.go @@ -606,6 +606,7 @@ func (db *DB) Sync() (err error) { if err := db.init(); err != nil { return err } else if db.db == nil { + Tracef("%s: sync: no database found", db.path) return nil } @@ -652,6 +653,7 @@ func (db *DB) Sync() (err error) { if err != nil { return fmt.Errorf("cannot verify wal state: %w", err) } + Tracef("%s: sync: info=%#v", db.path, info) // Track if anything in the shadow WAL changes and then notify at the end. changed := info.walSize != info.shadowWALSize || info.restart || info.reason != "" @@ -721,6 +723,8 @@ func (db *DB) Sync() (err error) { db.notify = make(chan struct{}) } + Tracef("%s: sync: ok", db.path) + return nil } @@ -898,6 +902,8 @@ func (db *DB) initShadowWALFile(filename string) error { } func (db *DB) copyToShadowWAL(filename string) (newSize int64, err error) { + Tracef("%s: copy-shadow: %s", db.path, filename) + r, err := os.Open(db.WALPath()) if err != nil { return 0, err @@ -946,8 +952,11 @@ func (db *DB) copyToShadowWAL(filename string) (newSize int64, err error) { newSize = origSize buf := make([]byte, db.pageSize+WALFrameHeaderSize) for { + Tracef("%s: copy-shadow: %s @ %d", db.path, filename, newSize) + // Read next page from WAL file. if _, err := io.ReadFull(r, buf); err == io.EOF || err == io.ErrUnexpectedEOF { + Tracef("%s: copy-shadow: break %s", db.path, err) break // end of file or partial page } else if err != nil { return newSize, fmt.Errorf("read wal: %w", err) @@ -957,6 +966,7 @@ func (db *DB) copyToShadowWAL(filename string) (newSize int64, err error) { salt0 := binary.BigEndian.Uint32(buf[8:]) salt1 := binary.BigEndian.Uint32(buf[12:]) if salt0 != hsalt0 || salt1 != hsalt1 { + Tracef("%s: copy-shadow: break: salt mismatch", db.path) break } diff --git a/litestream.go b/litestream.go index 270e04b..92e19f3 100644 --- a/litestream.go +++ b/litestream.go @@ -313,6 +313,9 @@ func mkdirAll(path string, perm os.FileMode, uid, gid int) error { return nil } +// Tracef is used for low-level tracing. +var Tracef = func(format string, a ...interface{}) {} + func assert(condition bool, message string) { if !condition { panic("assertion failed: " + message)