More debug logging, improve main_test.go (do not use all-zero content)

3 files changed, 19 insertions, 10 deletions

diff --git a/cryptfs/log.go b/cryptfs/log.go
index f9c46c8..8233529 100644
--- a/cryptfs/log.go
+++ b/cryptfs/log.go
@@ -15,5 +15,5 @@ func (l logChannel) Printf(format string, args ...interface{}) {
 }
 
 
-var Debug = logChannel{false}
+var Debug = logChannel{true}
 var Warn = logChannel{true}
diff --git a/main_test.go b/main_test.go
index 70dbbe2..9e4ca73 100644
--- a/main_test.go
+++ b/main_test.go
@@ -47,7 +47,7 @@ func TestMain(m *testing.M) {
 	os.Exit(r)
 }
 
-func testWriteN(t *testing.T, fn string, n int, hashWant string) {
+func testWriteN(t *testing.T, fn string, n int) string {
 	file, err := os.Create(plainDir + fn)
 	if err != nil {
 		t.FailNow()
@@ -66,28 +66,33 @@ func testWriteN(t *testing.T, fn string, n int, hashWant string) {
 		t.Fail()
 	}
 
-	rawHash := md5.Sum(buf)
-	hashActual := hex.EncodeToString(rawHash[:])
+	raw := md5.Sum(d)
+	hashWant := hex.EncodeToString(raw[:])
+
+	raw = md5.Sum(buf)
+	hashActual := hex.EncodeToString(raw[:])
 	if hashActual != hashWant {
 		fmt.Printf("hashWant=%s hashActual=%s\n", hashWant, hashActual)
 		t.Fail()
 	}
+
+	return hashActual
 }
 
 func TestWrite10(t *testing.T) {
-	testWriteN(t, "10", 10, "a63c90cc3684ad8b0a2176a6a8fe9005")
+	testWriteN(t, "10", 10)
 }
 
 func TestWrite100(t *testing.T) {
-	testWriteN(t, "100", 100, "6d0bb00954ceb7fbee436bb55a8397a9")
+	testWriteN(t, "100", 100)
 }
 
 func TestWrite1M(t *testing.T) {
-	testWriteN(t, "1M", 1024*1024, "b6d81b360a5672d80c27430f39153e2c")
+	testWriteN(t, "1M", 1024*1024)
 }
 
 func TestWrite1Mx100(t *testing.T) {
-	testWriteN(t, "1Mx100", 1024*1024, "b6d81b360a5672d80c27430f39153e2c")
+	hashWant := testWriteN(t, "1Mx100", 1024*1024)
 	// Read and check 100 times to catch race conditions
 	var i int
 	for i = 0; i < 100; i++ {
@@ -97,7 +102,7 @@ func TestWrite1Mx100(t *testing.T) {
 		}
 		rawHash := md5.Sum(buf)
 		hashActual := hex.EncodeToString(rawHash[:])
-		if hashActual != "b6d81b360a5672d80c27430f39153e2c" {
+		if hashActual != hashWant {
 			fmt.Printf("Read corruption in loop # %d\n", i)
 			t.FailNow()
 		} else {
diff --git a/pathfs_frontend/file.go b/pathfs_frontend/file.go
index 0ce4257..d94fe1b 100644
--- a/pathfs_frontend/file.go
+++ b/pathfs_frontend/file.go
@@ -59,11 +59,11 @@ func (f *file) doRead(off uint64, length uint64) ([]byte, fuse.Status) {
 	ciphertext := make([]byte, int(alignedLength))
 	n, err := f.fd.ReadAt(ciphertext, int64(alignedOffset))
 	ciphertext = ciphertext[0:n]
-	cryptfs.Debug.Printf("ReadAt length=%d offset=%d -> n=%d len=%d\n", alignedLength, alignedOffset, n, len(ciphertext))
 	if err != nil && err != io.EOF {
 		cryptfs.Warn.Printf("read: ReadAt: %s\n", err.Error())
 		return nil, fuse.ToStatus(err)
 	}
+	cryptfs.Debug.Printf("ReadAt length=%d offset=%d -> n=%d len=%d\n", alignedLength, alignedOffset, n, len(ciphertext))
 
 	// Decrypt it
 	plaintext, err := f.cfs.DecryptBlocks(ciphertext)
@@ -107,6 +107,8 @@ func (f *file) Read(buf []byte, off int64) (resultData fuse.ReadResult, code fus
 
 // Write - FUSE call
 func (f *file) Write(data []byte, off int64) (uint32, fuse.Status) {
+	cryptfs.Debug.Printf("Write: offset=%d length=%d\n", off, len(data))
+
 	var written uint32
 	var status fuse.Status
 	dataBuf := bytes.NewBuffer(data)
@@ -126,10 +128,12 @@ func (f *file) Write(data []byte, off int64) (uint32, fuse.Status) {
 			}
 			// Modify
 			blockData = f.cfs.MergeBlocks(oldData, blockData, int(b.Offset))
+			cryptfs.Debug.Printf("oldData=%d blockData=%d\n", len(oldData), len(blockData))
 		}
 		// Write
 		blockOffset, _ := b.CiphertextRange()
 		blockData = f.cfs.EncryptBlock(blockData)
+		cryptfs.Debug.Printf("WriteAt offset=%d length=%d\n", blockOffset, len(blockData))
 		_, err := f.fd.WriteAt(blockData, int64(blockOffset))
 
 		if err != nil {