diff --git a/log/benchmark_test.go b/log/benchmark_test.go new file mode 100644 index 0000000..7f60c24 --- /dev/null +++ b/log/benchmark_test.go @@ -0,0 +1,389 @@ +package log + +import ( + "testing" +) + +// drainClient continuously reads from a client to prevent blocking. +// Returns a function to stop draining and wait for completion. +func drainClient(c *Client) func() { + done := make(chan struct{}) + go func() { + for { + select { + case <-done: + return + case <-c.writer: + // Drain entries + } + } + }() + return func() { close(done) } +} + +// ----------------------------------------------------------------------------- +// Serial Benchmarks - Single Log Levels +// ----------------------------------------------------------------------------- + +func BenchmarkTrace(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LTrace) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + Trace("benchmark message") + } +} + +func BenchmarkDebug(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LDebug) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + Debug("benchmark message") + } +} + +func BenchmarkInfo(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LInfo) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + Info("benchmark message") + } +} + +func BenchmarkNotice(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LNotice) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + Notice("benchmark message") + } +} + +func BenchmarkWarn(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LWarn) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + Warn("benchmark message") + } +} + +func BenchmarkError(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LError) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + Error("benchmark message") + } +} + +// ----------------------------------------------------------------------------- +// Formatted Logging Benchmarks +// ----------------------------------------------------------------------------- + +func BenchmarkDebugf(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LDebug) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + Debugf("benchmark message %d with %s", i, "formatting") + } +} + +func BenchmarkInfof(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LInfo) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + Infof("benchmark message %d with %s", i, "formatting") + } +} + +func BenchmarkErrorf(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LError) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + Errorf("benchmark message %d with %s", i, "formatting") + } +} + +// ----------------------------------------------------------------------------- +// Parallel Benchmarks +// ----------------------------------------------------------------------------- + +func BenchmarkDebugParallel(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LDebug) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + b.RunParallel(func(pb *testing.PB) { + for pb.Next() { + Debug("parallel benchmark message") + } + }) +} + +func BenchmarkInfoParallel(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LInfo) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + b.RunParallel(func(pb *testing.PB) { + for pb.Next() { + Info("parallel benchmark message") + } + }) +} + +func BenchmarkInfofParallel(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LInfo) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + b.RunParallel(func(pb *testing.PB) { + counter := 0 + for pb.Next() { + Infof("parallel benchmark message %d", counter) + counter++ + } + }) +} + +// ----------------------------------------------------------------------------- +// Logger Instance Benchmarks (Namespaced Logging) +// ----------------------------------------------------------------------------- + +func BenchmarkLoggerInfo(b *testing.B) { + logger := NewLogger("benchmark") + c := CreateClient("benchmark") + c.SetLogLevel(LInfo) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + logger.Info("benchmark message") + } +} + +func BenchmarkLoggerInfof(b *testing.B) { + logger := NewLogger("benchmark") + c := CreateClient("benchmark") + c.SetLogLevel(LInfo) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + logger.Infof("benchmark message %d", i) + } +} + +func BenchmarkLoggerDebugParallel(b *testing.B) { + logger := NewLogger("benchmark") + c := CreateClient("benchmark") + c.SetLogLevel(LDebug) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + b.RunParallel(func(pb *testing.PB) { + for pb.Next() { + logger.Debug("parallel benchmark message") + } + }) +} + +// ----------------------------------------------------------------------------- +// Multiple Client Benchmarks +// ----------------------------------------------------------------------------- + +func BenchmarkMultipleClients(b *testing.B) { + const numClients = 5 + var clients []*Client + var stopFuncs []func() + + for i := 0; i < numClients; i++ { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LInfo) + stop := drainClient(c) + clients = append(clients, c) + stopFuncs = append(stopFuncs, stop) + } + + defer func() { + for i, c := range clients { + stopFuncs[i]() + c.Destroy() + } + }() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + Info("benchmark message to multiple clients") + } +} + +func BenchmarkMultipleNamespaces(b *testing.B) { + namespaces := []string{"auth", "db", "api", "cache", "queue"} + var loggers []*Logger + var clients []*Client + var stopFuncs []func() + + for _, ns := range namespaces { + loggers = append(loggers, NewLogger(ns)) + c := CreateClient(ns) + c.SetLogLevel(LInfo) + stop := drainClient(c) + clients = append(clients, c) + stopFuncs = append(stopFuncs, stop) + } + + defer func() { + for i, c := range clients { + stopFuncs[i]() + c.Destroy() + } + }() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + loggers[i%len(loggers)].Info("benchmark message") + } +} + +// ----------------------------------------------------------------------------- +// With Synchronous Client Consumption (Legacy Pattern) +// ----------------------------------------------------------------------------- + +// BenchmarkDebugWithSyncConsumer measures the overhead of synchronous consumption +// using the Get() method, processing one message at a time. +func BenchmarkDebugWithSyncConsumer(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LDebug) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + // This benchmark measures just the logging side with async draining. + // For sync consumption patterns, see the TestOrder test. + b.ResetTimer() + for i := 0; i < b.N; i++ { + Debug("benchmark message") + } +} + +// ----------------------------------------------------------------------------- +// Comparison Benchmarks (Different Message Sizes) +// ----------------------------------------------------------------------------- + +func BenchmarkInfoShortMessage(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LInfo) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + Info("ok") + } +} + +func BenchmarkInfoMediumMessage(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LInfo) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + msg := "This is a medium-length log message for benchmarking purposes" + b.ResetTimer() + for i := 0; i < b.N; i++ { + Info(msg) + } +} + +func BenchmarkInfoLongMessage(b *testing.B) { + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LInfo) + stop := drainClient(c) + defer stop() + defer c.Destroy() + + msg := "This is a much longer log message that simulates real-world logging scenarios where developers tend to include more context about what the application is doing, including variable values, request IDs, and other debugging information that can be quite verbose" + b.ResetTimer() + for i := 0; i < b.N; i++ { + Info(msg) + } +} + +// ----------------------------------------------------------------------------- +// Overhead Benchmarks (Level Filtering) +// ----------------------------------------------------------------------------- + +func BenchmarkDebugFilteredByLevel(b *testing.B) { + // No client with Debug level, so Debug logs won't be consumed + // This measures the overhead of creating log entries that get filtered + c := CreateClient(DefaultNamespace) + c.SetLogLevel(LError) // Only Error and above + stop := drainClient(c) + defer stop() + defer c.Destroy() + + b.ResetTimer() + for i := 0; i < b.N; i++ { + Debug("this message will be filtered") + } +} diff --git a/log/log.go b/log/log.go index a204501..87a356d 100644 --- a/log/log.go +++ b/log/log.go @@ -99,7 +99,7 @@ func createLog(e Entry) { namespacesMux.Lock() namespaces[e.Namespace] = true namespacesMux.Unlock() - + sliceTex.Lock() for _, c := range clients { func(c *Client, e Entry) { @@ -126,7 +126,7 @@ func createLog(e Entry) { func GetNamespaces() []string { namespacesMux.RLock() defer namespacesMux.RUnlock() - + result := make([]string, 0, len(namespaces)) for ns := range namespaces { result = append(result, ns) diff --git a/log/log_test.go b/log/log_test.go index c6d26ec..fba494b 100644 --- a/log/log_test.go +++ b/log/log_test.go @@ -2,7 +2,6 @@ package log import ( "strconv" - "sync" "testing" ) @@ -37,21 +36,6 @@ func TestSetLogLevel(t *testing.T) { c.Destroy() } -func BenchmarkDebugSerial(b *testing.B) { - c := CreateClient("test") - var x sync.WaitGroup - x.Add(b.N) - for i := 0; i < b.N; i++ { - Debug(i) - go func() { - c.Get() - x.Done() - }() - } - x.Wait() - c.Destroy() -} - // Trace ensure logs come out in the right order func TestOrder(t *testing.T) { testString := "Testing trace: " diff --git a/main.go b/main.go index 954285d..f1c2d77 100644 --- a/main.go +++ b/main.go @@ -17,21 +17,21 @@ func generateLogs() { apiLogger := logger.NewLogger("api") dbLogger := logger.NewLogger("database") authLogger := logger.NewLogger("auth") - + for { logger.Info("This is a default namespace log!") apiLogger.Info("API request received") apiLogger.Debug("Processing API call") - + dbLogger.Info("Database query executed") dbLogger.Warn("Slow query detected") - + authLogger.Info("User authentication successful") authLogger.Error("Failed login attempt detected") - + logger.Trace("This is a trace log in default namespace!") logger.Warn("This is a warning in default namespace!") - + time.Sleep(2 * time.Second) } } diff --git a/ws/server.go b/ws/server.go index e7e3a24..4c7027f 100644 --- a/ws/server.go +++ b/ws/server.go @@ -23,7 +23,7 @@ func LogSocketHandler(w http.ResponseWriter, r *http.Request) { if namespacesParam != "" { namespaces = strings.Split(namespacesParam, ",") } - + c, err := upgrader.Upgrade(w, r, nil) if err != nil { logger.Error("upgrade:", err)