Skip to content

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

@cancub

Description

@cancub

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"},

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions