From d95182f187e228b1999ffcd18114d98d8e8a0a21 Mon Sep 17 00:00:00 2001
From: PhatPhuckDave <david.majdandzic@hotmail.com>
Date: Thu, 21 Aug 2025 13:11:56 +0200
Subject: [PATCH] Add some logs

---
 main.go | 36 ++++++++++++++++++++++++++----------
 1 file changed, 26 insertions(+), 10 deletions(-)

diff --git a/main.go b/main.go
index 1763317..271d912 100644
--- a/main.go
+++ b/main.go
@@ -88,9 +88,7 @@ func loadConfig() Constants {
 			}
 		}
 	}
-	// Always ignore ROOT and ROOT_ARCHIVE themselves
 	ignored = append(ignored, filepath.ToSlash(archive))
-	ignored = append(ignored, filepath.ToSlash(root))
 
 	archiveMs := parseDurationMS(getenv("ARCHIVE_THRESHOLD", "1d"))
 	deleteMs := parseDurationMS(getenv("DELETE_THRESHOLD", "12h"))
@@ -118,15 +116,18 @@ func loadConfig() Constants {
 }
 
 func shouldIgnore(path string) bool {
+	log := logger.Default.WithPrefix("shouldIgnore").WithPrefix(path)
 	// Match against slash-normalized full path
 	path = filepath.ToSlash(path)
 	for _, pat := range constants.IGNORED_DIRECTORIES {
+		patLog := log.WithPrefix(pat)
 		ok, err := doublestar.Match(pat, path)
 		if err != nil {
-			logger.Warning("Ignore pattern error %q vs %q: %v", pat, path, err)
+			patLog.Warning("Ignore pattern error %q vs %q: %v", pat, path, err)
 			continue
 		}
-		if ok || path == pat {
+		if ok {
+			patLog.Debug("ignore due to doublestar %q", pat)
 			return true
 		}
 	}
@@ -143,50 +144,58 @@ func fileTime(info os.FileInfo) int64 {
 }
 
 func archiveCandidate(path string, info os.FileInfo) {
+	log := logger.Default.WithPrefix("archiveCandidate")
 	if info.IsDir() {
 		return
 	}
 	now := time.Now().UnixMilli()
 	ft := fileTime(info)
+	log.Debug("now %s filetime %s", time.UnixMilli(now).Format(time.RFC3339), time.UnixMilli(ft).Format(time.RFC3339))
 	if now-ft <= constants.ARCHIVE_THRESHOLD {
+		log.Debug("skip")
 		return
 	}
 
 	rel, err := filepath.Rel(constants.ROOT, path)
 	if err != nil {
-		logger.Warning("rel ROOT->%s: %v", path, err)
+		log.Warning("rel ROOT->%s: %v", path, err)
 		return
 	}
 	dst := filepath.Join(constants.ROOT_ARCHIVE, rel)
+	log.Debug("dst %s", dst)
 
 	if err := os.MkdirAll(filepath.Dir(dst), os.ModePerm); err != nil {
-		logger.Error("mkdir %s: %v", filepath.Dir(dst), err)
+		log.Error("mkdir %s: %v", filepath.Dir(dst), err)
 		return
 	}
 
 	if err := os.Rename(path, dst); err != nil {
-		logger.Error("archive %s -> %s: %v", path, dst, err)
+		log.Error("archive %s -> %s: %v", path, dst, err)
 		return
 	}
 	numFilesArchived++
-	logger.Info("Archived: %s -> %s", path, dst)
+	log.Info("Archived: %s -> %s", path, dst)
 }
 
 func deleteCandidate(path string, info os.FileInfo) {
+	log := logger.Default.WithPrefix("deleteCandidate").WithPrefix(path)
 	if info.IsDir() {
 		return
 	}
 	now := time.Now().UnixMilli()
 	ft := fileTime(info)
+	log.Debug("now %s filetime %s", time.UnixMilli(now).Format(time.RFC3339), time.UnixMilli(ft).Format(time.RFC3339))
 	if now-ft <= constants.DELETE_THRESHOLD {
+		log.Debug("skip")
 		return
 	}
+	log.Debug("delete")
 	if err := os.Remove(path); err != nil {
-		logger.Error("delete %s: %v", path, err)
+		log.Error("delete %s: %v", path, err)
 		return
 	}
 	numFilesDeleted++
-	logger.Info("Deleted: %s", path)
+	log.Info("Deleted: %s", path)
 }
 
 func scanRoot() {
@@ -194,17 +203,23 @@ func scanRoot() {
 	root := constants.ROOT
 
 	// doublestar.Glob with os.DirFS(root) returns relative paths
+	log.Debug("glob %s", root)
 	paths, err := doublestar.Glob(os.DirFS(root), "**")
 	if err != nil {
 		log.Error("glob %s: %v", root, err)
 		return
 	}
+	log.Info("Found %d files in root", len(paths))
 	for _, rel := range paths {
+		pathLog := log.WithPrefix(rel)
 		full := filepath.Join(root, rel)
+		pathLog.Debug("full %s", full)
 		if shouldIgnore(full) {
+			pathLog.Debug("ignore")
 			continue
 		}
 		info, err := os.Stat(full)
+		pathLog.Trace("stat %+v", info)
 		if err != nil {
 			log.Warning("stat %s: %v", full, err)
 			continue
@@ -313,6 +328,7 @@ func main() {
 
 	logger.Info("Starting directory cleaner")
 	constants = loadConfig()
+	constants.USE_MODTIME = true
 	logger.Info("Ready. First scan in %s", constants.SCAN_INTERVAL)
 
 	// Run immediately, then on interval