Add spanmetricsprocessor logic #2012

albertteoh · 2021-01-13T12:10:43Z

Description: Adds spanmetricsprocessor logic as a follow-up to #1917.

Link to tracking Issue: #403

Testing:

Unit and integration tested locally (by adding to cmd/otelcontribcol/components.go).
Performance tested (added metrics key cache to improve performance) and added benchmark function.

Documentation: Add relevant documentation to exported structs and functions.

Signed-off-by: albertteoh <albert.teoh@logz.io>

codecov · 2021-01-13T12:29:02Z

Codecov Report

Merging #2012 (bfee7b8) into master (5010cd7) will increase coverage by 0.06%.
The diff coverage is 100.00%.

@@            Coverage Diff             @@
##           master    #2012      +/-   ##
==========================================
+ Coverage   90.39%   90.45%   +0.06%     
==========================================
  Files         394      394              
  Lines       19347    19459     +112     
==========================================
+ Hits        17489    17602     +113     
+ Misses       1397     1396       -1     
  Partials      461      461

Flag	Coverage Δ
integration	`69.84% <ø> (+0.06%)`	⬆️
unit	`89.24% <100.00%> (+0.06%)`	⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

Impacted Files	Coverage Δ
processor/spanmetricsprocessor/processor.go	`100.00% <100.00%> (ø)`
processor/groupbytraceprocessor/event.go	`96.80% <0.00%> (+0.79%)`	⬆️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 5010cd7...bfee7b8. Read the comment docs.

Signed-off-by: albertteoh <albert.teoh@logz.io>

albertteoh · 2021-01-13T23:04:12Z

The "setup" step failed in CI; I suspect it's flaky. Any chance somebody can rerun this please? Or I'm happy to do it myself if given the permissions to do so; currently the rerun button is disabled for me.

Signed-off-by: albertteoh <albert.teoh@logz.io>

processor/spanmetricsprocessor/metricsdimensions/cache.go

tigrannajaryan · 2021-01-19T20:43:38Z

processor/spanmetricsprocessor/processor.go

+
+		availableMetricsExporters = append(availableMetricsExporters, k.Name())
+
+		p.logger.Info("Looking for spanmetrics exporter from available exporters",


Nit: log.Debug is likely more suitable here.

tigrannajaryan · 2021-01-19T20:45:40Z

processor/spanmetricsprocessor/processor.go

+	p.updateCallMetrics(key)
+	p.lock.Unlock()
+
+	latency := float64(span.EndTime()-span.StartTime()) / float64(time.Millisecond.Nanoseconds())


Suggested change

latency := float64(span.EndTime()-span.StartTime()) / float64(time.Millisecond.Nanoseconds())

latencyInMilliseconds := float64(span.EndTime()-span.StartTime()) / float64(time.Millisecond.Nanoseconds())

processor/spanmetricsprocessor/processor.go

tigrannajaryan · 2021-01-19T20:55:38Z

processor/spanmetricsprocessor/metricsdimensions/cache.go

+// CacheNode represents a node in the Cache Trie.
+type CacheNode struct {
+	children  map[string]*CacheNode
+	metricKey *string


Why is this a pointer and not just a string value?

The default nil pointer is used as a sentinel value to indicate if a dimension node in the trie cache contains the cached metricKey; example use:

https://github.com/open-telemetry/opentelemetry-collector-contrib/pull/2012/files#diff-b91e685e0c165315d86cef17341af406f7fc6cff3e7b7a9e67f006f0f4e63764R96

Do you have any concerns around this approach?

Anything prevents to use the empty string as the sentinel value? That will avoid unnecessary indirection, which results in the string slice header being allocated on the heap instead of passed by value, thus increasing the number of heap allocations and garbage to be collected.

Interesting, I've learnt something new :). Nope, I think using an empty string would be an acceptable sentinel value too; it wouldn't make sense to have an empty metric key.

As above, this may not even be a concern if we no longer need the cache. :)

processor/spanmetricsprocessor/metricsdimensions/cache.go

tigrannajaryan · 2021-01-19T21:00:47Z

processor/spanmetricsprocessor/processor.go

+func (p *processorImp) buildKey(serviceName string, span pdata.Span) (string, error) {
+	d := p.getDimensions(serviceName, span)
+	p.lock.Lock()
+	lastDimension := p.metricsKeyCache.InsertDimensions(d...)


The purpose of metricsKeyCache is not clear to me. Is it done to avoid serializing to json on every buildKey call? Is there any evidence this is less expensive? Also why json? Can we serialize trivially by concatenating dimensions and values sequentially? Would that be less expensive than json and most importantly less expensive than the trie-based cache?

OK, I can see benchmarking of the cache was done, which is good. It is not clear why not use a much simpler serialization instead of json. It may be potentially faster than the cache itself and eliminate the need for the cache.

Good point. The initial reason for marshalling to JSON is because it's convenient to unmarshal to the map representation again as in this line of code then use this map to build the metric labels with dpLatency.LabelsMap().InitFromMap(kmap).

I agree that concatenating dimensions and values sequentially would be a much simpler approach and do away with the complex caching mechanism. I avoided this option initially because I was focusing on the challenges of un/marshalling this concatenated string, but I realized that we could simply use this key to lookup the pre-built map of labels, which is probably what you were thinking of. :)

I'll try it out and benchmark the implementation to understand the performance implication.

processor/spanmetricsprocessor/processor.go

Signed-off-by: albertteoh <albert.teoh@logz.io>

albertteoh · 2021-01-22T23:10:35Z

@tigrannajaryan I believe I've addressed your comments. Good news also is with your proposed approach, there was a 60% performance improvement based on my benchmarks, compared with the original (before any caching) implementation. It's a 45% performance improvement from my more complicated trie-based cache as well :). Thanks again for the great suggestion!

