move to untimestamped logs, tag the lots INFO and DEBUG. Update tests

This commit is contained in:
Pim van Pelt
2025-06-11 00:22:16 +02:00
parent 0a0e3e7055
commit d408ec2867
5 changed files with 101 additions and 36 deletions

1
go.mod
View File

@ -16,6 +16,7 @@ require (
github.com/kr/text v0.2.0 // indirect
github.com/lunixbochs/struc v0.0.0-20200521075829-a4cb8d33dbbe // indirect
github.com/sirupsen/logrus v1.9.3 // indirect
github.com/stretchr/testify v1.8.1 // indirect
golang.org/x/sys v0.31.0 // indirect
)

7
go.sum
View File

@ -21,9 +21,14 @@ github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZN
github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ=
github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ=
github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw=
github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo=
github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY=
github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU=
github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk=
github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4=
go.fd.io/govpp v0.12.0 h1:5HnMzsKHSFdxglsFyEhR0g+CzncWiLYXG2NDYgNUrnE=
go.fd.io/govpp v0.12.0/go.mod h1:6qp4J/+jumgXXoowrtVAk13PSXS6+ghPrDG8CyuU/Is=
golang.org/x/net v0.37.0 h1:1zLorHbz+LYj7MQlSf1+2tPIIgibq2eL5xkrGk6f+2c=

View File

@ -4,43 +4,49 @@ package logger
import (
"fmt"
"log"
"path/filepath"
"runtime"
"govpp-snmp-agentx/config"
)
// logf logs a message with automatic caller information (file:function)
func logf(format string, args ...interface{}) {
pc, file, _, ok := runtime.Caller(2)
// getCallerInfo returns caller information in the format "file.go:function"
func getCallerInfo() string {
pc, file, _, ok := runtime.Caller(2) // Skip getCallerInfo and Printf/Debugf
if !ok {
log.Printf(format, args...)
return
return "unknown:unknown"
}
fn := runtime.FuncForPC(pc)
if fn == nil {
log.Printf(format, args...)
return
return "unknown:unknown"
}
funcName := filepath.Base(fn.Name())
fileName := filepath.Base(file)
prefix := fmt.Sprintf("%s:%s", fileName, funcName)
message := fmt.Sprintf(format, args...)
log.Printf("%s %s", prefix, message)
return fmt.Sprintf("%s:%s", fileName, funcName)
}
// Printf logs a message with caller information
// Printf logs a message with caller information in SYSLOG style
func Printf(format string, args ...interface{}) {
logf(format, args...)
caller := getCallerInfo()
message := fmt.Sprintf(format, args...)
syslogMessage := fmt.Sprintf("INFO %s %s", caller, message)
fmt.Println(syslogMessage)
}
// Debugf logs a debug message with caller information if global debug is enabled
func Debugf(format string, args ...interface{}) {
if config.Debug {
logf(format, args...)
caller := getCallerInfo()
message := fmt.Sprintf(format, args...)
syslogMessage := fmt.Sprintf("DEBUG %s %s", caller, message)
fmt.Println(syslogMessage)
}
}
// Sync flushes any buffered log entries (no-op for fmt.Println)
func Sync() {
// No buffering with fmt.Println, so this is a no-op
}

View File

@ -4,7 +4,7 @@ package logger
import (
"bytes"
"log"
"io"
"os"
"strings"
"testing"
@ -13,19 +13,33 @@ import (
)
func TestPrintf(t *testing.T) {
// Capture log output
var buf bytes.Buffer
log.SetOutput(&buf)
defer log.SetOutput(os.Stderr)
// Capture stdout
oldStdout := os.Stdout
r, w, _ := os.Pipe()
os.Stdout = w
Printf("test message: %s", "hello")
// Close writer and restore stdout
w.Close()
os.Stdout = oldStdout
// Read captured output
var buf bytes.Buffer
io.Copy(&buf, r)
output := buf.String()
if !strings.Contains(output, "logger_test.go:logger.TestPrintf") {
t.Errorf("Expected log output to contain caller info, got: %s", output)
// Check output format: "INFO file.go:function message"
if !strings.HasPrefix(output, "INFO ") {
t.Errorf("Expected output to start with 'INFO ', got: %s", output)
}
if !strings.Contains(output, "logger_test.go:logger.TestPrintf") {
t.Errorf("Expected output to contain caller info, got: %s", output)
}
if !strings.Contains(output, "test message: hello") {
t.Errorf("Expected log output to contain message, got: %s", output)
t.Errorf("Expected output to contain message, got: %s", output)
}
}
@ -37,16 +51,29 @@ func TestDebugfWithDebugEnabled(t *testing.T) {
// Enable debug
config.Debug = true
// Capture log output
var buf bytes.Buffer
log.SetOutput(&buf)
defer log.SetOutput(os.Stderr)
// Capture stdout
oldStdout := os.Stdout
r, w, _ := os.Pipe()
os.Stdout = w
Debugf("debug message: %s", "test")
// Close writer and restore stdout
w.Close()
os.Stdout = oldStdout
// Read captured output
var buf bytes.Buffer
io.Copy(&buf, r)
output := buf.String()
// Check output format: "DEBUG file.go:function message"
if !strings.HasPrefix(output, "DEBUG ") {
t.Errorf("Expected output to start with 'DEBUG ', got: %s", output)
}
if !strings.Contains(output, "debug message: test") {
t.Errorf("Expected debug message to be logged when debug is enabled, got: %s", output)
t.Errorf("Expected output to contain message, got: %s", output)
}
}
@ -58,15 +85,29 @@ func TestDebugfWithDebugDisabled(t *testing.T) {
// Disable debug
config.Debug = false
// Capture log output
var buf bytes.Buffer
log.SetOutput(&buf)
defer log.SetOutput(os.Stderr)
// Capture stdout
oldStdout := os.Stdout
r, w, _ := os.Pipe()
os.Stdout = w
Debugf("debug message: %s", "test")
// Close writer and restore stdout
w.Close()
os.Stdout = oldStdout
// Read captured output
var buf bytes.Buffer
io.Copy(&buf, r)
output := buf.String()
if strings.Contains(output, "debug message: test") {
t.Errorf("Expected debug message to NOT be logged when debug is disabled, got: %s", output)
// Should be empty when debug is disabled
if output != "" {
t.Errorf("Expected no output when debug is disabled, got: %s", output)
}
}
func TestSync(t *testing.T) {
// Test that Sync doesn't panic (it's a no-op now)
Sync()
}

16
main.go
View File

@ -5,10 +5,14 @@ package main
import (
"flag"
"log"
"os"
"os/signal"
"syscall"
"govpp-snmp-agentx/agentx"
"govpp-snmp-agentx/config"
"govpp-snmp-agentx/ifmib"
"govpp-snmp-agentx/logger"
"govpp-snmp-agentx/vppstats"
)
@ -38,6 +42,14 @@ func main() {
// Start VPP stats routine with callback to update MIB
vppstats.StartStatsRoutine(interfaceMIB.UpdateStats)
// Keep the main routine running
select {}
// Set up signal handling for graceful shutdown
sigChan := make(chan os.Signal, 1)
signal.Notify(sigChan, syscall.SIGINT, syscall.SIGTERM)
// Wait for shutdown signal
<-sigChan
logger.Printf("Shutting down...")
// Flush any buffered log entries
logger.Sync()
}