allow setting log level for freeport helper

pull/22103/head
Ludwig Bedacht 2025-01-23 13:35:22 +01:00
parent f82f5207a1
commit 7c2385f7f8
No known key found for this signature in database
GPG Key ID: 4A9C5FEC7250E1C4
2 changed files with 183 additions and 15 deletions

View File

@ -93,6 +93,10 @@ var (
// portLastUser associates ports with a test name in order to debug // portLastUser associates ports with a test name in order to debug
// which test may be leaking unclosed TCP connections. // which test may be leaking unclosed TCP connections.
portLastUser map[int]string portLastUser map[int]string
// logLevel is the verbosity of the logging output.
// The default log level is DEBUG.
logLevel LogLevel
) )
// initialize is used to initialize freeport. // initialize is used to initialize freeport.
@ -105,7 +109,7 @@ func initialize() {
panic("freeport: error getting system limit: " + err.Error()) panic("freeport: error getting system limit: " + err.Error())
} }
if limit > 0 && limit < blockSize { if limit > 0 && limit < blockSize {
logf("INFO", "blockSize %d too big for system limit %d. Adjusting...", blockSize, limit) logf(INFO, "blockSize %d too big for system limit %d. Adjusting...", blockSize, limit)
blockSize = limit - 3 blockSize = limit - 3
} }
@ -161,7 +165,7 @@ func shutdownGoroutine() {
// reset will reverse the setup from initialize() and then redo it (for tests) // reset will reverse the setup from initialize() and then redo it (for tests)
func reset() { func reset() {
logf("INFO", "resetting the freeport package state") logf(INFO, "resetting the freeport package state")
shutdownGoroutine() shutdownGoroutine()
mu.Lock() mu.Lock()
@ -189,7 +193,7 @@ func checkFreedPorts(stopCh <-chan struct{}) {
for { for {
select { select {
case <-stopCh: case <-stopCh:
logf("INFO", "Closing checkFreedPorts()") logf(INFO, "Closing checkFreedPorts()")
return return
case <-ticker.C: case <-ticker.C:
checkFreedPortsOnce() checkFreedPortsOnce()
@ -209,14 +213,14 @@ func checkFreedPortsOnce() {
freePorts.PushBack(port) freePorts.PushBack(port)
remove = append(remove, elem) remove = append(remove, elem)
} else { } else {
logf("WARN", "port %d still being used by %q", port, portLastUser[port]) logf(WARN, "port %d still being used by %q", port, portLastUser[port])
} }
} }
retained := pending - len(remove) retained := pending - len(remove)
if retained > 0 { if retained > 0 {
logf("WARN", "%d out of %d pending ports are still in use; something probably didn't wait around for the port to be closed!", retained, pending) logf(WARN, "%d out of %d pending ports are still in use; something probably didn't wait around for the port to be closed!", retained, pending)
} }
if len(remove) == 0 { if len(remove) == 0 {
@ -239,17 +243,17 @@ func adjustMaxBlocks() (int, error) {
} }
if ephemeralPortMin <= 0 || ephemeralPortMax <= 0 { if ephemeralPortMin <= 0 || ephemeralPortMax <= 0 {
logf("INFO", "ephemeral port range detection not configured for GOOS=%q", runtime.GOOS) logf(INFO, "ephemeral port range detection not configured for GOOS=%q", runtime.GOOS)
return maxBlocks, nil return maxBlocks, nil
} }
logf("INFO", "detected ephemeral port range of [%d, %d]", ephemeralPortMin, ephemeralPortMax) logf(INFO, "detected ephemeral port range of [%d, %d]", ephemeralPortMin, ephemeralPortMax)
for block := 0; block < maxBlocks; block++ { for block := 0; block < maxBlocks; block++ {
min := lowPort + block*blockSize min := lowPort + block*blockSize
max := min + blockSize max := min + blockSize
overlap := intervalOverlap(min, max-1, ephemeralPortMin, ephemeralPortMax) overlap := intervalOverlap(min, max-1, ephemeralPortMin, ephemeralPortMax)
if overlap { if overlap {
logf("INFO", "reducing max blocks from %d to %d to avoid the ephemeral port range", maxBlocks, block) logf(INFO, "reducing max blocks from %d to %d to avoid the ephemeral port range", maxBlocks, block)
return block, nil return block, nil
} }
} }
@ -285,6 +289,44 @@ func MustTake(n int) (ports []int) {
return ports return ports
} }
type LogLevel uint8
const (
DEBUG LogLevel = iota
INFO
WARN
ERROR
DISABLED
)
func (l LogLevel) String() string {
switch l {
case DEBUG:
return "DEBUG"
case INFO:
return "INFO"
case WARN:
return "WARN"
case ERROR:
return "ERROR"
default:
return "DISABLED"
}
}
// SetLogLevel sets the verbosity of the logging output.
// The default log level is DEBUG.
func SetLogLevel(level LogLevel) {
mu.Lock()
defer mu.Unlock()
if level > DISABLED {
level = DISABLED
}
logLevel = level
}
// Take returns a list of free ports from the reserved port block. It is safe // Take returns a list of free ports from the reserved port block. It is safe
// to call this method concurrently. Ports have been tested to be available on // to call this method concurrently. Ports have been tested to be available on
// 127.0.0.1 TCP but there is no guarantee that they will remain free in the // 127.0.0.1 TCP but there is no guarantee that they will remain free in the
@ -321,7 +363,7 @@ func Take(n int) (ports []int, err error) {
if used := isPortInUse(port); used { if used := isPortInUse(port); used {
// Something outside of the test suite has stolen this port, possibly // Something outside of the test suite has stolen this port, possibly
// due to assignment to an ephemeral port, remove it completely. // due to assignment to an ephemeral port, remove it completely.
logf("WARN", "leaked port %d due to theft; removing from circulation", port) logf(WARN, "leaked port %d due to theft; removing from circulation", port)
total-- total--
continue continue
} }
@ -394,18 +436,24 @@ func tcpAddr(ip string, port int) *net.TCPAddr {
// represented by [min1, max1] and [min2, max2] overlap. // represented by [min1, max1] and [min2, max2] overlap.
func intervalOverlap(min1, max1, min2, max2 int) bool { func intervalOverlap(min1, max1, min2, max2 int) bool {
if min1 > max1 { if min1 > max1 {
logf("WARN", "interval1 is not ordered [%d, %d]", min1, max1) logf(WARN, "interval1 is not ordered [%d, %d]", min1, max1)
return false return false
} }
if min2 > max2 { if min2 > max2 {
logf("WARN", "interval2 is not ordered [%d, %d]", min2, max2) logf(WARN, "interval2 is not ordered [%d, %d]", min2, max2)
return false return false
} }
return min1 <= max2 && min2 <= max1 return min1 <= max2 && min2 <= max1
} }
func logf(severity string, format string, a ...interface{}) { func logf(severity LogLevel, format string, a ...interface{}) {
fmt.Fprintf(os.Stderr, "["+severity+"] freeport: "+format+"\n", a...) if severity >= DISABLED {
return
}
if severity >= logLevel {
fmt.Fprintf(os.Stderr, "["+severity.String()+"] freeport: "+format+"\n", a...)
}
} }
// TestingT is the minimal set of methods implemented by *testing.T that are // TestingT is the minimal set of methods implemented by *testing.T that are
@ -428,7 +476,7 @@ func GetN(t TestingT, n int) []int {
if err != nil { if err != nil {
t.Fatalf("failed to take %v ports: %w", n, err) t.Fatalf("failed to take %v ports: %w", n, err)
} }
logf("DEBUG", "Test %q took ports %v", t.Name(), ports) logf(DEBUG, "Test %q took ports %v", t.Name(), ports)
mu.Lock() mu.Lock()
for _, p := range ports { for _, p := range ports {
portLastUser[p] = t.Name() portLastUser[p] = t.Name()
@ -436,7 +484,7 @@ func GetN(t TestingT, n int) []int {
mu.Unlock() mu.Unlock()
t.Cleanup(func() { t.Cleanup(func() {
Return(ports) Return(ports)
logf("DEBUG", "Test %q returned ports %v", t.Name(), ports) logf(DEBUG, "Test %q returned ports %v", t.Name(), ports)
}) })
return ports return ports
} }

View File

@ -4,9 +4,11 @@
package freeport package freeport
import ( import (
"bytes"
"fmt" "fmt"
"io" "io"
"net" "net"
"os"
"testing" "testing"
"github.com/hashicorp/consul/sdk/testutil/retry" "github.com/hashicorp/consul/sdk/testutil/retry"
@ -232,3 +234,121 @@ func TestIntervalOverlap(t *testing.T) {
}) })
} }
} }
func TestAllowSettingLogLevel(t *testing.T) {
cases := []struct {
level LogLevel
expected LogLevel
}{
{DEBUG, DEBUG},
{INFO, INFO},
{WARN, WARN},
{ERROR, ERROR},
{DISABLED, DISABLED},
{LogLevel(99), DISABLED},
}
for _, tc := range cases {
t.Run(fmt.Sprintf("Setting log level to %v", tc.level), func(t *testing.T) {
r, w, err := os.Pipe()
if err != nil {
t.Fatalf("failed to create pipe: %v", err)
}
t.Cleanup(func() {
_ = r.Close()
})
os.Stderr = w
SetLogLevel(tc.level)
if logLevel != tc.expected {
t.Fatalf("expected log level to be %v but got %v", tc.level, logLevel)
}
logf(tc.level, "This is a test log message")
_ = w.Close()
var b bytes.Buffer
if _, err := io.Copy(&b, r); err != nil {
t.Fatalf("failed to read from pipe: %v", err)
}
if tc.level >= DISABLED {
if b.String() != "" {
t.Fatalf("expected no log output but got %q", b.String())
}
return
}
expectedPrefix := []byte("[" + tc.expected.String() + "]")
if !bytes.HasPrefix(b.Bytes(), expectedPrefix) {
t.Fatalf("expected log output to start with %q but got %q", expectedPrefix, b.Bytes())
}
})
}
}
func TestLogLevelMessages(t *testing.T) {
tests := []struct {
level LogLevel
inputLogLevel LogLevel
expectMessageInStdErr bool
}{
{
level: DEBUG,
inputLogLevel: INFO,
expectMessageInStdErr: true,
},
{
level: INFO,
inputLogLevel: INFO,
expectMessageInStdErr: true,
},
{
level: WARN,
inputLogLevel: INFO,
expectMessageInStdErr: false,
},
{
level: ERROR,
inputLogLevel: INFO,
expectMessageInStdErr: false,
},
}
for _, tc := range tests {
t.Run(fmt.Sprintf("Setting log level to %v", tc.level), func(t *testing.T) {
r, w, err := os.Pipe()
if err != nil {
t.Fatalf("failed to create pipe: %v", err)
}
t.Cleanup(func() {
_ = r.Close()
})
os.Stderr = w
SetLogLevel(tc.level)
logf(tc.inputLogLevel, "This is a test log message")
_ = w.Close()
var b bytes.Buffer
if _, err := io.Copy(&b, r); err != nil {
t.Fatalf("failed to read from pipe: %v", err)
}
if tc.expectMessageInStdErr {
if b.String() == "" {
t.Fatalf("expected log output but got none")
}
} else {
if b.String() != "" {
t.Fatalf("expected no log output but got %q", b.String())
}
}
})
}
}