debug logger: remove logger callbacks

All debug logger instances were previously attached to a global set of
callbacks. This was done so loggers could be informed if they were ever enabled
dynamically. Unfortunately, loggers were never removed from this set of
callbacks, which meant that those loggers could never be reclaimed by the
garbage collector. Debug loggers are often constructed as the program runs,
adding fields and values to assist with tracing. This meant that programs often
did not have a static set of loggers, but were always creating new debug
loggers, which were always seen as live objects.

Now, debug loggers always ask their enabled status from the map tracking
enabled state. This incurs the cost of a mutex-read lock and map lookup at
runtime.

Author: aronatkins

pkg/rslog/NEWS.md

@@ -9,11 +9,10 @@ Unreleased
 *   Uncomment when items are available.
 -->
 
-<!--
 ### Fixed
 
-*   Uncomment when items are available.
--->
+*   Debug loggers are no longer attached to a global set of callbacks, which
+    means that those loggers are available for garbage collection.
 
 <!--
 ### Breaking

pkg/rslog/debug.go

@@ -6,106 +6,125 @@ import (
 	"sync"
 )
 
+// ProductRegion is a numerical value assigned to an area of the product.
 type ProductRegion int
 
-// regionNames translates the enum region to its string equivalent. This is
-// used for display (when logging) and also when processing the configuration
-// values.
-var regionNames map[ProductRegion]string
+// debugMutex protects access to product debug region/enabled information.
+var debugMutex sync.RWMutex
 
-type callbacksArr []func(flag bool)
+// debugRegions relates a numerical product debug region to its string
+// equivalent. Used for display (when logging) and when processing
+// configuration values.
+//
+// Protected by debugMutex.
+var debugRegions map[ProductRegion]string = map[ProductRegion]string{}
 
-var regionCallbacks = map[ProductRegion]callbacksArr{}
-var regionsEnabled = map[ProductRegion]bool{}
-var debugMutex sync.RWMutex
+// debugEnabled records product debug regions which enable debug logging.
+//
+// Protected by debugMutex.
+var debugEnabled map[ProductRegion]bool = map[ProductRegion]bool{}
 
+// RegisterRegions registers product debug regions. Called once at program
+// startup.
 func RegisterRegions(regions map[ProductRegion]string) {
-	regionNames = regions
+	debugMutex.Lock()
+	defer debugMutex.Unlock()
+
+	debugRegions = regions
 }
 
