Skip to content

Commit

Permalink
[receiver/cloudfoundryreceiver] Refactor logic and tests to set traci…
Browse files Browse the repository at this point in the history 
…ng attributes in RTR logs

Co-authored-by: Sam Clulow <sam.clulow@springernature.com>
Co-authored-by: Cem Deniz Kabakci <cem.kabakci@springer.com>
  • Loading branch information
@jriguera @m1rp @CemDK
3 people committed May 29, 2024
1 parent 9e23312 commit 361fd8e
Show file tree
Hide file tree
Showing 2 changed files with 154 additions and 40 deletions.
111 changes: 71 additions & 40 deletions receiver/cloudfoundryreceiver/converter.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
package cloudfoundryreceiver // import "github.com/open-telemetry/opentelemetry-collector-contrib/receiver/cloudfoundryreceiver"

import (
"encoding/hex"
"fmt"
"strings"
"time"
Expand All @@ -13,15 +14,14 @@ import (
"go.opentelemetry.io/collector/pdata/pcommon"
"go.opentelemetry.io/collector/pdata/plog"
"go.opentelemetry.io/collector/pdata/pmetric"
"go.opentelemetry.io/otel/trace"
)

const (
attributeNamePrefix = "org.cloudfoundry."
envelopeSourceTypeTag = "org.cloudfoundry.source_type"
envelopeSourceTypeValueRTR = "RTR"
logLineRTRTraceIDKey = "x_b3_traceid"
logLineRTRSpanIDKey = "x_b3_spanid"
logLineRTRZipkinKey = "b3"
logLineRTRW3CKey = "traceparent"
)

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

func convertEnvelopeToLogs(envelope *loggregator_v2.Envelope, logSlice plog.LogRecordSlice, startTime time.Time) error {
if _, isLog := envelope.Message.(*loggregator_v2.Envelope_Log); isLog {
log := logSlice.AppendEmpty()
log.SetTimestamp(pcommon.Timestamp(envelope.GetTimestamp()))
log.SetObservedTimestamp(pcommon.NewTimestampFromTime(startTime))
log.Body().SetStr(string(envelope.GetLog().GetPayload()))
switch envelope.GetLog().GetType() {
case loggregator_v2.Log_OUT:
log.SetSeverityText(plog.SeverityNumberInfo.String())
log.SetSeverityNumber(plog.SeverityNumberInfo)
case loggregator_v2.Log_ERR:
log.SetSeverityText(plog.SeverityNumberError.String())
log.SetSeverityNumber(plog.SeverityNumberError)
log := logSlice.AppendEmpty()
log.SetTimestamp(pcommon.Timestamp(envelope.GetTimestamp()))
log.SetObservedTimestamp(pcommon.NewTimestampFromTime(startTime))
logLine := string(envelope.GetLog().GetPayload())
log.Body().SetStr(logLine)
switch envelope.GetLog().GetType() {
case loggregator_v2.Log_OUT:
log.SetSeverityText(plog.SeverityNumberInfo.String())
log.SetSeverityNumber(plog.SeverityNumberInfo)
case loggregator_v2.Log_ERR:
log.SetSeverityText(plog.SeverityNumberError.String())
log.SetSeverityNumber(plog.SeverityNumberError)
}
copyEnvelopeAttributes(log.Attributes(), envelope)
if envelope.SourceId == envelopeSourceTypeValueRTR {
traceID, spanID, err := getTracingIDs(logLine)
if err != nil {
return err
}
copyEnvelopeAttributes(log.Attributes(), envelope)
if value, found := log.Attributes().Get(envelopeSourceTypeTag); found && value.AsString() == envelopeSourceTypeValueRTR {
_, wordsMap := parseLogLine(log.Body().AsString())
traceIDStr, found := wordsMap[logLineRTRTraceIDKey]
if !found {
return fmt.Errorf("traceid key %s not found in log", logLineRTRTraceIDKey)
}
spanIDStr, found := wordsMap[logLineRTRSpanIDKey]
if !found {
return fmt.Errorf("spanid key %s not found in log", logLineRTRSpanIDKey)
}
traceID, err := trace.TraceIDFromHex(traceIDStr)
if err != nil {
return err
}
spanID, err := trace.SpanIDFromHex(spanIDStr)
if err != nil {
return err
}
log.SetTraceID([16]byte(traceID))
log.SetSpanID([8]byte(spanID))
if !pcommon.TraceID(traceID).IsEmpty() {
log.SetTraceID(traceID)
log.SetSpanID(spanID)
}
return nil
}
return fmt.Errorf("envelope is not a log")
return nil
}

func getTracingIDs(logLine string) (traceID [16]byte, spanID [8]byte, err error) {
var trace []byte
var span []byte
_, wordsMap := parseLogLine(logLine)
traceIDStr, foundW3C := wordsMap[logLineRTRW3CKey]
if foundW3C {
// Use W3C headers
traceW3C := strings.Split(traceIDStr, "-")
if len(traceW3C) != 4 || traceW3C[0] != "00" {
err = fmt.Errorf(
"traceId W3C key %s with format %s not valid in log",
logLineRTRW3CKey, traceW3C[0])
return
}
trace = []byte(traceW3C[1])
span = []byte(traceW3C[2])
} else {
// try Zipkin headers
traceIDStr, foundZk := wordsMap[logLineRTRZipkinKey]
if !foundZk {
// log line has no tracing headers
return
}
traceZk := strings.Split(traceIDStr, "-")
if len(traceZk) != 2 {
err = fmt.Errorf(
"traceId Zipkin key %s not valid in log",
logLineRTRZipkinKey)
return
}
trace = []byte(traceZk[0])
span = []byte(traceZk[1])
}
traceDecoded := make([]byte, 16)
spanDecoded := make([]byte, 8)
if _, err = hex.Decode(traceDecoded, trace); err != nil {
return
}
if _, err = hex.Decode(spanDecoded, span); err != nil {
return
}
copy(traceID[:], traceDecoded)
copy(spanID[:], spanDecoded)
return
}

func copyEnvelopeAttributes(attributes pcommon.Map, envelope *loggregator_v2.Envelope) {
for key, value := range envelope.Tags {
attributes.PutStr(attributeNamePrefix+key, value)
}

if envelope.SourceId != "" {
attributes.PutStr(attributeNamePrefix+"source_id", envelope.SourceId)
}

if envelope.InstanceId != "" {
attributes.PutStr(attributeNamePrefix+"instance_id", envelope.InstanceId)
}
Expand Down
83 changes: 83 additions & 0 deletions receiver/cloudfoundryreceiver/converter_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,8 @@
package cloudfoundryreceiver

import (
"encoding/hex"
"fmt"
"testing"
"time"

Expand Down Expand Up @@ -186,6 +188,87 @@ func TestParseLogLine(t *testing.T) {
}
}

func TestSetTraceIDs(t *testing.T) {
t.Parallel()
tests := []struct {
id string
logLine string
expected map[string]interface{}
}{
{
id: "w3c-zipkin",
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"`,
expected: map[string]interface{}{
"err": nil,
"traceID": "766afb1917794bb965d4f01306f9f912",
"spanID": "65d4f01306f9f912",
},
},
{
id: "zipkin",
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"`,
expected: map[string]interface{}{
"err": nil,
"traceID": "766afb1917794bb965d4f01306f9f912",
"spanID": "65d4f01306f9f912",
},
},
{
id: "w3c",
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"`,
expected: map[string]interface{}{
"err": nil,
"traceID": "766afb1917794bb965d4f01306f9f912",
"spanID": "65d4f01306f9f912",
},
},
{
id: "not-found",
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"`,
expected: map[string]interface{}{
"err": nil,
"traceID": "00000000000000000000000000000000",
"spanID": "0000000000000000",
},
},
{
id: "error-w3c",
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{}{
"err": fmt.Errorf("encoding/hex: odd length hex string"),
"traceID": "00000000000000000000000000000000",
"spanID": "0000000000000000",
},
},
{
id: "error-w3c-format",
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{}{
"err": fmt.Errorf("traceId W3C key traceparent with format 00 not valid in log"),
"traceID": "00000000000000000000000000000000",
"spanID": "0000000000000000",
},
},
{
id: "error-zipkin-format",
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"`,
expected: map[string]interface{}{
"err": fmt.Errorf("traceId Zipkin key b3 not valid in log"),
"traceID": "00000000000000000000000000000000",
"spanID": "0000000000000000",
},
},
}
for _, tt := range tests {
t.Run(tt.id, func(t *testing.T) {
traceID, spanID, err := getTracingIDs(tt.logLine)

require.Equal(t, tt.expected["err"], err)
assert.Equal(t, tt.expected["traceID"].(string), hex.EncodeToString(traceID[:]))
assert.Equal(t, tt.expected["spanID"].(string), hex.EncodeToString(spanID[:]))

})
}
}

func TestConvertLogsEnvelope(t *testing.T) {
now := time.Now()
before := time.Now().Add(-time.Second)
Expand Down

0 comments on commit 361fd8e

Please sign in to comment.