trace: add buffer limit #824

jgracenin · 2018-07-12T12:50:25Z

This applies to all span data entities that are slices: Annotations,
Links, and Message Events.

At the limit, it pops the oldest sample off prior to appending the new
sample. This should not cause an additional allocation.

Each entity shares the same WithBufferLimit option following the YAGNI
principle.

Each test ensures 4 entities are added in total -- the first 2 are
dropped and the last 2 remain. This should prevent off by 1 bugs.

This applies to all span data entities that are slices: Annotations, Links, and Message Events. At the limit, it pops the oldest sample off prior to appending the new sample. This should not cause an additional allocation. Each entity shares the same WithBufferLimit option following the YAGNI principle. Each test ensures 4 entities are added in total -- the first 2 are dropped and the last 2 remain. This should prevent off by 1 bugs.

jgracenin · 2018-07-12T12:54:04Z

Hey,

I had one service with a very long running stream and saw 15GB+ of message events in /debug/pprof/heap :) . I suppose I should be using gRPC's MAX_CONNECTION_AGE at some point: https://github.com/grpc/proposal/blob/master/A9-server-side-conn-mgt.md

I see that this already be in progress (#401) so feel free to close if that's the case.

basvanbeek

I'll let others chime in too...

basvanbeek · 2018-07-12T12:57:45Z

trace/trace.go

@@ -110,6 +111,9 @@ const (
 	SpanKindClient
 )

+// DefaultBufferLimit is the default value for trace.StartOptions.BufferLimit.
+const DefaultBufferLimit = 1000


I'm not sure if limits for annotations, message events and links should have the same upper limit. I expect links to contain much less items then for instance annotations so probably should have a lower one.

Yeah, I suppose I was just trying to put a cap on the current long-lived stream memory leak, but we should think it through a bit more.

Your suggestion is pretty easy to implement, but I'll just leave it as is until others chime in (or have a different suggestion altogether).

I think as long as we have sensible defaults for these 3 options (so the client doesn't need to always specify 3 options), then I wouldn't mind having all 3.

I'd also be in favor of whatever the other language implementations are doing (or the spec) to keep the behavior consistent, but I haven't looked that up yet.

Let's follow the spec limits for each type:
https://github.com/census-instrumentation/opencensus-specs/blob/master/trace/TraceConfig.md

basvanbeek · 2018-07-12T13:01:27Z

trace/trace.go

+	// BufferLimit makes new spans with a custom buffer limit.
+	// This limits variable span data: Message Events, Links, and Annotations.
+	// The default is 1000 (trace.DefaultBufferLimit) and the minimum is 1.
+	BufferLimit int


As with the above mentioned upper limits I also think we should be careful with setting the bottom limit. Where it could be sensible for links to have a lower limit of 1 (or even 0) it probably is a bad idea to have one as low as this for annotations or message events.

My expectation was: only the most recent message events would be recorded / exported, even if it was just 1. But it sounds like I might be mistaken here (I'm not very familiar with the internals).

If we end up doing different floors, then we may need to validate the options (instead of just silently fixing it within the option). I was debating that already with the shared buffer limit, but it's a breaking change and makes it less convenient to use. Something like this:

ocsh, err := ocgrpc.NewServerHandler(...trace.StartOptions)

(and a drawback: the ServerHandler.IsPublicEndPoint option isn't a trace.StartOption)

According to the spec we should have a different limit for each: https://github.com/census-instrumentation/opencensus-specs/blob/master/trace/TraceConfig.md

There is an issue to add to StartOptions #670

I do not think we should enforce a lower limit at all. Anything 0 or less should mean "drop immediately".

Hey, I have an updated CL ready. I'd like to clarify one thing before sending it out.

The spec refers to a global trace config (allowing global overrides). It looks like this is what Java/C++ does today as well.

Are the per-span overrides in addition to the global default overrides or do they replace the global default overrides altogether?

I assumed it was in addition and ended up adding a GlobalOption variadic option type for trace.ApplyConfig. I don't mind removing this if you don't want global overrides. The signature looks like: type GlobalOption func(*Config).

Here's how it works:

global var config is set with defaults per the spec

trace.ApplyConfig rolls variadic GlobalOptions on top of that (if any)

trace.StartSpan rolls variadic StartOptions on top of that (if any)

unit test added to cover each scenario

This doesn't break trace.ApplyConfig's API, but I couldn't use the required config struct arg (since it's ambiguous if the integers were set or not (due to the zero value for that type). If we move forward with this change, we may want to deprecate the required config struct arg at a later time (I know it's used in a lot of places though).

I don't think we need global overrides. Having three levels of overrides sounds like going too far. I think its enough to have global defaults that can be changed by trace.ApplyConfig and per-Span values.

We can always add the "panic level" later if needed.

Interesting, I've been referring to a "global override" as something that overrides/changes global defaults with trace.ApplyConfig. Naming things is hard :)

So, we're in agreement then and I've posted my updated commit.

However, trace.ApplyConfig's existing implementation (coupled with limit values have meaning when they're <= 0) still makes this trickier than it seems due to Go's handling of zero values. I'll start a comment thread over there.

basvanbeek · 2018-07-12T13:04:10Z

trace/trace.go

@@ -340,6 +361,10 @@ func (s *Span) lazyPrintfInternal(attributes []Attribute, format string, a ...in
 		m = make(map[string]interface{})
 		copyAttributes(m, attributes)
 	}
+	if l := len(s.data.Annotations); l > 0 && l >= s.bufferLimit {


not all annotations are equal. especially once we start to have common annotations which have global meaning or even have annotations which have consumer platform meaning we need to be able to whitelist these so they don't get lost by tags of lesser importance.

I think we need some sort of "must keep" list that is configurable and probably have a list of system annotations that should never be removed.

Interesting, I didn't know this was in the works.

Sounds like the "must keep" annotations should be stored in a separate slice, but that would require other changes. SpanData could have an Annotations() method that merges the separate annotation slices together (and maybe a Kind enum field -- system/user/bulk should be in each one). I suppose the individual slices could still be exported alongside the merge helper method, though.

Regardless, maybe we should consider doing two commits for this (global / simple limits first, classified ones later)? The message events leak in particular is fairly serious for anyone that has a long lived stream.

I would leave this to a future PR once we have a concept of annotation priority.

Done. Annotation limit removed for now (TODO put in place).

basvanbeek · 2018-07-12T13:04:54Z

trace/trace.go

@@ -393,6 +422,10 @@ func (s *Span) AddMessageSendEvent(messageID, uncompressedByteSize, compressedBy
 	}
 	now := time.Now()
 	s.mu.Lock()
+	if l := len(s.data.MessageEvents); l > 0 && l >= s.bufferLimit {


same as my comment on annotations

I'm not sure if you mean a separate limit for message events (now implemented) or separate limits within message events like annotation priorities (is that also happening?)

rakyll · 2018-07-13T20:32:22Z

Can we discuss changed like this on the specs first? I'd expect all language implementations have support for this, especially if we are going to introduce new APIs. https://github.com/census-instrumentation/opencensus-specs

jgracenin · 2018-07-13T21:34:58Z

Good idea. census-instrumentation/opencensus-specs/issues/138

semistrict

I think we need to have separate limits to be consistent with the spec and the existing Java implementation.

semistrict · 2018-07-16T19:38:04Z

trace/export.go

+	// The count of all span.bufferLimit overflows.
+	// See trace.WithBufferLimit for more info.
+	// TODO: This is not currently exported anywhere (e.g. tracez page).
+	DroppedAnnotations   int


Would it be possible to record these using stats.Record instead?

Added something to specs to this effect: https://github.com/census-instrumentation/opencensus-specs/blob/master/trace/TraceConfig.md

(Totally optional IMO, we can do it in a follow up if you like)

Sure, I'll do this in a follow-up right after this (updated the TODO).

semistrict · 2018-07-16T19:39:15Z

trace/trace.go

@@ -110,6 +111,9 @@ const (
 	SpanKindClient
 )

+// DefaultBufferLimit is the default value for trace.StartOptions.BufferLimit.
+const DefaultBufferLimit = 1000


Let's follow the spec limits for each type:
https://github.com/census-instrumentation/opencensus-specs/blob/master/trace/TraceConfig.md

semistrict · 2018-07-16T19:41:34Z

trace/trace.go

+	// BufferLimit makes new spans with a custom buffer limit.
+	// This limits variable span data: Message Events, Links, and Annotations.
+	// The default is 1000 (trace.DefaultBufferLimit) and the minimum is 1.
+	BufferLimit int


According to the spec we should have a different limit for each: https://github.com/census-instrumentation/opencensus-specs/blob/master/trace/TraceConfig.md

There is an issue to add to StartOptions #670

semistrict · 2018-07-16T19:43:03Z

trace/trace.go

+	// BufferLimit makes new spans with a custom buffer limit.
+	// This limits variable span data: Message Events, Links, and Annotations.
+	// The default is 1000 (trace.DefaultBufferLimit) and the minimum is 1.
+	BufferLimit int


I do not think we should enforce a lower limit at all. Anything 0 or less should mean "drop immediately".

semistrict · 2018-07-16T19:43:34Z

trace/trace.go

@@ -340,6 +361,10 @@ func (s *Span) lazyPrintfInternal(attributes []Attribute, format string, a ...in
 		m = make(map[string]interface{})
 		copyAttributes(m, attributes)
 	}
+	if l := len(s.data.Annotations); l > 0 && l >= s.bufferLimit {


I would leave this to a future PR once we have a concept of annotation priority.

semistrict · 2018-07-16T19:46:26Z

trace/trace.go

@@ -356,6 +381,10 @@ func (s *Span) printStringInternal(attributes []Attribute, str string) {
 		a = make(map[string]interface{})
 		copyAttributes(a, attributes)
 	}
+	if l := len(s.data.Annotations); l > 0 && l >= s.bufferLimit {
+		s.data.Annotations = s.data.Annotations[1:]


I think doing it like this will cause extra allocation every time you exceed the limit because you are always adding to the end of the slice but removing from the beginning. While this is an improvement on the current situation (memory leak) and I am happy to have it like this for now, something to consider would be to replace this with a circular buffer of fixed size once you reach the maximum.

Ah, good catch. The underlying array in the slice is still subject to re-allocation with this. Ring buffer sounds like a good idea. I'm not sure if we should have an interface{} based ring or separate ones for each type. If Go had generics, this would be easier to do.

Another trick we could do: when we hit max capacity, we keep overwriting the last event (we'd also get the first and last events this way). I think this may confuse people though.

I'd say we leave it as is and open up a performance issue to implement a ring buffer.

rakyll · 2018-07-18T16:23:05Z

trace/export.go

@@ -73,4 +73,11 @@ type SpanData struct {
 	Status
 	Links           []Link
 	HasRemoteParent bool
+
+	// The count of all span.bufferLimit overflows.


golint your code.

// DroppedAnnotations represents all the annotations dropped
// due to the annotations limit.
DroppedAnnotations int

Done. I'm a Xoogler that misses the Critique golint badges.

rakyll · 2018-07-18T16:23:13Z

trace/export.go

+	// See trace.WithBufferLimit for more info.
+	// TODO: This is not currently exported anywhere (e.g. tracez page).
+	DroppedAnnotations   int
+	DroppedMessageEvents int


rakyll · 2018-07-18T16:23:20Z

trace/export.go

+	// TODO: This is not currently exported anywhere (e.g. tracez page).
+	DroppedAnnotations   int
+	DroppedMessageEvents int
+	DroppedLinks         int


rakyll · 2018-07-18T16:24:34Z

trace/trace.go

@@ -110,6 +111,9 @@ const (
 	SpanKindClient
 )

+// DefaultBufferLimit is the default value for trace.StartOptions.BufferLimit.
+const DefaultBufferLimit = 1000


I think we need to be consistent and allow user to override this default via trace.ApplyConfig. It is not represented in the specs and I filed census-instrumentation/opencensus-specs#147 to discuss.

We are not sure if user should change the defaults right now. We shouldn't export this constant.

It seems we've decided to allow trace.ApplyConfig updates and per-span StartOption updates now.

To your other point: I usually export default consts so the client can use them as defaults in their runtime flags if they want (if you feel strongly about this, I could unexport them).

rakyll · 2018-07-18T16:25:34Z

trace/trace.go

+	return func(o *StartOptions) {
+		o.BufferLimit = limit
+		if o.BufferLimit <= 0 {
+			o.BufferLimit = 1


it should be the default not 1.

We've decided on a different strategy (per @Ramonza). The client can pass anything in. If it's <= 0, then that trace type is disabled. I think it simplifies things.

rakyll · 2018-07-18T16:29:43Z

trace/trace.go

 // StartSpan starts a new child span of the current span in the context. If
 // there is no span in the context, creates a new trace and span.
 //
 // Returned context contains the newly created span. You can use it to
 // propagate the returned span in process.
 func StartSpan(ctx context.Context, name string, o ...StartOption) (context.Context, *Span) {
-	var opts StartOptions
+	opts := StartOptions{BufferLimit: DefaultBufferLimit}


Don't set the default here.

In startSpanInternal, set the default if opts.BufferLimit is zero.

This was re-worked a bit from the other changes.

Defaults can now be changed via trace.ApplyConfig and can also be <= 0. If it's <= 0, it means disabled, so we can't reset to the default if it's currently 0.

This involves layering / rolling the opts. I decided to to this all in startSpanInternal to simplify it -- the exported functions weren't actually doing anything with the opts other than building them and passing them to startSpanInternal.

rakyll · 2018-07-18T16:29:48Z

trace/trace.go

@@ -174,7 +195,7 @@ func StartSpan(ctx context.Context, name string, o ...StartOption) (context.Cont
 // Returned context contains the newly created span. You can use it to
 // propagate the returned span in process.
 func StartSpanWithRemoteParent(ctx context.Context, name string, parent SpanContext, o ...StartOption) (context.Context, *Span) {
-	var opts StartOptions
+	opts := StartOptions{BufferLimit: DefaultBufferLimit}


See previous comment on line 175.

rakyll · 2018-07-18T16:51:09Z

trace/trace.go

@@ -110,6 +111,9 @@ const (
 	SpanKindClient
 )

+// DefaultBufferLimit is the default value for trace.StartOptions.BufferLimit.
+const DefaultBufferLimit = 1000


We are not sure if user should change the defaults right now. We shouldn't export this constant.

rakyll · 2018-07-18T16:52:06Z

trace/trace.go

@@ -110,6 +111,9 @@ const (
 	SpanKindClient
 )

+// DefaultBufferLimit is the default value for trace.StartOptions.BufferLimit.
+const DefaultBufferLimit = 1000


The spec have different limits for each entities. Attributes: 32, Message events: 128, ...

https://github.com/census-instrumentation/opencensus-specs/blob/master/trace/TraceConfig.md

jgracenin · 2018-07-18T23:35:16Z

Hi @rakyll,

Sorry for the confusion, I didn't push anything new since the new spec was published / @Ramonza's initial review on Monday. Most of these changes are already implemented, but I'll double check anything you pointed out as well.

I added a question in a comment above (which caused the notification), I'll just paste it again here.

Though, I think you just answered no to this with your "We are not sure if user should change the defaults right now" comment.

Hey, I have an updated CL ready. I'd like to clarify one thing before sending it out.

The spec refers to a global trace config (allowing global overrides). It looks like this is what Java/C++ does today as well.

Are the per-span overrides in addition to the global default overrides or do they replace the global default overrides altogether?

I assumed it was in addition and ended up adding a GlobalOption variadic option type for trace.ApplyConfig. I don't mind removing this if you don't want global overrides. The signature looks like: type GlobalOption func(*Config).

Here's how it works:

global var config is set with defaults per the spec
trace.ApplyConfig rolls variadic GlobalOptions on top of that (if any)
trace.StartSpan rolls variadic StartOptions on top of that (if any)
unit test added to cover each scenario

This doesn't break trace.ApplyConfig's API, but I couldn't use the required config struct arg (since it's ambiguous if the integers were set or not (due to the zero value for that type). If we move forward with this change, we may want to deprecate the required config struct arg at a later time (I know it's used in a lot of places though).

This applies limits to span data entities that are slices: Attributes, Message Events, and Links. The limits are default per the spec and can be globally changed with trace.ApplyConfig. The limits can also be changed per-span when creating a new span with one or more trace.StartOption. At the limit, it pops the oldest sample off prior to appending the new sample. Each test ensures 4 entities are added in total -- the first 2 are dropped and the last 2 remain. This should prevent off by 1 bugs.

jgracenin

PTAL

The default values were updated per the new spec and trace.ApplyConfig + StartOptions can change them.

I noticed I missed an attribute limit, so I've added one. If that is also getting priorities I can remove it,

jgracenin · 2018-07-20T14:11:59Z

trace/config.go

 }

 // ApplyConfig applies changes to the global tracing configuration.
 //
 // Fields not provided in the given config are going to be preserved.
-func ApplyConfig(cfg Config) {
+func ApplyConfig(cfg Config, o ...GlobalOption) {


This is where it gets tricky:

With the current trace.ApplyConfig implementation:

cfg is a required parameter and is expected to be a partial update (preserving what was already set).

We want limits set to <= 0 to mean "disabled".

Go's zero value for an int is 0, so if someone changes one limit (or even just the DefaultSampler), the others would incorrectly become disabled.

To handle this, I added in a new variadic GlobalOption (which doesn't break the API), but I think the cfg arg should be deprecated in favor of all variadic options. I'm sure a lot of clients currently use this, though.

Another option: we could keep the cfg struct arg, add *int fields in for the limits, and add a trace.Limit function that takes an int and returns an *int, but I don't like that API as much.

We could keep the type int and make the fields public and just say that if you set 0 it has no effect. Since setting to -1 has exactly the same effect as setting to 0 I don't think we lose anything by doing this.

bogdandrutu · 2018-07-20T14:46:27Z

@jgracenin look what we did in java:
https://github.com/census-instrumentation/opencensus-java/blob/master/api/src/main/java/io/opencensus/trace/config/TraceParams.java

You start from the current config -> get a builder -> apply new mutations (everything else stays the same) -> create the new config -> apply the new config.

semistrict · 2018-07-20T19:29:32Z

@bogdandrutu agree that would be a nicer approach but currently users are not expected to call any function to construct a trace.Config so there is no opportunity to set defaults.

semistrict · 2018-07-20T19:30:10Z

trace/config.go

 }

 // ApplyConfig applies changes to the global tracing configuration.
 //
 // Fields not provided in the given config are going to be preserved.
-func ApplyConfig(cfg Config) {
+func ApplyConfig(cfg Config, o ...GlobalOption) {


We could keep the type int and make the fields public and just say that if you set 0 it has no effect. Since setting to -1 has exactly the same effect as setting to 0 I don't think we lose anything by doing this.

semistrict · 2018-07-20T19:36:29Z

trace/trace.go

 		return
 	}
 	now := time.Now()
 	s.mu.Lock()
+	if l := len(s.data.MessageEvents); l > 0 && l >= s.maxMessageEvents {
+		s.data.MessageEvents = s.data.MessageEvents[1:]


Ideally once we hit the max number of attributes, we would not allocate any more when you add attributes. I believe as written, we will allocate even when we have reached the maximum.

How about copying the message events to the beginning of the slice:

copy(s.data.MessageEvents[0:l-1], s.data.MessageEvents[1:]) s.data.MessageEvents = s.data.MessageEvents[0:l-1]

Then the subsequent append should never allocate once we reach the max. Would be really awesome to run some benchmarks before and after this change. Not sure any of the existing ones would work since they don't add lots of attributes/events.

semistrict · 2018-07-20T19:36:37Z

trace/trace.go

 		return
 	}
 	now := time.Now()
 	s.mu.Lock()
+	if l := len(s.data.MessageEvents); l > 0 && l >= s.maxMessageEvents {


semistrict · 2018-07-20T19:42:12Z

trace/trace.go

+
+	// The maximum limits for internal span data.
+	// These are set with trace.ApplyConfig and can be overriden by trace.StartOptions.
+	maxAttributes    int


We also need to consider the existing uses of trace.StartOptions struct in oc{http,grpc}.{Client,Server}Handler.

One thing we could do is instead of making these StartOptions, why not just expose them as public fields and allow the users to change them if desired?

I'm also happy to defer the work to add per-Span overrides to a future PR if you'd prefer. I think having the global limits only would be a good start.

semistrict · 2018-07-20T20:09:33Z

trace/config.go

+
+	// The below config options must be set with a GlobalOption.
+	// maxAttributes sets a global limit on the number of attributes.
+	maxAttributes int


I'm not sure these really belong in trace.Config. The simpler thing to do would be to just have them as package-vars. The reason to have them in trace.Config would be to be able to change them at arbitrary times at runtime in a goroutine-safe manner. But I can't really think of a compelling reason you'd want to do that. @rakyll interested to know what do you think of this?

Discussed with @rakyll offline. We think the best approach is to remove the GlobalOption type and instead rely on 0 to mean "don't change" (just like it does for the other fields of Config. If the user wants to not buffer anything (alway drop) they can always set the field to -1 explicitly.

semistrict · 2018-07-20T20:36:40Z

trace/trace.go

 		return
 	}
 	s.mu.Lock()
+	if l := len(s.data.Links); l > 0 && l >= s.maxLinks {
+		s.data.Links = s.data.Links[1:]


basvanbeek reviewed Jul 12, 2018

View reviewed changes

jgracenin mentioned this pull request Jul 13, 2018

Buffer limit API for message events, links, and annotations? census-instrumentation/opencensus-specs#138

Closed

semistrict suggested changes Jul 16, 2018

View reviewed changes

rakyll mentioned this pull request Jul 18, 2018

TraceParams are not mentioning the buffer limit census-instrumentation/opencensus-specs#147

Open

rakyll reviewed Jul 18, 2018

View reviewed changes

jgracenin commented Jul 20, 2018

View reviewed changes

semistrict reviewed Jul 20, 2018

View reviewed changes

trace: add buffer limit #824

Are you sure you want to change the base?

trace: add buffer limit #824

Conversation

jgracenin commented Jul 12, 2018

jgracenin commented Jul 12, 2018

basvanbeek left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

rakyll commented Jul 13, 2018

jgracenin commented Jul 13, 2018

semistrict left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jgracenin commented Jul 18, 2018

jgracenin left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

bogdandrutu commented Jul 20, 2018

semistrict commented Jul 20, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment