Add userId to log events

otellog/event.go

@@ -11,6 +11,7 @@ type Event struct {
 	Severity   Severity    `json:"sev,omitempty"`   // Numerical value of the severity cf. Severity constants like SeverityInfo for possible values and their semantics
 	Name       string      `json:"name,omitempty"`  // Short event identifier that does not contain varying parts. Name describes what happened (e.g. "ProcessStarted"). Recommended to be no longer than 50 characters. Not guaranteed to be unique in any way. Typically used for filtering and grouping purposes in backends. Can be used to identify domain events like FeaturesRequested or UserLoggedIn (cf. example).
 	Body       interface{} `json:"body,omitempty"`  // A value containing the body of the log record. Can be for example a human-readable string message (including multi-line) describing the event in a free form or it can be a structured data composed of arrays and maps of other values. Can vary for each occurrence of the event coming from the same source.
+	UserIdHash string      `json:"uid,omitempty"`   // The userId of the user causing this event. Must be the sha256 hash of the userId from the current identity provider for pseudonymization
 	TenantId   string      `json:"tn,omitempty"`    // ID of the tenant to which this event belongs.
 	TraceId    string      `json:"trace,omitempty"` // Request trace-id as defined in W3C Trace Context (https://www.w3.org/TR/trace-context/#trace-id) specification. That is the ID of the whole trace forest used to uniquely identify a distributed trace through a system.
 	SpanId     string      `json:"span,omitempty"`  // span-id. Can be set for logs that are part of a particular processing span. A span (https://opentracing.io/docs/overview/spans/) is the primary building block of a distributed trace, representing an individual unit of work done in a distributed system.

otellog/option.go

@@ -2,6 +2,8 @@ package otellog
 
 import (
 	"context"
+	"crypto/sha256"
+	"encoding/hex"
 	"fmt"
 	"net/http"
 	"strings"
@@ -131,6 +133,19 @@ func (ob *LogBuilder) WithDB(db DB) *LogBuilder {
 	return ob
 }
 
+func (ob *LogBuilder) WithUserId(userId string) *LogBuilder {
+	ob.options = append(ob.options, func(e *Event) {
+		if userId != "" {
+			hash := sha256.New()
+			hash.Write([]byte(userId))
+			sum := hash.Sum(nil)
+			uidHash := hex.EncodeToString(sum)
+			e.UserIdHash = uidHash
+		}
+	})
+	return ob
+}
+
 // WithException adds the exception attribute to the log event.
 func (ob *LogBuilder) WithException(err Exception) *LogBuilder {
 	ob.options = append(ob.options, func(e *Event) {
@@ -212,6 +227,13 @@ func WithDB(db DB) *LogBuilder {
 	return ob
 }
 
+// WithUserId hashes the userId and adds the uid attribute to the log event.
+func WithUserId(userId string) *LogBuilder {
+	ob := &LogBuilder{}
+	ob.WithUserId(userId)
+	return ob
+}
+
 // WithException adds the exception attribute to the log event.
 func WithException(err Exception) *LogBuilder {
 	ob := &LogBuilder{}

otellog/option_test.go

@@ -44,12 +44,12 @@ func TestLogMessageWithVisibilityIsFalse_Error_AddVisPropertyAndWritesJSONToBuff
 func TestLogMessageWithVisibilityIsFalseAndStructAsBody_Debug_WritesJSONToBuffer(t *testing.T) {
 	rec := initializeLogger(t)
 	body := &struct {
-		Id string `json:"id,omitempty"`
-		Toggle bool `json:"toggle,omitempty"`
-		Counter int `json:"counter,omitempty"`
+		Id      string `json:"id,omitempty"`
+		Toggle  bool   `json:"toggle,omitempty"`
+		Counter int    `json:"counter,omitempty"`
 	}{
-		Id: "id",
-		Toggle: true,
+		Id:      "id",
+		Toggle:  true,
 		Counter: 5,
 	}
 
@@ -61,12 +61,12 @@ func TestLogMessageWithVisibilityIsFalseAndStructAsBody_Debug_WritesJSONToBuffer
 func TestLogMessageWithVisibilityIsFalseAndStructAsBody_Info_WritesJSONToBuffer(t *testing.T) {
 	rec := initializeLogger(t)
 	body := &struct {
-		Id string `json:"id,omitempty"`
-		Toggle bool `json:"toggle,omitempty"`
-		Counter int `json:"counter,omitempty"`
+		Id      string `json:"id,omitempty"`
+		Toggle  bool   `json:"toggle,omitempty"`
+		Counter int    `json:"counter,omitempty"`
 	}{
-		Id: "id",
-		Toggle: true,
+		Id:      "id",
+		Toggle:  true,
 		Counter: 5,
 	}
 
@@ -78,12 +78,12 @@ func TestLogMessageWithVisibilityIsFalseAndStructAsBody_Info_WritesJSONToBuffer(
 func TestLogMessageWithVisibilityIsFalseAndStructAsBody_Error_WritesJSONToBuffer(t *testing.T) {
 	rec := initializeLogger(t)
 	body := &struct {
-		Id string `json:"id,omitempty"`
-		Toggle bool `json:"toggle,omitempty"`
-		Counter int `json:"counter,omitempty"`
+		Id      string `json:"id,omitempty"`
+		Toggle  bool   `json:"toggle,omitempty"`
+		Counter int    `json:"counter,omitempty"`
 	}{
-		Id: "id",
-		Toggle: true,
+		Id:      "id",
+		Toggle:  true,
 		Counter: 5,
 	}
 
@@ -225,6 +225,14 @@ func TestLogMessageWithDB_Info_AddDBPropertyAndWritesJSONToBuffer(t *testing.T)
 	rec.OutputShouldBe("{\"time\":\"2022-01-01T01:02:03.000000004Z\",\"sev\":9,\"body\":\"Log message\",\"attr\":{\"db\":{\"name\":\"CustomDb\"}}}\n")
 }
 
+func TestLogMessageWithUserId_Info_AddsUserIdHashAndWritesJSONToBuffer(t *testing.T) {
+	rec := initializeLogger(t)
+
+	log.WithUserId("a63554a8-1234-5678-1199-37a3b7d24e82").Info(context.Background(), "Log message")
+
+	rec.OutputShouldBe("{\"time\":\"2022-01-01T01:02:03.000000004Z\",\"sev\":9,\"body\":\"Log message\",\"uid\":\"5219bb0e97ae8956431ca19e10105c0d82a0cf1386cec6e01a7eaeae04722ded\"}\n")
+}
+
 func TestLogMessageWithException_Info_AddExceptionPropertyAndWritesJSONToBuffer(t *testing.T) {
 	rec := initializeLogger(t)
 
@@ -287,11 +295,12 @@ func TestLogMessageWithEveryPossibleOption_Info_AddAllPropertiesAndWritesJSONToB
 		WithVisibility(false).
 		WithHttp(log.Http{Method: "Get"}).
 		WithDB(log.DB{Name: "CustomDb"}).
+		WithUserId("a63554a8-1234-5678-1199-37a3b7d24e82").
 		WithException(log.Exception{Type: "CustomLogException"}).
 		WithAdditionalAttributes(customAttr).
 		Info(context.Background(), "Log message")
 
-	rec.OutputShouldBe("{\"time\":\"2022-01-01T01:02:03.000000004Z\",\"sev\":9,\"name\":\"Log message name\",\"body\":\"Log message\",\"attr\":{\"a\":{\"one\":1,\"two\":2},\"b\":{\"one\":1,\"two\":2},\"c\":\"3\",\"db\":{\"name\":\"CustomDb\"},\"exception\":{\"type\":\"CustomLogException\"},\"http\":{\"method\":\"Get\"}},\"vis\":0}\n")
+	rec.OutputShouldBe("{\"time\":\"2022-01-01T01:02:03.000000004Z\",\"sev\":9,\"name\":\"Log message name\",\"body\":\"Log message\",\"uid\":\"5219bb0e97ae8956431ca19e10105c0d82a0cf1386cec6e01a7eaeae04722ded\",\"attr\":{\"a\":{\"one\":1,\"two\":2},\"b\":{\"one\":1,\"two\":2},\"c\":\"3\",\"db\":{\"name\":\"CustomDb\"},\"exception\":{\"type\":\"CustomLogException\"},\"http\":{\"method\":\"Get\"}},\"vis\":0}\n")
 }
 
 func TestLogMessageWithRegisteredHookAndOtherService_Info_OverrideServicePropertyAndWritesJSONToBuffer(t *testing.T) {

otellog/uidhook.go

@@ -0,0 +1,24 @@
+package otellog
+
+import (
+	"context"
+	"crypto/sha256"
+	"encoding/hex"
+)
+
+type UidFromContextFn func(ctx context.Context) (string, error)
+
+func AddUserIdToLogEvents(uidFn UidFromContextFn) Hook {
+
+	return func(ctx context.Context, e *Event) {
+		uid, _ := uidFn(ctx)
+		if uid != "" {
+			hash := sha256.New()
+			hash.Write([]byte(uid))
+			sum := hash.Sum(nil)
+			uidHash := hex.EncodeToString(sum)
+			e.UserIdHash = uidHash
+		}
+	}
+
+}

otellog/uidhook_test.go

@@ -0,0 +1,72 @@
+package otellog_test
+
+import (
+	"context"
+	"errors"
+	log "github.com/d-velop/dvelop-sdk-go/otellog"
+	"testing"
+)
+
+func TestAddUidToLogEvent_givenUidFnReturnsUid_whenLogWritten_thenAddsUidToLog(t *testing.T) {
+
+	uidFn := log.UidFromContextFn(func(ctx context.Context) (string, error) {
+		return "a63554a8-6044-417b-a0aa-37a3b7d24e82", nil
+	})
+
+	hook := log.AddUserIdToLogEvents(uidFn)
+
+	rec := initializeLogger(t)
+
+	log.RegisterHook(hook)
+	log.Info(context.Background(), "Testmessage")
+
+	rec.OutputShouldBe(`{"time":"2022-01-01T01:02:03.000000004Z","sev":9,"body":"Testmessage","uid":"89757a7742548835532f1809558e0ab24eb39057966ad1630f1c493d94c3aec1"}` + "\n")
+}
+
+func TestAddUidToLogEvent_givenUidExplicitlySet_whenLogWritten_thenHookDoesNotReplaceExplicitValue(t *testing.T) {
+
+	uidFn := log.UidFromContextFn(func(ctx context.Context) (string, error) {
+		return "a63554a8-6044-417b-a0aa-37a3b7d24e82", nil
+	})
+
+	hook := log.AddUserIdToLogEvents(uidFn)
+
+	rec := initializeLogger(t)
+
+	log.RegisterHook(hook)
+	log.WithUserId("a63554a8-aaaa-bbbbb-cccc-37a3b7d24e82").Info(context.Background(), "Testmessage")
+
+	rec.OutputShouldBe(`{"time":"2022-01-01T01:02:03.000000004Z","sev":9,"body":"Testmessage","uid":"b91aa04538b01137e2e4733f9591f901d0e29a7b48d671c33a8e38972f9ee7e3"}` + "\n")
+}
+
+func TestAddUidToLogEvent_givenUidFnReturnsEmptyUid_whenLogWritten_thenAddsNothingToLog(t *testing.T) {
+
+	uidFn := log.UidFromContextFn(func(ctx context.Context) (string, error) {
+		return "", nil
+	})
+
+	hook := log.AddUserIdToLogEvents(uidFn)
+
+	rec := initializeLogger(t)
+
+	log.RegisterHook(hook)
+	log.Info(context.Background(), "Testmessage")
+
+	rec.OutputShouldBe(`{"time":"2022-01-01T01:02:03.000000004Z","sev":9,"body":"Testmessage"}` + "\n")
+}
+
+func TestAddUidToLogEvent_givenUidFnReturnsError_whenLogWritten_thenAddsNothingToLog(t *testing.T) {
+
+	uidFn := log.UidFromContextFn(func(ctx context.Context) (string, error) {
+		return "", errors.New("some error")
+	})
+
+	hook := log.AddUserIdToLogEvents(uidFn)
+
+	rec := initializeLogger(t)
+
+	log.RegisterHook(hook)
+	log.Info(context.Background(), "Testmessage")
+
+	rec.OutputShouldBe(`{"time":"2022-01-01T01:02:03.000000004Z","sev":9,"body":"Testmessage"}` + "\n")
+}