strc: add ability to override time in Span.Event and Span.End

.golangci.yml

@@ -0,0 +1,15 @@
+version: "2"
+
+linters:
+  settings:
+    errcheck:
+      exclude-functions:
+        - (io.Reader).Read
+        - (io.Writer).Write
+        - (io.Closer).Close
+        - (io.ReadCloser).Close
+        - (io.WriteCloser).Close
+        - (bytes.Buffer).ReadFrom
+        - (bytes.Buffer).WriteTo
+        - (net/http.ResponseWriter).Write
+        - fmt.Fprintf

internal/example_splunk/main.go

@@ -12,6 +12,7 @@ import (
 	"github.com/osbuild/logging/pkg/splunk"
 )
 
+//nolint:errcheck
 func main() {
 	srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		buf := new(bytes.Buffer)

internal/example_web/main.go

@@ -31,6 +31,7 @@ var pairs = []strc.HeaderField{
 	{HeaderName: "X-Request-Id", FieldName: "request_id"},
 }
 
+//nolint:errcheck
 func startServers(logger *slog.Logger) (*echo.Echo, *echo.Echo) {
 	tracerMW := strc.EchoTraceExtractor()
 	loggerMW := strc.EchoRequestLogger(logger, strc.MiddlewareConfig{})
@@ -86,6 +87,7 @@ func startServers(logger *slog.Logger) (*echo.Echo, *echo.Echo) {
 	return s1, s2
 }
 
+//nolint:errcheck
 func request(req *http.Request, handler slog.Handler) {
 	logger := slog.New(strc.NewMultiHandlerCustom(nil, strc.HeadersCallback(pairs), handler))
 	slog.SetDefault(logger)

pkg/sinit/flush_test.go

@@ -6,6 +6,7 @@ import (
 	"time"
 )
 
+//nolint:errcheck
 func TestValidationSplunkFlushRacy(t *testing.T) {
 	ctx := context.Background()
 	cfg := LoggingConfig{

pkg/sinit/init_test.go

@@ -112,7 +112,10 @@ func TestValidationSplunkWithHostname(t *testing.T) {
 	}()
 
 	slog.Warn("foo")
-	Flush()
+	err = Flush()
+	if err != nil {
+		t.Fatalf("expected no error on flush, got %v", err)
+	}
 
 	select {
 	case splunkBody := <-ch:
@@ -156,7 +159,10 @@ func TestValidationSplunkWithoutHostname(t *testing.T) {
 	}()
 
 	slog.Warn("foo")
-	Flush()
+	err = Flush()
+	if err != nil {
+		t.Fatalf("expected no error on flush, got %v", err)
+	}
 
 	select {
 	case splunkBody := <-ch:

pkg/splunk/client.go

@@ -73,7 +73,7 @@ type Stats struct {
 	LastRequestDuration time.Duration
 }
 
-func newSplunkLogger(ctx context.Context, url, token, source, hostname string, maximumSize int) *splunkLogger {
+func newSplunkLogger(ctx context.Context, url, token, source, hostname string, maximumSize int, sendFrequency time.Duration) *splunkLogger {
 	rcl := retryablehttp.NewClient()
 
 	sl := &splunkLogger{
@@ -84,7 +84,7 @@ func newSplunkLogger(ctx context.Context, url, token, source, hostname string, m
 		hostname:            hostname,
 		payloadsChannelSize: DefaultPayloadsChannelSize,
 		maximumSize:         DefaultMaximumSize,
-		sendFrequency:       DefaultSendFrequency,
+		sendFrequency:       sendFrequency,
 		pool: sync.Pool{
 			New: func() any {
 				buf := &bytes.Buffer{}

pkg/splunk/client_test.go

@@ -6,14 +6,15 @@ import (
 	"net/http"
 	"net/http/httptest"
 	"reflect"
-	"sync"
 	"sync/atomic"
 	"testing"
 	"time"
 
 	"github.com/stretchr/testify/assert"
 )
 
+const testSendFrequency = 100 * time.Millisecond
+
 func decodeBody(t *testing.T, r *http.Request) map[string]any {
 	m := map[string]any{}
 	err := json.NewDecoder(r.Body).Decode(&m)
@@ -25,17 +26,19 @@ func decodeBody(t *testing.T, r *http.Request) map[string]any {
 }
 
 func TestSplunkLoggerRetry(t *testing.T) {
-	var internalErrorOnce sync.Once
+	var counter atomic.Int32
 	ch := make(chan bool)
 	time.AfterFunc(time.Second*8, func() {
 		ch <- false
 	})
 
 	srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
-		internalErrorOnce.Do(func() {
-			// make sure the logger retries requests
+		if counter.Load() == 0 {
+			// make sure the logger retries the request
+			counter.Add(1)
 			w.WriteHeader(http.StatusInternalServerError)
-		})
+			return
+		}
 		if r.Header.Get("Authorization") != "Splunk token" {
 			t.Errorf("got %v, want Splunk token", r.Header.Get("Authorization"))
 		}
@@ -59,12 +62,17 @@ func TestSplunkLoggerRetry(t *testing.T) {
 	}))
 	defer srv.Close()
 
-	sl := newSplunkLogger(context.Background(), srv.URL, "token", "source", "hostname", 0)
+	sl := newSplunkLogger(context.Background(), srv.URL, "token", "source", "hostname", 0, testSendFrequency)
 	_, err := sl.event([]byte("{}\n"))
 	if err != nil {
 		t.Error(err)
 	}
-	sl.close(100 * time.Millisecond)
+	defer func() {
+		err := sl.close(100 * time.Millisecond)
+		if err != nil {
+			t.Error(err)
+		}
+	}()
 
 	if !<-ch {
 		t.Error("timeout")
@@ -103,12 +111,17 @@ func TestSplunkLoggerContext(t *testing.T) {
 
 	ctx, cancel := context.WithTimeout(context.Background(), time.Second*1)
 	defer cancel()
-	sl := newSplunkLogger(ctx, srv.URL, "token", "source", "hostname", 0)
+	sl := newSplunkLogger(ctx, srv.URL, "token", "source", "hostname", 0, testSendFrequency)
 	_, err := sl.event([]byte("{}\n"))
 	if err != nil {
 		t.Error(err)
 	}
-	sl.close(100 * time.Millisecond)
+	defer func() {
+		err := sl.close(100 * time.Millisecond)
+		if err != nil {
+			t.Error(err)
+		}
+	}()
 
 	if !<-ch {
 		t.Error("timeout")
@@ -126,8 +139,13 @@ func TestSplunkLoggerPayloads(t *testing.T) {
 		{
 			name: "empty",
 			f: func() error {
-				sl := newSplunkLogger(context.Background(), url, "token", "source", "hostname", 0)
-				defer sl.close(100 * time.Millisecond)
+				sl := newSplunkLogger(context.Background(), url, "token", "source", "hostname", 0, testSendFrequency)
+				defer func() {
+					err := sl.close(100 * time.Millisecond)
+					if err != nil {
+						t.Error(err)
+					}
+				}()
 				_, err := sl.event([]byte("{}\n"))
 				if err != nil {
 					return err
@@ -147,8 +165,13 @@ func TestSplunkLoggerPayloads(t *testing.T) {
 		{
 			name: "json",
 			f: func() error {
-				sl := newSplunkLogger(context.Background(), url, "token", "source", "hostname", 0)
-				defer sl.close(100 * time.Millisecond)
+				sl := newSplunkLogger(context.Background(), url, "token", "source", "hostname", 0, testSendFrequency)
+				defer func() {
+					err := sl.close(100 * time.Millisecond)
+					if err != nil {
+						t.Error(err)
+					}
+				}()
 				_, err := sl.event([]byte(`{"a": "b"}` + "\n"))
 				if err != nil {
 					return err
@@ -212,7 +235,7 @@ func TestSplunkLoggerCloseTimeout(t *testing.T) {
 	ctx, cancel := context.WithTimeout(context.Background(), time.Second*1)
 	defer cancel()
 
-	sl := newSplunkLogger(ctx, srv.URL, "token", "source", "hostname", 0)
+	sl := newSplunkLogger(ctx, srv.URL, "token", "source", "hostname", 0, testSendFrequency)
 	_, err := sl.event([]byte("{}\n"))
 	if err != nil {
 		t.Error(err)

pkg/splunk/handler.go

@@ -59,7 +59,7 @@ type SplunkConfig struct {
 func NewSplunkHandler(ctx context.Context, config SplunkConfig) *SplunkHandler {
 	h := &SplunkHandler{
 		level:  config.Level,
-		splunk: newSplunkLogger(ctx, config.URL, config.Token, config.Source, config.Hostname, config.DefaultMaximumSize),
+		splunk: newSplunkLogger(ctx, config.URL, config.Token, config.Source, config.Hostname, config.DefaultMaximumSize, DefaultSendFrequency),
 	}
 
 	h.jh = slog.NewJSONHandler(h, &slog.HandlerOptions{Level: config.Level, AddSource: true, ReplaceAttr: replaceAttr})
@@ -77,8 +77,8 @@ func (h *SplunkHandler) Flush() {
 // logs after closing the handler will return ErrFullOrClosed. The call can
 // block but not longer than 2 seconds. Use CloseWithTimeout to specify a custom
 // timeout.
-func (h *SplunkHandler) Close() {
-	h.splunk.close(2 * time.Second)
+func (h *SplunkHandler) Close() error {
+	return h.splunk.close(2 * time.Second)
 }
 
 // CloseWithTimeout flushes all pending payloads and closes the Splunk client.

pkg/splunk/handler_test.go

@@ -18,7 +18,7 @@ func TestSplunkHandler(t *testing.T) {
 	emptyLines := 0
 	srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		buf := new(bytes.Buffer)
-		buf.ReadFrom(r.Body)
+		_, _ = buf.ReadFrom(r.Body)
 
 		lines := strings.Split(buf.String(), "\n")
 		for _, line := range lines {
@@ -96,7 +96,10 @@ func TestSplunkHandler(t *testing.T) {
 			h := NewSplunkHandler(context.Background(), c)
 			logger := slog.New(h)
 			tt.f(logger)
-			h.Close()
+			err := h.Close()
+			if err != nil {
+				t.Error(err)
+			}
 			stats := h.Statistics()
 
 			if int(stats.EventCount) != tt.events {
@@ -118,7 +121,7 @@ func TestSplunkHandler(t *testing.T) {
 func TestSplunkHandlerBatching(t *testing.T) {
 	srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		buf := new(bytes.Buffer)
-		buf.ReadFrom(r.Body)
+		buf.ReadFrom(r.Body) //nolint:errcheck
 
 		lines := strings.Split(buf.String(), "\n")
 		for _, line := range lines {
@@ -145,7 +148,10 @@ func TestSplunkHandlerBatching(t *testing.T) {
 	for i := 0; i < 4000; i++ {
 		logger.Debug("msg", "i", i)
 	}
-	h.Close()
+	err := h.Close()
+	if err != nil {
+		t.Error(err)
+	}
 	stats := h.Statistics()
 
 	t.Logf("events: %d, batches: %d", stats.EventCount, stats.BatchCount)

pkg/strc/README.md

@@ -42,6 +42,16 @@ Spans end up in log sink too, for better readability, the following fields are a
 * `trace_id` - trace ID (disable by setting `strc.TraceIDFieldKey` to empty string)
 * `build_id` - build Git sha (disable by setting `strc.BuildIDFieldKey` to empty string)
 
+### Overriding time
+
+Span start, event and end time is automatically taken via `time.Now()` call but there are some use cases when this needs to be overridden to a specific time. Use special attributes to do that:
+
+```go
+span := strc.Start(ctx, "span name", "started", time.Now())
+span.Event("an event", "at", time.Now())
+span.End("finished", time.Now())
+```
+
 ### Propagation
 
 A simple HTTP header-based propagation API is available. Note this is not meant to be used directly, there is HTTP middleware and client wrapper available:

pkg/strc/context_test.go

@@ -11,7 +11,7 @@ import (
 func TestTraceID(t *testing.T) {
 	src = rand.NewSource(0)
 	var tid TraceID
-	var r *http.Request = &http.Request{
+	r := &http.Request{
 		Header: http.Header{},
 	}
 
@@ -62,7 +62,7 @@ func TestTraceID(t *testing.T) {
 func TestSpanID(t *testing.T) {
 	src = rand.NewSource(0)
 	var sid SpanID
-	var r *http.Request = &http.Request{
+	r := &http.Request{
 		Header: http.Header{},
 	}