From 7c028e02aa0cbb0d7f9c150f14ace80a3f3939a1 Mon Sep 17 00:00:00 2001 From: Muhammad Azeez Date: Wed, 17 Jan 2024 13:21:43 +0300 Subject: [PATCH] feat: add manual instrumentation host functions to Go SDK (#152) * feat: add span_enter and span_exit to go sdk * add more functions * test stdout adapter * test otelstdout * logs and metrics * stub out log and metric impl * cleanup * feat: don't associate logs and metrics with spans * cleanup --- go/adapter.go | 15 ++ go/adapter/datadog/adapter.go | 13 ++ go/adapter/datadog_formatter/format.go | 4 + go/adapter/honeycomb/adapter.go | 4 + go/adapter/lightstep/adapter.go | 4 + go/adapter/opentelemetry/adapter.go | 6 +- go/adapter/otel_stdout/adapter.go | 4 + go/adapter/stdout/adapter.go | 7 + go/bin/otelstdout/main.go | 10 +- go/bin/stdout/main.go | 11 +- go/event.go | 51 +++++++ go/go.mod | 14 +- go/go.sum | 17 +++ go/listener.go | 8 + go/trace_ctx.go | 197 ++++++++++++++++++------- 15 files changed, 306 insertions(+), 59 deletions(-) diff --git a/go/adapter.go b/go/adapter.go index 2d961498..3ba0a1a5 100644 --- a/go/adapter.go +++ b/go/adapter.go @@ -4,6 +4,7 @@ import ( "context" "fmt" "log" + "strings" "time" "github.com/tetratelabs/wazero" @@ -109,6 +110,20 @@ func (b *AdapterBase) MakeOtelCallSpans(event CallEvent, parentId []byte, traceI last.Attributes = append(last.Attributes, kv) } } + if tags, ok := ev.(SpanTagsEvent); ok { + last := spans[len(spans)-1] + + for _, tag := range tags.Tags { + parts := strings.Split(tag, ":") + if len(parts) != 2 { + log.Printf("Invalid tag: %s\n", tag) + continue + } + + kv := NewOtelKeyValueString(parts[0], parts[1]) + last.Attributes = append(last.Attributes, kv) + } + } } return spans } diff --git a/go/adapter/datadog/adapter.go b/go/adapter/datadog/adapter.go index bc569a6e..7cff86dd 100644 --- a/go/adapter/datadog/adapter.go +++ b/go/adapter/datadog/adapter.go @@ -8,6 +8,7 @@ import ( "log" "net/http" "net/url" + "strings" "time" observe "github.com/dylibso/observe-sdk/go" @@ -193,6 +194,18 @@ func (d *DatadogAdapter) makeCallSpans(event observe.CallEvent, parentId *uint64 span := spans[len(spans)-1] span.AddAllocation(alloc.MemoryGrowAmount()) } + if tags, ok := ev.(observe.SpanTagsEvent); ok { + span := spans[len(spans)-1] + for _, tag := range tags.Tags { + parts := strings.Split(tag, ":") + if len(parts) != 2 { + log.Printf("Invalid tag: %s\n", tag) + continue + } + + span.AddTag(parts[0], parts[1]) + } + } } return spans diff --git a/go/adapter/datadog_formatter/format.go b/go/adapter/datadog_formatter/format.go index be866bab..8928fcc6 100644 --- a/go/adapter/datadog_formatter/format.go +++ b/go/adapter/datadog_formatter/format.go @@ -55,6 +55,10 @@ func (s *Span) AddAllocation(amount uint32) { } } +func (s *Span) AddTag(key, value string) { + s.Meta[key] = value +} + func New() *DatadogFormatter { return &DatadogFormatter{} } diff --git a/go/adapter/honeycomb/adapter.go b/go/adapter/honeycomb/adapter.go index 549a2d40..9c99a734 100644 --- a/go/adapter/honeycomb/adapter.go +++ b/go/adapter/honeycomb/adapter.go @@ -62,6 +62,10 @@ func (h *HoneycombAdapter) Flush(evts []observe.TraceEvent) error { log.Println("MemoryGrowEvent should be attached to a span") case observe.CustomEvent: log.Println("Honeycomb adapter does not respect custom events") + case observe.MetricEvent: + log.Println("Honeycomb adapter does not respect metric events") + case observe.LogEvent: + log.Println("Honeycomb adapter does not respect log events") } } diff --git a/go/adapter/lightstep/adapter.go b/go/adapter/lightstep/adapter.go index f5168df2..0caacd3f 100644 --- a/go/adapter/lightstep/adapter.go +++ b/go/adapter/lightstep/adapter.go @@ -62,6 +62,10 @@ func (l *LightstepAdapter) Flush(evts []observe.TraceEvent) error { log.Println("MemoryGrowEvent should be attached to a span") case observe.CustomEvent: log.Println("lightstep adapter does not respect custom events") + case observe.MetricEvent: + log.Println("lightstep adapter does not respect metric events") + case observe.LogEvent: + log.Println("lightstep adapter does not respect log events") } } diff --git a/go/adapter/opentelemetry/adapter.go b/go/adapter/opentelemetry/adapter.go index 1a396f81..c37bcd8d 100644 --- a/go/adapter/opentelemetry/adapter.go +++ b/go/adapter/opentelemetry/adapter.go @@ -37,7 +37,7 @@ type OTelAdapter struct { Config *OTelConfig } -// UseCustomClient accepts a pre-initialized client to allow for customization of how to get data into a collector +// UseCustomClient accepts a pre-initialized client to allow for customization of how to get data into a collector func (a *OTelAdapter) UseCustomClient(client otlptrace.Client) { if a.Config != nil { a.Config.client = client @@ -122,6 +122,10 @@ func (o *OTelAdapter) Flush(evts []observe.TraceEvent) error { log.Println("MemoryGrowEvent should be attached to a span") case observe.CustomEvent: log.Println("opentelemetry adapter does not respect custom events") + case observe.MetricEvent: + log.Println("opentelemetry adapter does not respect metric events") + case observe.LogEvent: + log.Println("opentelemetry adapter does not respect log events") } } diff --git a/go/adapter/otel_stdout/adapter.go b/go/adapter/otel_stdout/adapter.go index ada060be..9e3e60f4 100644 --- a/go/adapter/otel_stdout/adapter.go +++ b/go/adapter/otel_stdout/adapter.go @@ -45,6 +45,10 @@ func (o *OtelStdoutAdapter) Flush(evts []observe.TraceEvent) error { log.Println("MemoryGrowEvent should be attached to a span") case observe.CustomEvent: log.Println("Otel adapter does not respect custom events") + case observe.MetricEvent: + log.Printf("metric: %s\n", event.Message) + case observe.LogEvent: + log.Println(event.Message) } } diff --git a/go/adapter/stdout/adapter.go b/go/adapter/stdout/adapter.go index 2a5f1cb1..f6ce93e5 100644 --- a/go/adapter/stdout/adapter.go +++ b/go/adapter/stdout/adapter.go @@ -38,6 +38,10 @@ func (s *StdoutAdapter) Flush(evts []observe.TraceEvent) error { log.Println("Allocated", event.MemoryGrowAmount(), "pages of memory in", name) case observe.CustomEvent: log.Println(event.Name, event.Time) + case observe.MetricEvent: + log.Printf("metric: %s\n", event.Message) + case observe.LogEvent: + log.Println(event.Message) } } } @@ -55,6 +59,9 @@ func (s *StdoutAdapter) printEvents(event observe.CallEvent, indentation int) { if alloc, ok := event.(observe.MemoryGrowEvent); ok { log.Println(strings.Repeat(" ", indentation), "Allocated", alloc.MemoryGrowAmount(), "pages of memory in", name) } + if spanTags, ok := event.(observe.SpanTagsEvent); ok { + log.Println(strings.Repeat(" ", indentation), "Span tags:", spanTags.Tags) + } } } diff --git a/go/bin/otelstdout/main.go b/go/bin/otelstdout/main.go index 8746f436..e429c6a2 100644 --- a/go/bin/otelstdout/main.go +++ b/go/bin/otelstdout/main.go @@ -6,6 +6,7 @@ import ( "os" "time" + observe "github.com/dylibso/observe-sdk/go" "github.com/dylibso/observe-sdk/go/adapter/otel_stdout" "github.com/tetratelabs/wazero" "github.com/tetratelabs/wazero/imports/wasi_snapshot_preview1" @@ -27,7 +28,14 @@ func main() { cfg := wazero.NewRuntimeConfig().WithCustomSections(true) rt := wazero.NewRuntimeWithConfig(ctx, cfg) - traceCtx, err := adapter.NewTraceCtx(ctx, rt, wasm, nil) + opts := observe.Options{ + ChannelBufferSize: 1024, + SpanFilter: &observe.SpanFilter{ + MinDuration: 0, + }, + } + + traceCtx, err := adapter.NewTraceCtx(ctx, rt, wasm, &opts) if err != nil { log.Panicln(err) } diff --git a/go/bin/stdout/main.go b/go/bin/stdout/main.go index b084a79f..f0e4254a 100644 --- a/go/bin/stdout/main.go +++ b/go/bin/stdout/main.go @@ -6,6 +6,7 @@ import ( "os" "time" + observe "github.com/dylibso/observe-sdk/go" "github.com/dylibso/observe-sdk/go/adapter/stdout" "github.com/tetratelabs/wazero" "github.com/tetratelabs/wazero/imports/wasi_snapshot_preview1" @@ -27,7 +28,15 @@ func main() { cfg := wazero.NewRuntimeConfig().WithCustomSections(true) rt := wazero.NewRuntimeWithConfig(ctx, cfg) - traceCtx, err := adapter.NewTraceCtx(ctx, rt, wasm, nil) + + opts := observe.Options{ + ChannelBufferSize: 1024, + SpanFilter: &observe.SpanFilter{ + MinDuration: 0, + }, + } + + traceCtx, err := adapter.NewTraceCtx(ctx, rt, wasm, &opts) if err != nil { log.Panicln(err) } diff --git a/go/event.go b/go/event.go index 02784cb3..2865cf74 100644 --- a/go/event.go +++ b/go/event.go @@ -13,6 +13,9 @@ const ( RawEnter RawEventKind = iota RawExit RawMemoryGrow + RawMetric + RawSpanTags + RawLog ) type EventKind int @@ -21,6 +24,15 @@ const ( Call EventKind = iota MemoryGrow Custom + Metric + SpanTags + Log +) + +type MetricFormat int + +const ( + StatsdFormat MetricFormat = 1 ) // Represents the raw event in our Observe form. @@ -77,11 +89,38 @@ func (e CustomEvent) RawEvents() []RawEvent { return []RawEvent{} } +type MetricEvent struct { + Time time.Time + Format MetricFormat + Message string +} + +type SpanTagsEvent struct { + Raw RawEvent + Time time.Time + Tags []string +} + type MemoryGrowEvent struct { Raw RawEvent Time time.Time } +type LogLevel int + +const ( + Error LogLevel = 1 + Warn = 2 + Info = 3 + Debug = 4 +) + +type LogEvent struct { + Time time.Time + Message string + Level LogLevel +} + func (e MemoryGrowEvent) RawEvents() []RawEvent { return []RawEvent{e.Raw} } @@ -113,3 +152,15 @@ func (e CallEvent) FunctionIndex() uint32 { func (e MemoryGrowEvent) MemoryGrowAmount() uint32 { return e.Raw.MemoryGrowAmount } + +func (e MetricEvent) RawEvents() []RawEvent { + return []RawEvent{} +} + +func (e SpanTagsEvent) RawEvents() []RawEvent { + return []RawEvent{e.Raw} +} + +func (e LogEvent) RawEvents() []RawEvent { + return []RawEvent{} +} diff --git a/go/go.mod b/go/go.mod index 41785899..cb00c3db 100644 --- a/go/go.mod +++ b/go/go.mod @@ -18,16 +18,18 @@ require ( require ( github.com/cenkalti/backoff/v4 v4.2.1 // indirect - github.com/go-logr/logr v1.2.4 // indirect + github.com/go-logr/logr v1.3.0 // indirect github.com/go-logr/stdr v1.2.2 // indirect github.com/golang/protobuf v1.5.3 // indirect github.com/grpc-ecosystem/grpc-gateway/v2 v2.16.0 // indirect - go.opentelemetry.io/otel v1.18.0 // indirect - go.opentelemetry.io/otel/metric v1.18.0 // indirect - go.opentelemetry.io/otel/sdk v1.18.0 // indirect - go.opentelemetry.io/otel/trace v1.18.0 // indirect + go.opentelemetry.io/otel v1.21.0 // indirect + go.opentelemetry.io/otel/exporters/stdout/stdoutmetric v0.44.0 // indirect + go.opentelemetry.io/otel/metric v1.21.0 // indirect + go.opentelemetry.io/otel/sdk v1.21.0 // indirect + go.opentelemetry.io/otel/sdk/metric v1.21.0 // indirect + go.opentelemetry.io/otel/trace v1.21.0 // indirect golang.org/x/net v0.17.0 // indirect - golang.org/x/sys v0.13.0 // indirect + golang.org/x/sys v0.14.0 // indirect golang.org/x/text v0.13.0 // indirect google.golang.org/genproto/googleapis/api v0.0.0-20230711160842-782d3b101e98 // indirect google.golang.org/genproto/googleapis/rpc v0.0.0-20230711160842-782d3b101e98 // indirect diff --git a/go/go.sum b/go/go.sum index 3f28ebc4..8e8587f8 100644 --- a/go/go.sum +++ b/go/go.sum @@ -4,6 +4,8 @@ github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= github.com/go-logr/logr v1.2.4 h1:g01GSCwiDw2xSZfjJ2/T9M+S6pFdcNtFYsp+Y43HYDQ= github.com/go-logr/logr v1.2.4/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= +github.com/go-logr/logr v1.3.0 h1:2y3SDp0ZXuc6/cjLSZ+Q3ir+QB9T/iG5yYRXqsagWSY= +github.com/go-logr/logr v1.3.0/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= github.com/golang/glog v1.1.0 h1:/d3pCKDPWNnvIWe0vVUpNP32qc8U3PDVxySP/y360qE= @@ -12,6 +14,7 @@ github.com/golang/protobuf v1.5.3 h1:KhyjKVUg7Usr/dYsdSqoFveMYd5ko72D+zANwlG1mmg github.com/golang/protobuf v1.5.3/go.mod h1:XVQd3VNwM+JqD3oG2Ue2ip4fOMUkwXdXDdiuN0vRsmY= github.com/google/go-cmp v0.5.5/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE= github.com/google/go-cmp v0.5.9 h1:O2Tfq5qg4qc4AmwVlvv0oLiVAGB7enBSJ2x2DqQFi38= +github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI= github.com/grpc-ecosystem/grpc-gateway/v2 v2.16.0 h1:YBftPWNWd4WwGqtY2yeZL2ef8rHAxPBD8KFhJpmcqms= github.com/grpc-ecosystem/grpc-gateway/v2 v2.16.0/go.mod h1:YN5jB8ie0yfIUg6VvR9Kz84aCaG7AsGZnLjhHbUqwPg= github.com/ianlancetaylor/demangle v0.0.0-20230524184225-eabc099b10ab h1:BA4a7pe6ZTd9F8kXETBoijjFJ/ntaa//1wiH9BZu4zU= @@ -24,18 +27,30 @@ github.com/tetratelabs/wazero v1.2.1 h1:J4X2hrGzJvt+wqltuvcSjHQ7ujQxA9gb6PeMs4ql github.com/tetratelabs/wazero v1.2.1/go.mod h1:wYx2gNRg8/WihJfSDxA1TIL8H+GkfLYm+bIfbblu9VQ= go.opentelemetry.io/otel v1.18.0 h1:TgVozPGZ01nHyDZxK5WGPFB9QexeTMXEH7+tIClWfzs= go.opentelemetry.io/otel v1.18.0/go.mod h1:9lWqYO0Db579XzVuCKFNPDl4s73Voa+zEck3wHaAYQI= +go.opentelemetry.io/otel v1.21.0 h1:hzLeKBZEL7Okw2mGzZ0cc4k/A7Fta0uoPgaJCr8fsFc= +go.opentelemetry.io/otel v1.21.0/go.mod h1:QZzNPQPm1zLX4gZK4cMi+71eaorMSGT3A4znnUvNNEo= go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.18.0 h1:IAtl+7gua134xcV3NieDhJHjjOVeJhXAnYf/0hswjUY= go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.18.0/go.mod h1:w+pXobnBzh95MNIkeIuAKcHe/Uu/CX2PKIvBP6ipKRA= go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc v1.18.0 h1:yE32ay7mJG2leczfREEhoW3VfSZIvHaB+gvVo1o8DQ8= go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc v1.18.0/go.mod h1:G17FHPDLt74bCI7tJ4CMitEk4BXTYG4FW6XUpkPBXa4= go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.18.0 h1:6pu8ttx76BxHf+xz/H77AUZkPF3cwWzXqAUsXhVKI18= go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.18.0/go.mod h1:IOmXxPrxoxFMXdNy7lfDmE8MzE61YPcurbUm0SMjerI= +go.opentelemetry.io/otel/exporters/stdout/stdoutmetric v0.44.0 h1:dEZWPjVN22urgYCza3PXRUGEyCB++y1sAqm6guWFesk= +go.opentelemetry.io/otel/exporters/stdout/stdoutmetric v0.44.0/go.mod h1:sTt30Evb7hJB/gEk27qLb1+l9n4Tb8HvHkR0Wx3S6CU= go.opentelemetry.io/otel/metric v1.18.0 h1:JwVzw94UYmbx3ej++CwLUQZxEODDj/pOuTCvzhtRrSQ= go.opentelemetry.io/otel/metric v1.18.0/go.mod h1:nNSpsVDjWGfb7chbRLUNW+PBNdcSTHD4Uu5pfFMOI0k= +go.opentelemetry.io/otel/metric v1.21.0 h1:tlYWfeo+Bocx5kLEloTjbcDwBuELRrIFxwdQ36PlJu4= +go.opentelemetry.io/otel/metric v1.21.0/go.mod h1:o1p3CA8nNHW8j5yuQLdc1eeqEaPfzug24uvsyIEJRWM= go.opentelemetry.io/otel/sdk v1.18.0 h1:e3bAB0wB3MljH38sHzpV/qWrOTCFrdZF2ct9F8rBkcY= go.opentelemetry.io/otel/sdk v1.18.0/go.mod h1:1RCygWV7plY2KmdskZEDDBs4tJeHG92MdHZIluiYs/M= +go.opentelemetry.io/otel/sdk v1.21.0 h1:FTt8qirL1EysG6sTQRZ5TokkU8d0ugCj8htOgThZXQ8= +go.opentelemetry.io/otel/sdk v1.21.0/go.mod h1:Nna6Yv7PWTdgJHVRD9hIYywQBRx7pbox6nwBnZIxl/E= +go.opentelemetry.io/otel/sdk/metric v1.21.0 h1:smhI5oD714d6jHE6Tie36fPx4WDFIg+Y6RfAY4ICcR0= +go.opentelemetry.io/otel/sdk/metric v1.21.0/go.mod h1:FJ8RAsoPGv/wYMgBdUJXOm+6pzFY3YdljnXtv1SBE8Q= go.opentelemetry.io/otel/trace v1.18.0 h1:NY+czwbHbmndxojTEKiSMHkG2ClNH2PwmcHrdo0JY10= go.opentelemetry.io/otel/trace v1.18.0/go.mod h1:T2+SGJGuYZY3bjj5rgh/hN7KIrlpWC5nS8Mjvzckz+0= +go.opentelemetry.io/otel/trace v1.21.0 h1:WD9i5gzvoUPuXIXH24ZNBudiarZDKuekPqi/E8fpfLc= +go.opentelemetry.io/otel/trace v1.21.0/go.mod h1:LGbsEB0f9LGjN+OZaQQ26sohbOmiMR+BaslueVtS/qQ= go.opentelemetry.io/proto/otlp v1.0.0 h1:T0TX0tmXU8a3CbNXzEKGeU5mIVOdf0oykP+u2lIVU/I= go.opentelemetry.io/proto/otlp v1.0.0/go.mod h1:Sy6pihPLfYHkr3NkUbEhGHFhINUSI/v80hjKIs5JXpM= go.uber.org/goleak v1.2.1 h1:NBol2c7O1ZokfZ0LEU9K6Whx/KnwvepVetCUhtKja4A= @@ -43,6 +58,8 @@ golang.org/x/net v0.17.0 h1:pVaXccu2ozPjCXewfr1S7xza/zcXTity9cCdXQYSjIM= golang.org/x/net v0.17.0/go.mod h1:NxSsAGuq816PNPmqtQdLE42eU2Fs7NoRIZrHJAlaCOE= golang.org/x/sys v0.13.0 h1:Af8nKPmuFypiUBjVoU9V20FiaFXOcuZI21p0ycVYYGE= golang.org/x/sys v0.13.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.14.0 h1:Vz7Qs629MkJkGyHxUlRHizWJRG2j8fbQKjELVSNhy7Q= +golang.org/x/sys v0.14.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= golang.org/x/text v0.13.0 h1:ablQoSUd0tRdKxZewP80B+BaqeKJuVhuRxj/dkrun3k= golang.org/x/text v0.13.0/go.mod h1:TvPlkZtksWOMsz7fbANvkp4WM8x/WCo/om8BMLbz+aE= golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= diff --git a/go/listener.go b/go/listener.go index 0b819227..9aeeb9b3 100644 --- a/go/listener.go +++ b/go/listener.go @@ -38,6 +38,14 @@ func (t *TraceCtx) Before(ctx context.Context, _ api.Module, def api.FunctionDef case "instrument_memory_grow": event.Kind = RawMemoryGrow event.MemoryGrowAmount = uint32(inputs[0]) + + // manual events + case "span_enter": + event.Kind = RawEnter + case "span_exit": + event.Kind = RawExit + case "span_tags": + event.Kind = RawSpanTags default: return } diff --git a/go/trace_ctx.go b/go/trace_ctx.go index 85206500..b1af61bd 100644 --- a/go/trace_ctx.go +++ b/go/trace_ctx.go @@ -3,6 +3,7 @@ package observe import ( "context" "log" + "strings" "time" "github.com/tetratelabs/wazero" @@ -90,67 +91,38 @@ func (t *TraceCtx) init(ctx context.Context, r wazero.Runtime) error { functions.WithFunc(func(ctx context.Context, m api.Module, i int32) { start := time.Now() ev := <-t.raw - if ev.Kind != RawEnter { - log.Println("Expected event", RawEnter, "but got", ev.Kind) - } - t.pushFunction(CallEvent{Raw: []RawEvent{ev}, Time: start}) + + t.enter(ev, start) }).Export("instrument_enter") - functions.WithFunc(func(ctx context.Context, i int32) { - end := time.Now() + functions.WithFunc(func(ctx context.Context, m api.Module, ptr uint64, len uint32) { + start := time.Now() ev := <-t.raw - if ev.Kind != RawExit { - log.Println("Expected event", RawExit, "but got", ev.Kind) - return - } - fn, ok := t.peekFunction() - if !ok { - log.Println("Expected values on started function stack, but none were found") - return - } - if ev.FunctionIndex != fn.FunctionIndex() { - log.Println("Expected call to", ev.FunctionIndex, "but found call to", fn.FunctionIndex()) - return - } - - fn, _ = t.popFunction() - fn.Stop(end) - fn.Raw = append(fn.Raw, ev) - // if there is no function left to pop, we are exiting the root function of the trace - f, ok := t.peekFunction() + functionName, ok := m.Memory().Read(uint32(ptr), len) if !ok { - t.events = append(t.events, fn) - return + log.Printf("span_enter: failed to read memory at offset %v with length %v\n", ptr, len) } - // if the function duration is less than minimum duration, disregard - funcDuration := fn.Duration.Microseconds() - minSpanDuration := t.Options.SpanFilter.MinDuration.Microseconds() - if funcDuration < minSpanDuration { - // check for memory allocations and attribute them to the parent span - f, ok = t.popFunction() - if ok { - for _, ev := range fn.within { - switch e := ev.(type) { - case MemoryGrowEvent: - f.within = append(f.within, e) - } - } - t.pushFunction(f) - } - return - } + ev.FunctionName = string(functionName) - // the function is within another function - f, ok = t.popFunction() - if ok { - f.within = append(f.within, fn) - t.pushFunction(f) - } + t.enter(ev, start) + }).Export("span_enter") + functions.WithFunc(func(ctx context.Context, i int32) { + end := time.Now() + ev := <-t.raw + + t.exit(ev, end) }).Export("instrument_exit") + functions.WithFunc(func(ctx context.Context, m api.Module) { + end := time.Now() + ev := <-t.raw + + t.exit(ev, end) + }).Export("span_exit") + functions.WithFunc(func(ctx context.Context, amt int32) { ev := <-t.raw if ev.Kind != RawMemoryGrow { @@ -178,6 +150,71 @@ func (t *TraceCtx) init(ctx context.Context, r wazero.Runtime) error { t.pushFunction(fn) }).Export("instrument_memory_grow") + functions.WithFunc(func(ctx context.Context, m api.Module, f int32, ptr int64, len int32) { + format := MetricFormat(f) + buffer, ok := m.Memory().Read(uint32(ptr), uint32(len)) + if !ok { + log.Printf("metric: failed to read memory at offset %v with length %v\n", ptr, len) + } + + event := MetricEvent{ + Time: time.Now(), + Format: format, + Message: string(buffer), + } + + t.events = append(t.events, event) + }).Export("metric") + + functions.WithFunc(func(ctx context.Context, m api.Module, ptr int64, len int32) { + buffer, ok := m.Memory().Read(uint32(ptr), uint32(len)) + if !ok { + log.Printf("metric: failed to read memory at offset %v with length %v\n", ptr, len) + } + + ev := <-t.raw + if ev.Kind != RawSpanTags { + log.Println("Expected event", Metric, "but got", ev.Kind) + return + } + + event := SpanTagsEvent{ + Time: time.Now(), + Raw: ev, + Tags: strings.Split(string(buffer), ","), + } + + fn, ok := t.popFunction() + if !ok { + t.events = append(t.events, event) + return + } + fn.within = append(fn.within, event) + t.pushFunction(fn) + + }).Export("span_tags") + + functions.WithFunc(func(ctx context.Context, m api.Module, l int32, ptr int64, len int32) { + if l < int32(Error) || l > int32(Debug) { + log.Printf("log: invalid log level %v\n", l) + } + + level := LogLevel(l) + + buffer, ok := m.Memory().Read(uint32(ptr), uint32(len)) + if !ok { + log.Printf("metric: failed to read memory at offset %v with length %v\n", ptr, len) + } + + event := LogEvent{ + Time: time.Now(), + Level: level, + Message: string(buffer), + } + + t.events = append(t.events, event) + }).Export("log") + _, err := observe.Instantiate(ctx) if err != nil { return err @@ -185,6 +222,66 @@ func (t *TraceCtx) init(ctx context.Context, r wazero.Runtime) error { return nil } +func (t *TraceCtx) enter(ev RawEvent, start time.Time) { + if ev.Kind != RawEnter { + log.Println("Expected event", RawEnter, "but got", ev.Kind) + } + t.pushFunction(CallEvent{Raw: []RawEvent{ev}, Time: start}) +} + +func (t *TraceCtx) exit(ev RawEvent, end time.Time) { + + if ev.Kind != RawExit { + log.Println("Expected event", RawExit, "but got", ev.Kind) + return + } + fn, ok := t.peekFunction() + if !ok { + log.Println("Expected values on started function stack, but none were found") + return + } + if ev.FunctionIndex != fn.FunctionIndex() { + log.Println("Expected call to", ev.FunctionIndex, "but found call to", fn.FunctionIndex()) + return + } + + fn, _ = t.popFunction() + fn.Stop(end) + fn.Raw = append(fn.Raw, ev) + + // if there is no function left to pop, we are exiting the root function of the trace + f, ok := t.peekFunction() + if !ok { + t.events = append(t.events, fn) + return + } + + // if the function duration is less than minimum duration, disregard + funcDuration := fn.Duration.Microseconds() + minSpanDuration := t.Options.SpanFilter.MinDuration.Microseconds() + if funcDuration < minSpanDuration { + // check for memory allocations and attribute them to the parent span + f, ok = t.popFunction() + if ok { + for _, ev := range fn.within { + switch e := ev.(type) { + case MemoryGrowEvent: + f.within = append(f.within, e) + } + } + t.pushFunction(f) + } + return + } + + // the function is within another function + f, ok = t.popFunction() + if ok { + f.within = append(f.within, fn) + t.pushFunction(f) + } +} + // Pushes a function onto the stack func (t *TraceCtx) pushFunction(ev CallEvent) { t.stack = append(t.stack, ev)