Skip to content

Commit 361fd8e

Browse files
jrigueram1rpCemDK
committed
[receiver/cloudfoundryreceiver] Refactor logic and tests to set tracing attributes in RTR logs
Co-authored-by: Sam Clulow <[email protected]> Co-authored-by: Cem Deniz Kabakci <[email protected]>
1 parent 9e23312 commit 361fd8e

File tree

2 files changed

+154
-40
lines changed

2 files changed

+154
-40
lines changed

‎receiver/cloudfoundryreceiver/converter.go

+71-40
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
package cloudfoundryreceiver // import "github.com/open-telemetry/opentelemetry-collector-contrib/receiver/cloudfoundryreceiver"
55

66
import (
7+
"encoding/hex"
78
"fmt"
89
"strings"
910
"time"
@@ -13,15 +14,14 @@ import (
1314
"go.opentelemetry.io/collector/pdata/pcommon"
1415
"go.opentelemetry.io/collector/pdata/plog"
1516
"go.opentelemetry.io/collector/pdata/pmetric"
16-
"go.opentelemetry.io/otel/trace"
1717
)
1818

1919
const (
2020
attributeNamePrefix = "org.cloudfoundry."
2121
envelopeSourceTypeTag = "org.cloudfoundry.source_type"
2222
envelopeSourceTypeValueRTR = "RTR"
23-
logLineRTRTraceIDKey = "x_b3_traceid"
24-
logLineRTRSpanIDKey = "x_b3_spanid"
23+
logLineRTRZipkinKey = "b3"
24+
logLineRTRW3CKey = "traceparent"
2525
)
2626

2727
func convertEnvelopeToMetrics(envelope *loggregator_v2.Envelope, metricSlice pmetric.MetricSlice, startTime time.Time) {
@@ -50,55 +50,86 @@ func convertEnvelopeToMetrics(envelope *loggregator_v2.Envelope, metricSlice pme
5050
}
5151

5252
func convertEnvelopeToLogs(envelope *loggregator_v2.Envelope, logSlice plog.LogRecordSlice, startTime time.Time) error {
53-
if _, isLog := envelope.Message.(*loggregator_v2.Envelope_Log); isLog {
54-
log := logSlice.AppendEmpty()
55-
log.SetTimestamp(pcommon.Timestamp(envelope.GetTimestamp()))
56-
log.SetObservedTimestamp(pcommon.NewTimestampFromTime(startTime))
57-
log.Body().SetStr(string(envelope.GetLog().GetPayload()))
58-
switch envelope.GetLog().GetType() {
59-
case loggregator_v2.Log_OUT:
60-
log.SetSeverityText(plog.SeverityNumberInfo.String())
61-
log.SetSeverityNumber(plog.SeverityNumberInfo)
62-
case loggregator_v2.Log_ERR:
63-
log.SetSeverityText(plog.SeverityNumberError.String())
64-
log.SetSeverityNumber(plog.SeverityNumberError)
53+
log := logSlice.AppendEmpty()
54+
log.SetTimestamp(pcommon.Timestamp(envelope.GetTimestamp()))
55+
log.SetObservedTimestamp(pcommon.NewTimestampFromTime(startTime))
56+
logLine := string(envelope.GetLog().GetPayload())
57+
log.Body().SetStr(logLine)
58+
switch envelope.GetLog().GetType() {
59+
case loggregator_v2.Log_OUT:
60+
log.SetSeverityText(plog.SeverityNumberInfo.String())
61+
log.SetSeverityNumber(plog.SeverityNumberInfo)
62+
case loggregator_v2.Log_ERR:
63+
log.SetSeverityText(plog.SeverityNumberError.String())
64+
log.SetSeverityNumber(plog.SeverityNumberError)
65+
}
66+
copyEnvelopeAttributes(log.Attributes(), envelope)
67+
if envelope.SourceId == envelopeSourceTypeValueRTR {
68+
traceID, spanID, err := getTracingIDs(logLine)
69+
if err != nil {
70+
return err
6571
}
66-
copyEnvelopeAttributes(log.Attributes(), envelope)
67-
if value, found := log.Attributes().Get(envelopeSourceTypeTag); found && value.AsString() == envelopeSourceTypeValueRTR {
68-
_, wordsMap := parseLogLine(log.Body().AsString())
69-
traceIDStr, found := wordsMap[logLineRTRTraceIDKey]
70-
if !found {
71-
return fmt.Errorf("traceid key %s not found in log", logLineRTRTraceIDKey)
72-
}
73-
spanIDStr, found := wordsMap[logLineRTRSpanIDKey]
74-
if !found {
75-
return fmt.Errorf("spanid key %s not found in log", logLineRTRSpanIDKey)
76-
}
77-
traceID, err := trace.TraceIDFromHex(traceIDStr)
78-
if err != nil {
79-
return err
80-
}
81-
spanID, err := trace.SpanIDFromHex(spanIDStr)
82-
if err != nil {
83-
return err
84-
}
85-
log.SetTraceID([16]byte(traceID))
86-
log.SetSpanID([8]byte(spanID))
72+
if !pcommon.TraceID(traceID).IsEmpty() {
73+
log.SetTraceID(traceID)
74+
log.SetSpanID(spanID)
8775
}
88-
return nil
8976
}
90-
return fmt.Errorf("envelope is not a log")
77+
return nil
78+
}
79+
80+
func getTracingIDs(logLine string) (traceID [16]byte, spanID [8]byte, err error) {
81+
var trace []byte
82+
var span []byte
83+
_, wordsMap := parseLogLine(logLine)
84+
traceIDStr, foundW3C := wordsMap[logLineRTRW3CKey]
85+
if foundW3C {
86+
// Use W3C headers
87+
traceW3C := strings.Split(traceIDStr, "-")
88+
if len(traceW3C) != 4 || traceW3C[0] != "00" {
89+
err = fmt.Errorf(
90+
"traceId W3C key %s with format %s not valid in log",
91+
logLineRTRW3CKey, traceW3C[0])
92+
return
93+
}
94+
trace = []byte(traceW3C[1])
95+
span = []byte(traceW3C[2])
96+
} else {
97+
// try Zipkin headers
98+
traceIDStr, foundZk := wordsMap[logLineRTRZipkinKey]
99+
if !foundZk {
100+
// log line has no tracing headers
101+
return
102+
}
103+
traceZk := strings.Split(traceIDStr, "-")
104+
if len(traceZk) != 2 {
105+
err = fmt.Errorf(
106+
"traceId Zipkin key %s not valid in log",
107+
logLineRTRZipkinKey)
108+
return
109+
}
110+
trace = []byte(traceZk[0])
111+
span = []byte(traceZk[1])
112+
}
113+
traceDecoded := make([]byte, 16)
114+
spanDecoded := make([]byte, 8)
115+
if _, err = hex.Decode(traceDecoded, trace); err != nil {
116+
return
117+
}
118+
if _, err = hex.Decode(spanDecoded, span); err != nil {
119+
return
120+
}
121+
copy(traceID[:], traceDecoded)
122+
copy(spanID[:], spanDecoded)
123+
return
91124
}
92125

93126
func copyEnvelopeAttributes(attributes pcommon.Map, envelope *loggregator_v2.Envelope) {
94127
for key, value := range envelope.Tags {
95128
attributes.PutStr(attributeNamePrefix+key, value)
96129
}
97-
98130
if envelope.SourceId != "" {
99131
attributes.PutStr(attributeNamePrefix+"source_id", envelope.SourceId)
100132
}
101-
102133
if envelope.InstanceId != "" {
103134
attributes.PutStr(attributeNamePrefix+"instance_id", envelope.InstanceId)
104135
}

‎receiver/cloudfoundryreceiver/converter_test.go

+83
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,8 @@
44
package cloudfoundryreceiver
55

66
import (
7+
"encoding/hex"
8+
"fmt"
79
"testing"
810
"time"
911

@@ -186,6 +188,87 @@ func TestParseLogLine(t *testing.T) {
186188
}
187189
}
188190

191+
func TestSetTraceIDs(t *testing.T) {
192+
t.Parallel()
193+
tests := []struct {
194+
id string
195+
logLine string
196+
expected map[string]interface{}
197+
}{
198+
{
199+
id: "w3c-zipkin",
200+
logLine: `www.example.com - [2024-05-21T15:40:13.892179798Z] "GET /articles/ssdfws HTTP/1.1" 200 0 110563 "-" "python-requests/2.26.0" "20.191.2.244:52238" "10.88.195.81:61222" x_forwarded_for:"18.21.57.150, 10.28.45.29, 35.16.25.46, 20.191.2.244" x_forwarded_proto:"https" vcap_request_id:"766afb19-1779-4bb9-65d4-f01306f9f912" response_time:0.191835 gorouter_time:0.000139 app_id:"e3267823-0938-43ce-85ff-003e3e3a5a23" app_index:"4" instance_id:"918dd283-a0ed-48be-7f0c-253b" x_cf_routererror:"-" x_forwarded_host:"www.example.com" x_b3_traceid:"766afb1917794bb965d4f01306f9f912" x_b3_spanid:"65d4f01306f9f912" x_b3_parentspanid:"-" b3:"766afb1917794bb965d4f01306f9f912-65d4f01306f9f912" traceparent:"00-766afb1917794bb965d4f01306f9f912-65d4f01306f9f912-01" tracestate:"gorouter=65d4f01306f9f912"`,
201+
expected: map[string]interface{}{
202+
"err": nil,
203+
"traceID": "766afb1917794bb965d4f01306f9f912",
204+
"spanID": "65d4f01306f9f912",
205+
},
206+
},
207+
{
208+
id: "zipkin",
209+
logLine: `www.example.com - [2024-05-21T15:40:13.892179798Z] "GET /articles/ssdfws HTTP/1.1" 200 0 110563 "-" "python-requests/2.26.0" "20.191.2.244:52238" "10.88.195.81:61222" x_forwarded_for:"18.21.57.150, 10.28.45.29, 35.16.25.46, 20.191.2.244" x_forwarded_proto:"https" vcap_request_id:"766afb19-1779-4bb9-65d4-f01306f9f912" response_time:0.191835 gorouter_time:0.000139 app_id:"e3267823-0938-43ce-85ff-003e3e3a5a23" app_index:"4" instance_id:"918dd283-a0ed-48be-7f0c-253b" x_cf_routererror:"-" x_forwarded_host:"www.example.com" x_b3_traceid:"766afb1917794bb965d4f01306f9f912" x_b3_spanid:"65d4f01306f9f912" x_b3_parentspanid:"-" b3:"766afb1917794bb965d4f01306f9f912-65d4f01306f9f912"`,
210+
expected: map[string]interface{}{
211+
"err": nil,
212+
"traceID": "766afb1917794bb965d4f01306f9f912",
213+
"spanID": "65d4f01306f9f912",
214+
},
215+
},
216+
{
217+
id: "w3c",
218+
logLine: `www.example.com - [2024-05-21T15:40:13.892179798Z] "GET /articles/ssdfws HTTP/1.1" 200 0 110563 "-" "python-requests/2.26.0" "20.191.2.244:52238" "10.88.195.81:61222" x_forwarded_for:"18.21.57.150, 10.28.45.29, 35.16.25.46, 20.191.2.244" x_forwarded_proto:"https" vcap_request_id:"766afb19-1779-4bb9-65d4-f01306f9f912" response_time:0.191835 gorouter_time:0.000139 app_id:"e3267823-0938-43ce-85ff-003e3e3a5a23" app_index:"4" instance_id:"918dd283-a0ed-48be-7f0c-253b" x_cf_routererror:"-" x_forwarded_host:"www.example.com" traceparent:"00-766afb1917794bb965d4f01306f9f912-65d4f01306f9f912-01" tracestate:"gorouter=65d4f01306f9f912"`,
219+
expected: map[string]interface{}{
220+
"err": nil,
221+
"traceID": "766afb1917794bb965d4f01306f9f912",
222+
"spanID": "65d4f01306f9f912",
223+
},
224+
},
225+
{
226+
id: "not-found",
227+
logLine: `www.example.com - [2024-05-21T15:40:13.892179798Z] "GET /articles/ssdfws HTTP/1.1" 200 0 110563 "-" "python-requests/2.26.0" "20.191.2.244:52238" "10.88.195.81:61222" x_forwarded_for:"18.21.57.150, 10.28.45.29, 35.16.25.46, 20.191.2.244" x_forwarded_proto:"https" vcap_request_id:"766afb19-1779-4bb9-65d4-f01306f9f912" response_time:0.191835 gorouter_time:0.000139 app_id:"e3267823-0938-43ce-85ff-003e3e3a5a23" app_index:"4" instance_id:"918dd283-a0ed-48be-7f0c-253b" x_cf_routererror:"-" x_forwarded_host:"www.example.com"`,
228+
expected: map[string]interface{}{
229+
"err": nil,
230+
"traceID": "00000000000000000000000000000000",
231+
"spanID": "0000000000000000",
232+
},
233+
},
234+
{
235+
id: "error-w3c",
236+
logLine: `www.example.com - [2024-05-21T15:40:13.892179798Z] "GET /articles/ssdfws HTTP/1.1" 200 0 110563 "-" "python-requests/2.26.0" "20.191.2.244:52238" "10.88.195.81:61222" x_forwarded_for:"18.21.57.150, 10.28.45.29, 35.16.25.46, 20.191.2.244" x_forwarded_proto:"https" vcap_request_id:"766afb19-1779-4bb9-65d4-f01306f9f912" response_time:0.191835 gorouter_time:0.000139 app_id:"e3267823-0938-43ce-85ff-003e3e3a5a23" app_index:"4" instance_id:"918dd283-a0ed-48be-7f0c-253b" x_cf_routererror:"-" x_forwarded_host:"www.example.com" traceparent:"00-766afb1917794bb965d4f01306f9f912-65d4f01306f9f9122-01" tracestate:"gorouter=65d4f01306f9f912"`, expected: map[string]interface{}{
237+
"err": fmt.Errorf("encoding/hex: odd length hex string"),
238+
"traceID": "00000000000000000000000000000000",
239+
"spanID": "0000000000000000",
240+
},
241+
},
242+
{
243+
id: "error-w3c-format",
244+
logLine: `www.example.com - [2024-05-21T15:40:13.892179798Z] "GET /articles/ssdfws HTTP/1.1" 200 0 110563 "-" "python-requests/2.26.0" "20.191.2.244:52238" "10.88.195.81:61222" x_forwarded_for:"18.21.57.150, 10.28.45.29, 35.16.25.46, 20.191.2.244" x_forwarded_proto:"https" vcap_request_id:"766afb19-1779-4bb9-65d4-f01306f9f912" response_time:0.191835 gorouter_time:0.000139 app_id:"e3267823-0938-43ce-85ff-003e3e3a5a23" app_index:"4" instance_id:"918dd283-a0ed-48be-7f0c-253b" x_cf_routererror:"-" x_forwarded_host:"www.example.com" traceparent:"00-766afb1917794bb965d4f01306f9f912-65d4f01306f9f912" tracestate:"gorouter=65d4f01306f9f912"`, expected: map[string]interface{}{
245+
"err": fmt.Errorf("traceId W3C key traceparent with format 00 not valid in log"),
246+
"traceID": "00000000000000000000000000000000",
247+
"spanID": "0000000000000000",
248+
},
249+
},
250+
{
251+
id: "error-zipkin-format",
252+
logLine: `www.example.com - [2024-05-21T15:40:13.892179798Z] "GET /articles/ssdfws HTTP/1.1" 200 0 110563 "-" "python-requests/2.26.0" "20.191.2.244:52238" "10.88.195.81:61222" x_forwarded_for:"18.21.57.150, 10.28.45.29, 35.16.25.46, 20.191.2.244" x_forwarded_proto:"https" vcap_request_id:"766afb19-1779-4bb9-65d4-f01306f9f912" response_time:0.191835 gorouter_time:0.000139 app_id:"e3267823-0938-43ce-85ff-003e3e3a5a23" app_index:"4" instance_id:"918dd283-a0ed-48be-7f0c-253b" x_cf_routererror:"-" x_forwarded_host:"www.example.com" x_b3_traceid:"766afb1917794bb965d4f01306f9f912" x_b3_spanid:"65d4f01306f9f912" x_b3_parentspanid:"-" b3:"766afb1917794bb965d4f01306f9f912-65d4f01306f9f912-01"`,
253+
expected: map[string]interface{}{
254+
"err": fmt.Errorf("traceId Zipkin key b3 not valid in log"),
255+
"traceID": "00000000000000000000000000000000",
256+
"spanID": "0000000000000000",
257+
},
258+
},
259+
}
260+
for _, tt := range tests {
261+
t.Run(tt.id, func(t *testing.T) {
262+
traceID, spanID, err := getTracingIDs(tt.logLine)
263+
264+
require.Equal(t, tt.expected["err"], err)
265+
assert.Equal(t, tt.expected["traceID"].(string), hex.EncodeToString(traceID[:]))
266+
assert.Equal(t, tt.expected["spanID"].(string), hex.EncodeToString(spanID[:]))
267+
268+
})
269+
}
270+
}
271+
189272
func TestConvertLogsEnvelope(t *testing.T) {
190273
now := time.Now()
191274
before := time.Now().Add(-time.Second)

0 commit comments

Comments
 (0)