Skip to content
Merged
Show file tree
Hide file tree
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 2 additions & 3 deletions pkg/rslog/NEWS.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
168 changes: 87 additions & 81 deletions pkg/rslog/debug.go
Original file line number Diff line number Diff line change
@@ -1,111 +1,130 @@
package rslog

// Copyright (C) 2022 by RStudio, PBC.
// Copyright (C) 2025 by Posit Software, PBC.

import (
"sync"
)

// ProductRegion is a numerical value assigned to an area of the product.
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Added docs throughout the file.

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
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Renamed the globals to clearly indicate that they are only for debug log handling.


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()
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Used the mutex for ALL debugRegions and debugEnabled accesses. We no longer assume that some functions are only called at program startup. Consistent use of the mutex is easier to explain that implicit conventions.

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]
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

InitDebugLogs() directly accesses debugRegions because RegionName() now uses debugMutex; we need InitDebugLogs() to hold the mutex until its work is complete.

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 {
Expand All @@ -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)

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This isn't really relevant for this PR but I don't understand why WithSubRegion exists. Why not just call WithFields() like we do in the tests down below?

                gr.WithFields(Fields{
			"region":     "alfa",
			"sub_region": "drinks",
		})

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I do not want to alter the public API.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The API exists because folks wanted a well-known field name.

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
}
Loading
Loading