]> go.fuhry.dev Git - runtime.git/commitdiff
[mtls/fsnotify] hush fsnotify debug log messages
authorDan Fuhry <dan@fuhry.com>
Sat, 14 Mar 2026 23:39:19 +0000 (19:39 -0400)
committerDan Fuhry <dan@fuhry.com>
Sun, 15 Mar 2026 01:17:54 +0000 (21:17 -0400)
mtls/fsnotify/fsnotify.go

index 0fd985a94b4d1688c2631fa6cc31e316846c71ed..23f8fefe1397363b4018da6b74e3b766d03687c8 100644 (file)
@@ -29,23 +29,26 @@ import (
        "sync"
 
        "go.fuhry.dev/fsnotify"
+
        "go.fuhry.dev/runtime/utils/hashset"
        "go.fuhry.dev/runtime/utils/log"
 )
 
-type NotifyFunc = func(string, fsnotify.Op)
-type notifyRule struct {
-       // absPath is the real path of the file after resolving all symlinks both in the filename
-       // itself, and in any of the directories in the path components of the file's absolute path.
-       absPath string
-       // inum is the inode number of the underlying file after resolving
-       // all symlinks.
-       inum int64
-       // upstreams is a HashSet of the original filename, target filename, and all intermediates
-       // in between
-       upstreams *hashset.HashSet[string]
-       callbacks []NotifyFunc
-}
+type (
+       NotifyFunc = func(string, fsnotify.Op)
+       notifyRule struct {
+               // absPath is the real path of the file after resolving all symlinks both in the filename
+               // itself, and in any of the directories in the path components of the file's absolute path.
+               absPath string
+               // inum is the inode number of the underlying file after resolving
+               // all symlinks.
+               inum int64
+               // upstreams is a HashSet of the original filename, target filename, and all intermediates
+               // in between
+               upstreams *hashset.HashSet[string]
+               callbacks []NotifyFunc
+       }
+)
 
 type Op = fsnotify.Op
 
@@ -58,9 +61,11 @@ var (
        Close  = fsnotify.Close
 )
 
-var startWatcherMu sync.Mutex
-var gWatcher *fsnotify.Watcher
-var logger log.Logger
+var (
+       startWatcherMu sync.Mutex
+       gWatcher       *fsnotify.Watcher
+       logger         log.Logger
+)
 
 // Map of original path => notifyRule.
 // This tracks paths we were asked to watch. More paths may be watched than the entries here, if
@@ -86,7 +91,7 @@ func startWatcher() error {
                return nil
        }
 
-       logger = log.Default().WithPrefix("mtls/fsnotify")
+       logger = log.Default().WithPrefix("mtls/fsnotify").V(4)
        initState()
        // inodes = make(map[string]int64)
        watcher, err := fsnotify.NewWatcher()
@@ -111,17 +116,17 @@ func subscribeInternal(filePath string) error {
        defer startWatcherMu.Unlock()
 
        if n, ok := watched[filePath]; ok {
-               logger.V(2).Debugf("subscribe(%s): refCount=%d", filePath, n+1)
+               logger.Debugf("subscribe(%s): refCount=%d", filePath, n+1)
                watched[filePath]++
                return nil
        }
 
        err := gWatcher.Add(filePath)
        if err != nil {
-               logger.V(2).Errorf("subscribe(%s): ERR=%v", filePath, err)
+               logger.Errorf("subscribe(%s): ERR=%v", filePath, err)
                return err
        }
-       logger.V(2).Debugf("subscribe(%s): refCount=1", filePath)
+       logger.Debugf("subscribe(%s): refCount=1", filePath)
        watched[filePath] = 1
        return nil
 }
