Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Composite policy does not observe the policy_order in the config #36955

Open
cancub opened this issue Dec 24, 2024 · 2 comments
Open

Composite policy does not observe the policy_order in the config #36955

cancub opened this issue Dec 24, 2024 · 2 comments
Labels
bug Something isn't working needs triage New item requiring triage processor/tailsampling Tail sampling processor

Comments

@cancub
Copy link

cancub commented Dec 24, 2024

Component(s)

processor/tailsampling

What happened?

Description

Regardless of the order set in composite.policy_order, the actual order of processing is the order in which the subpolicies are defined in composite.composite_sub_policy.

Steps to Reproduce

  1. Build otelcol with tailsamplingprocessor
  2. use a configuration whose policy_order differs from the order of subpolicies in composite_sub_policy
          policy_order:
            - probabilistic-policy
            - always-sample-policy
          composite_sub_policy:
            - name: always-sample-policy
              type: always_sample
            - name: probabilistic-policy
              type: probabilistic
              probabilistic:
                sampling_percentage: 20
          rate_allocation:
            - policy: always-sample-policy
              percent: 10
            - policy: probabilistic-policy
              percent: 90
    
    and set the logs for DEBUG mode to see logs about which policy is being used
    service:
      telemetry:
        logs:
          level: INFO
    
  3. start up the otelcollector and send a bunch of traces in (for example, by using xk6-client-tracing)

Expected Result

The probabilistic subpolicy (PSP) receives the traces first, and any unsampled traces then move on to the always sample subpolicy (ASSP). If a ramping increase of spans/sec is used, we will at first see a 100% sampling rate for this Composite policy followed by an inflection point where the ASSP saturates at 100 spans/sec and 80 % of spans after this point are not sampled. Similarly, when we look at the exporter's spans/sec rate, we can see that there is an inflection at around this time, where the slope of the graph after the inflection is 20% of the slop before.

Logs for PSP seen before any logs for ASSP. For example:

2024-12-24T09:59:08.078-0500	debug	sampling/probabilistic.go:46	Evaluating spans in probabilistic filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "probabilistic"}
2024-12-24T09:59:08.078-0500	debug	sampling/probabilistic.go:46	Evaluating spans in probabilistic filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "probabilistic"}
2024-12-24T09:59:08.078-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T09:59:08.078-0500	debug	sampling/probabilistic.go:46	Evaluating spans in probabilistic filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "probabilistic"}
2024-12-24T09:59:08.078-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
...

2024-12-24T09:59:08.078-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T09:59:08.078-0500	debug	sampling/probabilistic.go:46	Evaluating spans in probabilistic filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "probabilistic"}
2024-12-24T09:59:08.078-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}

Actual Result

The AASP always receives traces, PSP never receives anything. At first we see a 100% sampling rate in a ramping ingress, and then the AASP saturates, and we see the non sampling rate gradually increases. Similarly, we see the exporter's spans/sec rate flatline at 100 spans/sec (the saturation of the AASP).

Logs for ASSP always seen first, PP never seen at all:

2024-12-24T10:01:13.078-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T10:01:13.078-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
...
2024-12-24T10:01:13.079-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}

Collector version

v0.116.0

Environment information

Environment

OS: Ubuntu 22.04
Compiler(if manually compiled): [email protected] go1.23.4

OpenTelemetry Collector configuration

receivers:
  otlp:
    protocols:
      grpc:
        endpoint: "localhost:14317"

processors:
  tail_sampling:
    policies:
      - name: composite-policy
        type: composite
        composite:
          max_total_spans_per_second: 1000
          policy_order:
            - probabilistic-policy
            - always-sample-policy
          composite_sub_policy:
            - name: always-sample-policy
              type: always_sample
            - name: probabilistic-policy
              type: probabilistic
              probabilistic:
                sampling_percentage: 20
          rate_allocation:
            - policy: always-sample-policy
              percent: 10
            - policy: probabilistic-policy
              percent: 90

exporters:
  otlp:
    endpoint: "localhost:4317"
    tls:
      insecure: true
  debug:
    verbosity: detailed

service:
  telemetry:
    logs:
      level: DEBUG
    metrics:
      level: detailed
      readers:
        - pull:
            exporter:
              prometheus:
                host: "0.0.0.0"
                port: 8888
  pipelines:
    traces:
      receivers: [otlp]
      processors: [tail_sampling]
      exporters: [otlp]

Log output

Sampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:03.237-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:03.237-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 0, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:04.238-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:04.238-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 0, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:06.237-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:06.237-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 0, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:07.237-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:07.237-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 0, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:08.237-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:08.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:08.237-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 1, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:09.238-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:09.238-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 0, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:10.237-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:10.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:10.238-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 1, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:11.237-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:11.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:11.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:11.237-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 2, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:12.237-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:12.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:12.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:12.237-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 2, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:13.238-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:13.238-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:13.238-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:13.238-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 2, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:14.237-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:14.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:14.237-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 1, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:15.238-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:15.238-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:15.238-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 1, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:17.237-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:17.237-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 2, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:18.238-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:18.238-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:18.238-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:18.238-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 2, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:19.237-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:19.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:19.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:19.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:19.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:19.237-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 4, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}
2024-12-24T13:16:20.237-0500	debug	[email protected]/processor.go:271	Sampling Policy Evaluation ticked	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces"}
2024-12-24T13:16:20.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:20.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:20.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:20.237-0500	debug	sampling/always_sample.go:29	Evaluating spans in always-sample filter	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "policy": "always_sample"}
2024-12-24T13:16:20.237-0500	debug	[email protected]/processor.go:300	Sampling policy evaluation completed	{"kind": "processor", "name": "tail_sampling", "pipeline": "traces", "batch.len": 6, "sampled": 0, "notSampled": 0, "droppedPriorToEvaluation": 0, "policyEvaluationErrors": 0}

Additional context

There's definitely a space for the policy order inside the config struct:
https://github.com/open-telemetry/opentelemetry-collector-contrib/blob/main/processor/tailsamplingprocessor/config.go#L107

It's just that it's not being referenced anywhere:
https://github.com/search?q=repo%3Aopen-telemetry/opentelemetry-collector-contrib%20PolicyOrder&type=code

And the only test that's using it is just looking at this as an afterthought:

PolicyOrder: []string{"test-composite-policy-1"},

@cancub cancub added bug Something isn't working needs triage New item requiring triage labels Dec 24, 2024
@github-actions github-actions bot added the processor/tailsampling Tail sampling processor label Dec 24, 2024
Copy link
Contributor

Pinging code owners:

See Adding Labels via Comments if you do not have permissions to add labels yourself.

@cancub
Copy link
Author

cancub commented Dec 24, 2024

If we're in agreement that this is indeed a bug, I'm happy to update the code to perform a sorting and add the tests.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working needs triage New item requiring triage processor/tailsampling Tail sampling processor
Projects
None yet
Development

No branches or pull requests

1 participant