Skip to content

Commit 116f672

Browse files
authored
fix(telemetry): Make sure log tags are propagated correctly (#4324)
Co-authored-by: kemal.akkoyun <[email protected]>
1 parent d3f3d23 commit 116f672

File tree

4 files changed

+190
-9
lines changed

4 files changed

+190
-9
lines changed

internal/appsec/appsec.go

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -121,7 +121,8 @@ func Start(opts ...config.StartOption) {
121121
func logUnexpectedStartError(err error) {
122122
log.Error("appsec: could not start because of an unexpected error: %s\nNo security activities will be collected. Please contact support at https://docs.datadoghq.com/help/ for help.", err.Error())
123123

124-
telemetrylog.Error("appsec: could not start because of an unexpected error", slog.Any("error", telemetrylog.NewSafeError(err)))
124+
logger := telemetrylog.With(telemetry.WithTags([]string{"product:appsec"}))
125+
logger.Error("appsec: could not start because of an unexpected error", slog.Any("error", telemetrylog.NewSafeError(err)))
125126
telemetry.ProductStartError(telemetry.NamespaceAppSec, err)
126127
}
127128

internal/appsec/telemetry.go

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -77,15 +77,15 @@ func detectLibDL() {
7777
return
7878
}
7979

80+
logger := telemetrylog.With(telemetry.WithTags([]string{"product:appsec"}))
8081
for _, method := range detectLibDLMethods {
8182
if ok, err := method.method(); ok {
82-
logger := telemetrylog.With(telemetry.WithTags([]string{"method:" + method.name}))
8383
logger.Debug("libdl detected using method", slog.String("method", method.name))
84-
log.Debug("libdl detected using method: %s", method.name)
84+
log.Debug("appsec: libdl detected using method: %s", method.name)
8585
telemetry.RegisterAppConfig("libdl_present", true, telemetry.OriginCode)
8686
return
8787
} else if err != nil {
88-
log.Debug("failed to detect libdl with method %s: %v", method.name, err.Error())
88+
log.Debug("appsec: failed to detect libdl with method %s: %v", method.name, err.Error())
8989
}
9090
}
9191

internal/telemetry/backend_test.go

Lines changed: 141 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -222,9 +222,8 @@ func TestLoggerBackend_StackTrace(t *testing.T) {
222222
}
223223

224224
func TestLoggerBackend_Tags(t *testing.T) {
225-
backend := newLoggerBackend(10)
226-
227225
t.Run("includes tags in log entry", func(t *testing.T) {
226+
backend := newLoggerBackend(10)
228227
record := NewRecord(LogDebug, "tagged message")
229228
backend.Add(record, WithTags([]string{"service:api", "version:1.2.3"}))
230229

@@ -236,4 +235,144 @@ func TestLoggerBackend_Tags(t *testing.T) {
236235

237236
assert.Equal(t, "service:api,version:1.2.3", logs.Logs[0].Tags)
238237
})
238+
239+
t.Run("same message with different tags are separate entries", func(t *testing.T) {
240+
backend := newLoggerBackend(10)
241+
record1 := NewRecord(LogDebug, "shared message")
242+
record2 := NewRecord(LogDebug, "shared message")
243+
244+
backend.Add(record1, WithTags([]string{"env:prod"}))
245+
backend.Add(record2, WithTags([]string{"env:staging"}))
246+
247+
payload := backend.Payload()
248+
require.NotNil(t, payload)
249+
250+
logs := payload.(transport.Logs)
251+
require.Len(t, logs.Logs, 2, "Should have two separate log entries for different tags")
252+
253+
// Extract tags for comparison
254+
tagSet := make(map[string]bool)
255+
for _, log := range logs.Logs {
256+
tagSet[log.Tags] = true
257+
assert.Equal(t, "shared message", log.Message)
258+
assert.Equal(t, uint32(1), log.Count)
259+
}
260+
assert.True(t, tagSet["env:prod"], "Should contain env:prod tag")
261+
assert.True(t, tagSet["env:staging"], "Should contain env:staging tag")
262+
})
263+
264+
t.Run("same message and tags increments count", func(t *testing.T) {
265+
backend := newLoggerBackend(10)
266+
tags := []string{"service:api", "version:1.0"}
267+
268+
backend.Add(NewRecord(LogWarn, "repeated message"), WithTags(tags))
269+
backend.Add(NewRecord(LogWarn, "repeated message"), WithTags(tags))
270+
backend.Add(NewRecord(LogWarn, "repeated message"), WithTags(tags))
271+
272+
payload := backend.Payload()
273+
require.NotNil(t, payload)
274+
275+
logs := payload.(transport.Logs)
276+
require.Len(t, logs.Logs, 1, "Should deduplicate logs with same message and tags")
277+
278+
assert.Equal(t, "repeated message", logs.Logs[0].Message)
279+
assert.Equal(t, "service:api,version:1.0", logs.Logs[0].Tags)
280+
assert.Equal(t, uint32(3), logs.Logs[0].Count)
281+
})
282+
283+
t.Run("empty tags slice results in empty tags string", func(t *testing.T) {
284+
backend := newLoggerBackend(10)
285+
record := NewRecord(LogDebug, "no tags message")
286+
backend.Add(record, WithTags([]string{}))
287+
288+
payload := backend.Payload()
289+
require.NotNil(t, payload)
290+
291+
logs := payload.(transport.Logs)
292+
require.Len(t, logs.Logs, 1)
293+
294+
assert.Equal(t, "", logs.Logs[0].Tags)
295+
})
296+
297+
t.Run("message without tags has empty tags field", func(t *testing.T) {
298+
backend := newLoggerBackend(10)
299+
record := NewRecord(LogDebug, "plain message")
300+
backend.Add(record) // No WithTags option
301+
302+
payload := backend.Payload()
303+
require.NotNil(t, payload)
304+
305+
logs := payload.(transport.Logs)
306+
require.Len(t, logs.Logs, 1)
307+
308+
assert.Equal(t, "", logs.Logs[0].Tags)
309+
})
310+
311+
t.Run("single tag is serialized correctly", func(t *testing.T) {
312+
backend := newLoggerBackend(10)
313+
record := NewRecord(LogDebug, "single tag message")
314+
backend.Add(record, WithTags([]string{"env:production"}))
315+
316+
payload := backend.Payload()
317+
require.NotNil(t, payload)
318+
319+
logs := payload.(transport.Logs)
320+
require.Len(t, logs.Logs, 1)
321+
322+
assert.Equal(t, "env:production", logs.Logs[0].Tags)
323+
})
324+
325+
t.Run("multiple WithTags options appends tags", func(t *testing.T) {
326+
backend := newLoggerBackend(10)
327+
record := NewRecord(LogDebug, "multi tags message")
328+
backend.Add(record,
329+
WithTags([]string{"product:appsec"}),
330+
WithTags([]string{"version:1.0", "env:prod"}),
331+
)
332+
333+
payload := backend.Payload()
334+
require.NotNil(t, payload)
335+
336+
logs := payload.(transport.Logs)
337+
require.Len(t, logs.Logs, 1)
338+
339+
// All tags from both WithTags calls should be present
340+
assert.Equal(t, "product:appsec,version:1.0,env:prod", logs.Logs[0].Tags)
341+
})
342+
343+
t.Run("multiple WithTags options deduplicates tags", func(t *testing.T) {
344+
backend := newLoggerBackend(10)
345+
record := NewRecord(LogDebug, "dedup tags message")
346+
backend.Add(record,
347+
WithTags([]string{"product:appsec", "env:prod"}),
348+
WithTags([]string{"version:1.0", "product:appsec"}), // product:appsec is duplicated
349+
)
350+
351+
payload := backend.Payload()
352+
require.NotNil(t, payload)
353+
354+
logs := payload.(transport.Logs)
355+
require.Len(t, logs.Logs, 1)
356+
357+
// Tags should be deduplicated - product:appsec should appear only once
358+
assert.Equal(t, "product:appsec,env:prod,version:1.0", logs.Logs[0].Tags)
359+
})
360+
361+
t.Run("WithTags with empty slice after non-empty preserves original tags", func(t *testing.T) {
362+
backend := newLoggerBackend(10)
363+
record := NewRecord(LogDebug, "preserve tags message")
364+
backend.Add(record,
365+
WithTags([]string{"product:appsec"}),
366+
WithTags([]string{}),
367+
)
368+
369+
payload := backend.Payload()
370+
require.NotNil(t, payload)
371+
372+
logs := payload.(transport.Logs)
373+
require.Len(t, logs.Logs, 1)
374+
375+
// Original tags should be preserved even when empty WithTags is added
376+
assert.Equal(t, "product:appsec", logs.Logs[0].Tags)
377+
})
239378
}

internal/telemetry/options.go

Lines changed: 44 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -9,15 +9,56 @@ import (
99
"strings"
1010
)
1111

12-
// WithTags returns a LogOption that sets the tags for the telemetry log message. Tags are key-value pairs that are then
12+
// WithTags returns a LogOption that appends the tags for the telemetry log message. Tags are key-value pairs that are then
1313
// serialized into a simple "key:value,key2:value2" format. No quoting or escaping is performed.
14+
// Multiple calls to WithTags will append tags without duplications, preserving the order of first occurrence.
1415
func WithTags(tags []string) LogOption {
15-
compiledTags := strings.Join(tags, ",")
16+
if len(tags) == 0 {
17+
return func(*loggerKey, *loggerValue) {}
18+
}
19+
20+
// Pre-compute joined string to minimize closure size (string vs slice header)
21+
// and avoid repeated joins in the common fast-path case
22+
compiled := strings.Join(tags, ",")
23+
1624
return func(key *loggerKey, _ *loggerValue) {
1725
if key == nil {
1826
return
1927
}
20-
key.tags = compiledTags
28+
29+
if key.tags == "" {
30+
// Fast path: no existing tags, just assign
31+
key.tags = compiled
32+
return
33+
}
34+
35+
// Slow path: merge and deduplicate
36+
seen := make(map[string]struct{})
37+
38+
var builder strings.Builder
39+
builder.Grow(len(key.tags) + len(compiled) + 1)
40+
41+
// Add existing tags
42+
for tag := range strings.SplitSeq(key.tags, ",") {
43+
if builder.Len() > 0 {
44+
builder.WriteByte(',')
45+
}
46+
builder.WriteString(tag)
47+
seen[tag] = struct{}{}
48+
}
49+
50+
// Add new tags, skipping duplicates
51+
for tag := range strings.SplitSeq(compiled, ",") {
52+
if _, exists := seen[tag]; !exists {
53+
if builder.Len() > 0 {
54+
builder.WriteByte(',')
55+
}
56+
builder.WriteString(tag)
57+
seen[tag] = struct{}{}
58+
}
59+
}
60+
61+
key.tags = builder.String()
2162
}
2263
}
2364

0 commit comments

Comments
 (0)