@@ -141,12 +146,12 @@ func unsubscribeInternal(filePath string) error {
        defer startWatcherMu.Unlock()
 
        if _, ok := watched[filePath]; !ok {
-               logger.V(2).Debugf("unsubscribe(%s): refCount=!NF", filePath)
+               logger.Debugf("unsubscribe(%s): refCount=!NF", filePath)
                return nil
        }
 
        watched[filePath]--
-       logger.V(2).Debugf("unsubscribe(%s): refCount=%d", filePath, watched[filePath])
+       logger.Debugf("unsubscribe(%s): refCount=%d", filePath, watched[filePath])
        if watched[filePath] > 0 {
                return nil
        }
@@ -155,10 +160,10 @@ func unsubscribeInternal(filePath string) error {
        err := gWatcher.Remove(filePath)
        if err != nil {
                if errors.Is(err, fsnotify.ErrNonExistentWatch) {
-                       logger.V(2).Debugf("unsubscribe(%s): refCount=!0", filePath)
+                       logger.Debugf("unsubscribe(%s): refCount=!0", filePath)
                        return nil
                }
-               logger.V(2).Errorf("unsubscribe(%s): failed to remove a watch: %T(%+v)", filePath, err, err)
+               logger.Errorf("unsubscribe(%s): failed to remove a watch: %T(%+v)", filePath, err, err)
                // log error but don't block dir refcount from being decremented
                return nil
        }
@@ -225,7 +230,7 @@ func handleEvent(event fsnotify.Event) {
                // Event occurred on the underlying file (recursively-resolved absolute path) of a watched
                // path
                for _, child := range children.AsSortedSlice() {
-                       logger.V(2).Debugf("propagating %v event on %s to underlying path %s",
+                       logger.Debugf("propagating %v event on %s to underlying path %s",
                                event.Op, event.Name, child)
                        handleEventForPath(event, child)
                }
@@ -260,11 +265,11 @@ func handleEvent(event fsnotify.Event) {
                for _, link := range links {
                        for _, ruleName := range symlinkPropagationMap[link].AsSlice() {
                                if _, ok := watchHandlers[ruleName]; ok {
-                                       logger.V(2).Debugf("propagating %v event on %s to origin %s",
+                                       logger.Debugf("propagating %v event on %s to origin %s",
                                                event.Op, link, ruleName)
                                        handleEventForPath(event, ruleName)
                                } else {
-                                       logger.V(2).Errorf("symlinkPropagationMap target without corresponding rule: %s", ruleName)
+                                       logger.Errorf("symlinkPropagationMap target without corresponding rule: %s", ruleName)
                                }
                        }
                }
@@ -278,7 +283,7 @@ func handleEvent(event fsnotify.Event) {
                        return
                }
        }
-       logger.V(4).Warningf("dangling watcher on path %s: not known within normal rules or symlink map: %v", event.Name, event.Op)
+       logger.Warningf("dangling watcher on path %s: not known within normal rules or symlink map: %v", event.Name, event.Op)
 }
 
 // handleEventForPath is the second stage of event handling which calls the actual handlers.
@@ -290,15 +295,15 @@ func handleEvent(event fsnotify.Event) {
 func handleEventForPath(event fsnotify.Event, ruleName string) {
        rule, ok := watchHandlers[ruleName]
        if !ok {
-               logger.V(1).Errorf("handleEventForPath called for file without rule: %s: %+v", ruleName, event)
+               logger.Errorf("handleEventForPath called for file without rule: %s: %+v", ruleName, event)
                return
        }
 
        op := event.Op
 
-       logger.V(2).Debugf("inotify event on %s: %v", event.Name, event.Op)
-       logger.V(2).Debugf("ruleName: %s", ruleName)
-       logger.V(2).Debugf("upstreams: %+v", rule.upstreams.AsSlice())
+       logger.Debugf("inotify event on %s: %v", event.Name, event.Op)
+       logger.Debugf("ruleName: %s", ruleName)
+       logger.Debugf("upstreams: %+v", rule.upstreams.AsSlice())
 
        newRealpath := resolveSymlinkAndDereferenceParents(ruleName)
        newInum := inum(newRealpath)
@@ -306,7 +311,7 @@ func handleEventForPath(event fsnotify.Event, ruleName string) {
        handlerPath := event.Name
 
        if fileSwapped {
-               logger.V(1).Noticef(
+               logger.Noticef(
                        "watched file %s: detected absolute path or inum change, pruning watchers:\n  %s->%s\n  %d->%d",
                        ruleName,
                        rule.absPath, newRealpath,
@@ -321,7 +326,7 @@ func handleEventForPath(event fsnotify.Event, ruleName string) {
                untrackSymlinks(ruleName)
                Unsubscribe(ruleName)
                if len(watchHandlers) == 1 {
-                       logger.V(2).Noticef("all watchers should now be cleaned up:")
+                       logger.Noticef("all watchers should now be cleaned up:")
                        Debug()
                }
                subscribe(ruleName)
@@ -368,7 +373,7 @@ func untrackSymlinks(ruleName string) {
        var toDelete []string
        for link, targets := range symlinkPropagationMap {
                if targets.Contains(ruleName) {
-                       logger.V(2).Debugf("cleaning up watcher on %s for fsnotify watch rule %s", link, ruleName)
+                       logger.Debugf("cleaning up watcher on %s for fsnotify watch rule %s", link, ruleName)
                        Unsubscribe(link)
                        targets.Del(ruleName)
                }
@@ -384,7 +389,7 @@ func untrackSymlinks(ruleName string) {
 
 func symlinkPropagationChildren(link string) []string {
        var targets []string
-       for path, _ := range symlinkPropagationMap {
+       for path := range symlinkPropagationMap {
                if path == link || strings.HasPrefix(path, link+"/") {
                        targets = append(targets, path)
                }
@@ -406,7 +411,7 @@ func scanSymlinks(filePath string) error {
                        break
                }
 
-               logger.V(1).Debugf("symlink resolution step yields abspath: %s", target)
+               logger.Debugf("symlink resolution step yields abspath: %s", target)
                rule.upstreams.Add(target)
 
                subscribe(target)
@@ -418,10 +423,10 @@ func scanSymlinks(filePath string) error {
                // replaced, we can fire a change event on the original file.
                for _, link := range symlinksInFullpath(target) {
                        target = link.target + strings.TrimPrefix(target, link.link)
-                       logger.V(1).Debugf("while adding watcher on file %s: rewrote abspath to %s based on symlink %s->%s",
+                       logger.Debugf("while adding watcher on file %s: rewrote abspath to %s based on symlink %s->%s",
                                filePath, target, link.link, link.target)
                        if _, err := os.Lstat(link.target); err != nil {
-                               logger.V(1).Warningf("failed to stat resolved parent directory %s: %v", link.target, err)
+                               logger.Warningf("failed to stat resolved parent directory %s: %v", link.target, err)
                                continue
                        }
                        rule.upstreams.Add(target)
@@ -438,28 +443,28 @@ func scanSymlinks(filePath string) error {
 }
 
 func Debug() {
-       logger.V(1).Debugf("symlinkPropagationMap:")
+       logger.Debugf("symlinkPropagationMap:")
        if len(symlinkPropagationMap) == 0 {
-               logger.V(1).Debugf("  <NONE>")
+               logger.Debugf("  <NONE>")
        }
        for filePath, members := range symlinkPropagationMap {
-               logger.V(1).Debugf("   %s: %+v", filePath, members.AsSortedSlice())
+               logger.Debugf("   %s: %+v", filePath, members.AsSortedSlice())
        }
 
-       logger.V(1).Debugf("watchHandlers:")
+       logger.Debugf("watchHandlers:")
        if len(watchHandlers) == 0 {
-               logger.V(1).Debugf("  <NONE>")
+               logger.Debugf("  <NONE>")
        }
        for filePath, rule := range watchHandlers {
-               logger.V(1).Debugf("   %s: upstreams=%+v, %+v", filePath, rule.upstreams.AsSortedSlice(), rule.callbacks)
+               logger.Debugf("   %s: upstreams=%+v, %+v", filePath, rule.upstreams.AsSortedSlice(), rule.callbacks)
        }
 
-       logger.V(1).Debugf("fsnotify ref counts:")
+       logger.Debugf("fsnotify ref counts:")
        if len(watched) == 0 {
-               logger.V(1).Debugf("  <NONE>")
+               logger.Debugf("  <NONE>")
        }
        for filePath, n := range watched {
-               logger.V(1).Debugf("  %s: %d", filePath, n)
+               logger.Debugf("  %s: %d", filePath, n)
        }
 }
 
@@ -474,7 +479,7 @@ func NotifyPath(filePath string, callback NotifyFunc) error {
                return fmt.Errorf("unable to watch %s: error calling lstat: %v", filePath, err)
        }
 
-       logger.V(1).Debugf("adding watcher on file %s", filePath)
+       logger.Debugf("adding watcher on file %s", filePath)
        err = subscribe(filePath)
        if err != nil {
                return err
@@ -504,7 +509,7 @@ func Stop() {
        }
        startWatcherMu.Unlock()
 
-       for path, _ := range watched {
+       for path := range watched {
                unsubscribeInternal(path)
        }