+// RegionNames returns the names of all registered product debug regions.
 func RegionNames() []string {
+	debugMutex.RLock()
+	defer debugMutex.RUnlock()
+
 	var names []string
-	for _, name := range regionNames {
+	for _, name := range debugRegions {
 		names = append(names, name)
 	}
 	return names
 }
 
+// Regions returns the numerical product debug regions.
 func Regions() []ProductRegion {
+	debugMutex.RLock()
+	defer debugMutex.RUnlock()
+
 	var regions []ProductRegion
-	for r := range regionNames {
+	for r := range debugRegions {
 		regions = append(regions, r)
 	}
 	return regions
 }
 
-func RegionByName(text string) ProductRegion {
-	for region, name := range regionNames {
-		if name == text {
+// RegionByName returns the numerical product debug region associated with
+// name. Returns zero when there is no match.
+func RegionByName(name string) ProductRegion {
+	debugMutex.RLock()
+	defer debugMutex.RUnlock()
+
+	for region, region_name := range debugRegions {
+		if name == region_name {
 			return region
 		}
 	}
 	return 0
 }
 
+// RegionName returns the name associated with the numerical product debug
+// region. Returns an empty string when there is no match.
 func RegionName(region ProductRegion) string {
-	return regionNames[region]
+	debugMutex.RLock()
+	defer debugMutex.RUnlock()
+
+	return debugRegions[region]
 }
 
-// Register debug regions enabled.
-// This should be called as early as possible when starting an application.
+// InitDebugLogs registers a set of product debug regions as enabled.
+//
+// This should be called as early as possible when starting an application,
+// but after RegisterRegions.
 func InitDebugLogs(regions []ProductRegion) {
 	debugMutex.Lock()
 	defer debugMutex.Unlock()
 
 	// Reset enabled regions on each call.
-	regionsEnabled = make(map[ProductRegion]bool)
+	debugEnabled = make(map[ProductRegion]bool)
 	lgr := DefaultLogger()
 
 	// match debug log region to list
 	for _, region := range regions {
 		if region == 0 {
 			continue
 		}
-		regionsEnabled[region] = true
-		regionName := RegionName(region)
+		debugEnabled[region] = true
+		regionName := debugRegions[region]
 		lgr.Infof("Debug logging enabled for area: %s", regionName)
 	}
 }
 
-// Enable turns on logging for a named region. Useful in test.
+// Enable turns on debug logging for region. Useful in test.
 func Enable(region ProductRegion) {
 	debugMutex.Lock()
 	defer debugMutex.Unlock()
 
-	regionsEnabled[region] = true
-	_, ok := regionCallbacks[region]
-	if ok {
-		for _, cb := range regionCallbacks[region] {
-			cb(true)
-		}
-	}
+	debugEnabled[region] = true
 }
 
-// Disable turns on logging for a named region. Useful in test.
+// Disable turns on debug logging for region. Useful in test.
 func Disable(region ProductRegion) {
 	debugMutex.Lock()
 	defer debugMutex.Unlock()
 
-	regionsEnabled[region] = false
-	_, ok := regionCallbacks[region]
-	if ok {
-		for _, cb := range regionCallbacks[region] {
-			cb(false)
-		}
-	}
+	debugEnabled[region] = false
 }
 
-// Enabled returns true if debug logging is configured for this region.
+// Enabled returns true if debug logging is configured for region.
 func Enabled(region ProductRegion) bool {
 	debugMutex.RLock()
 	defer debugMutex.RUnlock()
-	return regionsEnabled[region]
+
+	return debugEnabled[region]
 }
 
 type DebugLogger interface {
@@ -118,86 +137,73 @@ type DebugLogger interface {
 
 type debugLogger struct {
 	Logger
-	region  ProductRegion
-	enabled bool
+	region ProductRegion
 }
 
-// NewDebugLogger returns a new logger which includes
-// the name of the debug region at every message.
+// NewDebugLogger returns a new logger which includes the name of the product
+// debug region at every message. Debugf and Tracef only occur when the
+// product debug region is enabled.
+//
+// Logging occurs only when enabled for region.
 func NewDebugLogger(region ProductRegion) *debugLogger {
 	lgr := DefaultLogger()
 
+	regionName := RegionName(region)
 	entry := lgr.WithFields(Fields{
-		"region": regionNames[region],
+		"region": regionName,
 	})
 
 	dbglgr := &debugLogger{
-		Logger:  entry,
-		region:  region,
-		enabled: Enabled(region),
+		Logger: entry,
+		region: region,
 	}
 
-	registerLoggerCb(region, dbglgr.enable)
-
 	return dbglgr
 }
 
-func registerLoggerCb(region ProductRegion, cb func(bool)) {
-	debugMutex.Lock()
-	defer debugMutex.Unlock()
-
-	regionCallbacks[region] = append(regionCallbacks[region], cb)
-}
-
-// Enabled returns true if debug logging is enabled for this rslog.
+// Enabled returns true if debug logging is enabled for the associated product
+// debug region.
 func (l *debugLogger) Enabled() bool {
 	return Enabled(l.region)
 }
 
+// Debugf logs a message when debug logging is enabled for the associated
+// product debug region.
 func (l *debugLogger) Debugf(message string, args ...interface{}) {
-	debugMutex.RLock()
-	defer debugMutex.RUnlock()
-
-	if l.enabled {
+	if l.Enabled() {
 		l.Logger.Debugf(message, args...)
 	}
 }
 
+// Tracef logs a message when debug logging is enabled for the associated
+// product debug region.
 func (l *debugLogger) Tracef(message string, args ...interface{}) {
-	debugMutex.RLock()
-	defer debugMutex.RUnlock()
-
-	if l.enabled {
+	if l.Enabled() {
 		l.Logger.Tracef(message, args...)
 	}
 }
 
-// Set fields to be logged
+// WithFields returns a new logger having additional fields. The returned
+// logger is associated with the same product debug region.
 func (l *debugLogger) WithFields(fields Fields) DebugLogger {
 	newLgr := l.Logger.WithFields(fields)
 	dbglgr := &debugLogger{
-		Logger:  newLgr,
-		region:  l.region,
-		enabled: l.enabled,
+		Logger: newLgr,
+		region: l.region,
 	}
-	registerLoggerCb(l.region, dbglgr.enable)
 	return dbglgr
 }
 
-// WithSubRegion returns a debug logger with further specificity
-// via sub_region key:value. E.g "region": "LDAP", "sub_region": "membership scanner"
+// WithSubRegion returns a debug logger having an additional "sub_region"
+// field. The returned logger is associated with the same product debug
+// region.
+//
+// Equivalent to `debugLogger.WithField("sub_region", subregion)`
 func (l *debugLogger) WithSubRegion(subregion string) DebugLogger {
 	newLgr := l.Logger.WithField("sub_region", subregion)
 	dbglgr := &debugLogger{
-		Logger:  newLgr,
-		region:  l.region,
-		enabled: l.enabled,
+		Logger: newLgr,
+		region: l.region,
 	}
-	registerLoggerCb(l.region, dbglgr.enable)
 	return dbglgr
 }
-
-// Enable or disable this region debug logging instance
-func (l *debugLogger) enable(enabled bool) {
-	l.enabled = enabled
-}