Add detailed logging for WriteDir

6 files changed, 35 insertions, 8 deletions

diff --git a/backup/backup.go b/backup/backup.go
index 5e4ffc1..c2106ba 100644
--- a/backup/backup.go
+++ b/backup/backup.go
@@ -3,6 +3,7 @@ package backup
 import (
 	"code.laria.me/petrific/cache"
 	"code.laria.me/petrific/fs"
+	"code.laria.me/petrific/logging"
 	"code.laria.me/petrific/objects"
 	"code.laria.me/petrific/storage"
 	"io"
@@ -28,10 +29,12 @@ type writeFileTask struct {
 	result *chan writeFileTaskResult
 }
 
-func (task writeFileTask) process(store storage.Storage) {
+func (task writeFileTask) process(proc writeDirProcess) {
 	var result writeFileTaskResult
 	result.file = task.file
 
+	proc.log.Info().Printf("start writing file %s", task.file.Name())
+
 	rwc, err := task.file.Open()
 	if err != nil {
 		result.err = err
@@ -40,7 +43,9 @@ func (task writeFileTask) process(store storage.Storage) {
 	}
 	defer rwc.Close()
 
-	result.file_id, result.err = WriteFile(store, rwc)
+	result.file_id, result.err = WriteFile(proc.store, rwc)
+
+	proc.log.Info().Printf("finished writing file %s", task.file.Name())
 
 	*(task.result) <- result
 }
@@ -48,11 +53,12 @@ func (task writeFileTask) process(store storage.Storage) {
 type writeDirProcess struct {
 	queue chan writeFileTask
 	store storage.Storage
+	log   *logging.Log
 }
 
 func (proc writeDirProcess) worker() {
 	for task := range proc.queue {
-		task.process(proc.store)
+		task.process(proc)
 	}
 }
 
@@ -71,10 +77,12 @@ func WriteDir(
 	abspath string,
 	d fs.Dir,
 	pcache cache.Cache,
+	log *logging.Log,
 ) (objects.ObjectId, error) {
 	proc := writeDirProcess{
 		make(chan writeFileTask),
 		store,
+		log,
 	}
 	defer proc.stop()
 
@@ -90,6 +98,8 @@ func (proc writeDirProcess) writeDir(
 	d fs.Dir,
 	pcache cache.Cache,
 ) (objects.ObjectId, error) {
+	proc.log.Info().Printf("start writeDir for %s", abspath)
+
 	_children, err := d.Readdir()
 	if err != nil {
 		return objects.ObjectId{}, err
@@ -104,11 +114,15 @@ func (proc writeDirProcess) writeDir(
 
 	infos := make(objects.Tree)
 	for _, c := range children {
+		proc.log.Info().Printf("processing %s (%s) in %s", c.Name(), c.Type(), abspath)
+
 		var info objects.TreeEntry = nil
 
 		switch c.Type() {
 		case fs.FFile:
 			mtime, file_id, ok := pcache.PathUpdated(abspath + "/" + c.Name())
+			proc.log.Debug().Printf("cache info for %s: %s, %s, %t", abspath+"/"+c.Name(), mtime, file_id, ok)
+
 			if !ok || mtime.Before(c.ModTime()) {
 				// According to cache the file was changed
 
@@ -159,6 +173,7 @@ func (proc writeDirProcess) writeDir(
 		return objects.ObjectId{}, err
 	}
 
+	proc.log.Info().Printf("finishing writeDir for %s", abspath)
 	return storage.SetObject(proc.store, objects.ToRawObject(infos))
 }
 
diff --git a/backup/backup_test.go b/backup/backup_test.go
index a7f7ff9..230aa83 100644
--- a/backup/backup_test.go
+++ b/backup/backup_test.go
@@ -4,6 +4,7 @@ import (
 	"bytes"
 	"code.laria.me/petrific/cache"
 	"code.laria.me/petrific/fs"
+	"code.laria.me/petrific/logging"
 	"code.laria.me/petrific/objects"
 	"code.laria.me/petrific/storage"
 	"code.laria.me/petrific/storage/memory"
@@ -80,7 +81,7 @@ func TestWriteDir(t *testing.T) {
 		t.Fatalf("Failed creating dir: %s", err)
 	}
 
-	id, err := WriteDir(s, "", root, cache.NopCache{})
+	id, err := WriteDir(s, "", root, cache.NopCache{}, logging.NewNopLog())
 	if err != nil {
 		t.Fatalf("Could not WriteDir: %s", err)
 	}
diff --git a/backup/caching_test.go b/backup/caching_test.go
index 6dad62b..9445703 100644
--- a/backup/caching_test.go
+++ b/backup/caching_test.go
@@ -3,6 +3,7 @@ package backup
 import (
 	"code.laria.me/petrific/cache"
 	"code.laria.me/petrific/fs"
+	"code.laria.me/petrific/logging"
 	"code.laria.me/petrific/objects"
 	"code.laria.me/petrific/storage/memory"
 	"testing"
@@ -20,7 +21,7 @@ func TestCacheMTime(t *testing.T) {
 	}
 
 	want := file.ModTime()
-	if _, err := WriteDir(st, "/foo", filesys, c); err != nil {
+	if _, err := WriteDir(st, "/foo", filesys, c, logging.NewNopLog()); err != nil {
 		t.Fatal(err)
 	}
 
@@ -52,7 +53,7 @@ func TestCacheRetrieve(t *testing.T) {
 	mtime := file.ModTime().Add(1 * time.Hour)
 	c.SetPathUpdated("/foo/bar", mtime, objid_emptyfile)
 
-	if _, err := WriteDir(st, "/foo", filesys, c); err != nil {
+	if _, err := WriteDir(st, "/foo", filesys, c, logging.NewNopLog()); err != nil {
 		t.Fatal(err)
 	}
 
diff --git a/logging/log.go b/logging/log.go
index 9bef591..ce3fb74 100644
--- a/logging/log.go
+++ b/logging/log.go
@@ -54,3 +54,13 @@ func NewLog(out io.Writer, level Level) *Log {
 
 	return l
 }
+
+// NewNopLog creates a logger that is completly silent / doesn't log on any log level
+func NewNopLog() *Log {
+	return &Log{
+		NopLogger{},
+		NopLogger{},
+		NopLogger{},
+		NopLogger{},
+	}
+}
diff --git a/snapshot.go b/snapshot.go
index 06244e2..28b26ff 100644
--- a/snapshot.go
+++ b/snapshot.go
@@ -114,7 +114,7 @@ func TakeSnapshot(env *Env, args []string) int {
 		return 1
 	}
 
-	tree_id, err := backup.WriteDir(env.Store, dir_path, d, env.IdCache)
+	tree_id, err := backup.WriteDir(env.Store, dir_path, d, env.IdCache, env.Log)
 	if err != nil {
 		errout(err)
 		return 1
diff --git a/write_dir.go b/write_dir.go
index e3348c5..c5b05aa 100644
--- a/write_dir.go
+++ b/write_dir.go
@@ -45,7 +45,7 @@ func WriteDir(env *Env, args []string) int {
 		return 1
 	}
 
-	id, err := backup.WriteDir(env.Store, dir_path, d, env.IdCache)
+	id, err := backup.WriteDir(env.Store, dir_path, d, env.IdCache, env.Log)
 	if err != nil {
 		errout(err)
 		return 1