Signed-off-by: albertteoh <albert.teoh@logz.io>

processor/spanmetricsprocessor/processor.go

Signed-off-by: albertteoh <albert.teoh@logz.io>

albertteoh · 2021-01-28T21:50:42Z

@tigrannajaryan please let me know if there are any other issues that I have not addressed.

tigrannajaryan

LGTM. Merging as is, feel free to address the nits in a future PR.

tigrannajaryan · 2021-01-28T23:13:52Z

processor/spanmetricsprocessor/processor.go

+
+func concatDimensionValue(metricKeyBuilder *strings.Builder, value string, prefixSep bool) {
+	// It's worth noting that from pprof benchmarks, WriteString is the most expensive operation of this processor.
+	// Specifically, the need to grow the underlying []byte slice to make room for the appended string.


Nit: we probably can easily have a fairly good idea about the expected size of the final string and can preallocate it. Can be a future improvement.

I did try stringBuilder.Grow(n) to initialize the capacity before concatenating strings, but it seemed to increase CPU time. It seems the larger proportion of time taken in Grow is the creation of a new slice, whereas growing the existing slice seemed to be cheaper; I don't completely understand why tbh.

I've attached screenshots of the flamegraphs in case you were interested.

tigrannajaryan · 2021-01-28T23:15:02Z

processor/spanmetricsprocessor/processor.go

+	index := sort.SearchFloat64s(p.latencyBounds, latencyInMilliseconds)
+
+	p.lock.Lock()
+	key := buildKey(serviceName, span, p.dimensions)


Nit: I think this line can be before the lock, I do not see it touching any shared data.

albertteoh · 2021-01-29T00:36:43Z

@tigrannajaryan thank you for the thorough review. It has definitely made the quality of this component a lot better, and I've learnt a lot along the way. 🙏

I'll address the nit relating to the lock. As for the string builder, I'll leave that for later as I'm not sure if that'll be a quick change.

Signed-off-by: albertteoh <albert.teoh@logz.io> **Description:** Enables the spanmetricsprocessor for use in otel collector configs as a follow-up to #2012. **Link to tracking Issue:** Fixes #403 **Testing:** Integration tested locally against a prebuilt Grafana dashboard to confirm metrics look correct.

**Description:** as discussed in the past, we are moving the tail-based sampling processor to the contrib repository. IMPORTANT: there shouldn't be a release of the collector/contrib until the contrib counterpart is merged! **Link to tracking Issue:** Partially addresses #2020. **Testing:** regular test. **Documentation:** Removed processor from readme. Signed-off-by: Juraci Paixão Kröhling <juraci@kroehling.de>

**Description:** Adds spanmetricsprocessor logic as a follow-up to #1917. **Link to tracking Issue:** #403 **Testing:** - Unit and integration tested locally (by adding to `cmd/otelcontribcol/components.go`). - Performance tested (added metrics key cache to improve performance) and added benchmark function. **Documentation:** Add relevant documentation to exported structs and functions.

Signed-off-by: albertteoh <albert.teoh@logz.io> **Description:** Enables the spanmetricsprocessor for use in otel collector configs as a follow-up to #2012. **Link to tracking Issue:** Fixes #403 **Testing:** Integration tested locally against a prebuilt Grafana dashboard to confirm metrics look correct.

* Interface stability documentation * Update versioning policy * Update CONTRIBUTING * Document how to extend immutable interfaces * Markdown format VERSIONING changes

albertteoh added 4 commits January 12, 2021 16:20

Add processor logic

488352d

Signed-off-by: albertteoh <albert.teoh@logz.io>

Add license

fc11428

Signed-off-by: albertteoh <albert.teoh@logz.io>

Cache metrics dimension key

9e6f5e7

Signed-off-by: albertteoh <albert.teoh@logz.io>

Add metrics dimensions cache

ea25e4f

Signed-off-by: albertteoh <albert.teoh@logz.io>

albertteoh requested a review from a team January 13, 2021 12:10

github-actions bot assigned james-bebbington Jan 13, 2021

Fix linting issues

a8f10a8

Signed-off-by: albertteoh <albert.teoh@logz.io>

albertteoh added 3 commits January 14, 2021 14:51

Add experimental note in README

9fd0b8b

Signed-off-by: albertteoh <albert.teoh@logz.io>

Refactor for readability

2efbee8

Signed-off-by: albertteoh <albert.teoh@logz.io>

Idiomatic logging

73a9ebc

Signed-off-by: albertteoh <albert.teoh@logz.io>

tigrannajaryan reviewed Jan 19, 2021

View reviewed changes

tigrannajaryan self-assigned this Jan 19, 2021

Simplify metric key building

bdd50b8

Signed-off-by: albertteoh <albert.teoh@logz.io>

albertteoh mentioned this pull request Jan 22, 2021

Periodic reset of spanmetricsprocessor metric maps #2179

Closed

Fix lint error

3258722

Signed-off-by: albertteoh <albert.teoh@logz.io>

tigrannajaryan reviewed Jan 25, 2021

View reviewed changes

albertteoh added 2 commits January 26, 2021 17:41

metricKey type and use AttributeValueToString

9a46143

Signed-off-by: albertteoh <albert.teoh@logz.io>

Address review comments

bfee7b8

Signed-off-by: albertteoh <albert.teoh@logz.io>

albertteoh force-pushed the atm-part-1 branch from b3c501f to bfee7b8 Compare January 26, 2021 08:42

This was referenced Jan 26, 2021

Support FindService && FindOperations grafana/tempo#471

Closed

Add support for metrics from traces grafana/agent#357

Closed

Base automatically changed from master to main January 28, 2021 00:57

tigrannajaryan approved these changes Jan 28, 2021

View reviewed changes

tigrannajaryan merged commit 8ca2e9b into open-telemetry:main Jan 28, 2021

albertteoh deleted the atm-part-1 branch January 29, 2021 00:14

albertteoh mentioned this pull request Jan 29, 2021

Enable spanmetricsprocessor component #2225

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add spanmetricsprocessor logic #2012

Add spanmetricsprocessor logic #2012

albertteoh commented Jan 13, 2021

codecov bot commented Jan 13, 2021 •

edited

Loading

albertteoh commented Jan 13, 2021

tigrannajaryan Jan 19, 2021

tigrannajaryan Jan 19, 2021

tigrannajaryan Jan 19, 2021

albertteoh Jan 20, 2021

tigrannajaryan Jan 20, 2021

albertteoh Jan 21, 2021

tigrannajaryan Jan 19, 2021

tigrannajaryan Jan 19, 2021

albertteoh Jan 20, 2021 •

edited

Loading

albertteoh commented Jan 22, 2021 •

edited

Loading

albertteoh commented Jan 28, 2021

tigrannajaryan left a comment

tigrannajaryan Jan 28, 2021

albertteoh Jan 29, 2021

tigrannajaryan Jan 28, 2021

albertteoh commented Jan 29, 2021


		availableMetricsExporters = append(availableMetricsExporters, k.Name())

		p.logger.Info("Looking for spanmetrics exporter from available exporters",

	latency := float64(span.EndTime()-span.StartTime()) / float64(time.Millisecond.Nanoseconds())
	latencyInMilliseconds := float64(span.EndTime()-span.StartTime()) / float64(time.Millisecond.Nanoseconds())

Add spanmetricsprocessor logic #2012

Add spanmetricsprocessor logic #2012

Conversation

albertteoh commented Jan 13, 2021

codecov bot commented Jan 13, 2021 • edited Loading

Codecov Report

albertteoh commented Jan 13, 2021

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

albertteoh Jan 20, 2021 • edited Loading

Choose a reason for hiding this comment

albertteoh commented Jan 22, 2021 • edited Loading

albertteoh commented Jan 28, 2021

tigrannajaryan 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

albertteoh commented Jan 29, 2021

codecov bot commented Jan 13, 2021 •

edited

Loading

albertteoh Jan 20, 2021 •

edited

Loading

albertteoh commented Jan 22, 2021 •

edited

Loading