Valid processor config yields unexpected results

[JelleSmet-TomTom]

Component(s)

processor/transform

What happened?

Description

The transform documentation mentions in the Basic Config section that log_statements is a list consisting out of the individual expressions as strings.

This format, at least in my particular test, yields unexpected (and therefor wrong) results. It seems that for every line of the input file, a log is generated but each log has the content of the line of the input.log file

When the same configuration is converted to the advanced configuration style results are correct.

It is unclear where the difference comes from.

Steps to Reproduce

create file input.log with following content:

{"product": {"id": 1}, "proxy": {"id": 2}, "log": "first log"}
{"product": {"id": 10}, "proxy": {"id": 20}, "log": "second log"}
{"product": {"id": 10}, "proxy": {"id": 20}, "log": "third log"}

Apply the below mentioned configuration.

working processor config

Replace the processors section of the broken config with this and the result is what is expected.

processors:
  transform/log:
    error_mode: propagate
    log_statements:
      - statements:
        - merge_maps(log.cache, ParseJSON(log.body), "upsert") where IsMatch(log.body, "^\\{")
        - set(log.body, log.cache["log"])

Expected Result

output.log contains:

{
  "resourceLogs": [
    {
      "resource": {},
      "scopeLogs": [
        {
          "scope": {},
          "logRecords": [
            {
              "observedTimeUnixNano": "1742847852280836180",
              "body": {
                "stringValue": "first log"
              },
              "attributes": [
                {
                  "key": "log.file.name",
                  "value": {
                    "stringValue": "input.log"
                  }
                }
              ],
              "traceId": "",
              "spanId": ""
            },
            {
              "observedTimeUnixNano": "1742847852280843519",
              "body": {
                "stringValue": "second log"
              },
              "attributes": [
                {
                  "key": "log.file.name",
                  "value": {
                    "stringValue": "input.log"
                  }
                }
              ],
              "traceId": "",
              "spanId": ""
            },
            {
              "observedTimeUnixNano": "1742847852280844952",
              "body": {
                "stringValue": "third log"
              },
              "attributes": [
                {
                  "key": "log.file.name",
                  "value": {
                    "stringValue": "input.log"
                  }
                }
              ],
              "traceId": "",
              "spanId": ""
            }
          ]
        }
      ]
    }
  ]
}

Actual Result

output.log contains:

{
  "resourceLogs": [
    {
      "resource": {},
      "scopeLogs": [
        {
          "scope": {},
          "logRecords": [
            {
              "observedTimeUnixNano": "1742846994264031175",
              "body": {
                "stringValue": "third log"
              },
              "attributes": [
                {
                  "key": "log.file.name",
                  "value": {
                    "stringValue": "input.log"
                  }
                }
              ],
              "traceId": "",
              "spanId": ""
            },
            {
              "observedTimeUnixNano": "1742846994264052451",
              "body": {
                "stringValue": "third log"
              },
              "attributes": [
                {
                  "key": "log.file.name",
                  "value": {
                    "stringValue": "input.log"
                  }
                }
              ],
              "traceId": "",
              "spanId": ""
            },
            {
              "observedTimeUnixNano": "1742846994264054274",
              "body": {
                "stringValue": "third log"
              },
              "attributes": [
                {
                  "key": "log.file.name",
                  "value": {
                    "stringValue": "input.log"
                  }
                }
              ],
              "traceId": "",
              "spanId": ""
            }
          ]
        }
      ]
    }
  ]
}

Collector version

v0.120.0 and latest

Environment information

Environment

official docker images

$ docker images
REPOSITORY                             TAG       IMAGE ID       CREATED       SIZE
otel/opentelemetry-collector-contrib   latest    49ab54809761   5 days ago    329MB
otel/opentelemetry-collector-contrib   0.120.0   c67f607546f4   4 weeks ago   315MB

OpenTelemetry Collector configuration

(causes the faulty results)

receivers:
  filelog:
    type: file_input
    include:
      - /input.log
    start_at: beginning

processors:
  transform/log:
    error_mode: propagate
    log_statements:
      - merge_maps(log.cache, ParseJSON(log.body), "upsert") where IsMatch(log.body, "^\\{")
      - set(log.body, log.cache["log"])

exporters:
  file/local:
    path: ./output.log

service:
  pipelines:
    logs:
      receivers:
        - filelog
      processors:
        - transform/log
      exporters:
        - file/local

Log output

n/a

Additional context

No response

[github-actions]

Pinging code owners:

• processor/transform: @TylerHelmuth @kentquirk @bogdandrutu @evan-bradley @edmocosta

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

[edmocosta]

Hi @JelleSmet-TomTom, thank you for reporting, that's indeed an issue with the new basic configuration style and the cache feature. Differently from the advanced mode, the basic configuration style runs each statement for every telemetry data before moving to the next one, which results into the cache being overridden when the data has multiple entries. As an alternative while we don't get it fixed, please use the advanced mode instead.

[odubajDT]

Hey, I would like to look at this issue.

[edmocosta]

Hi @odubajDT, I'm sorry, I forget to assign this issue to myself. I've been working on a solution already and the draft still needs to be discussed and validated with maintainers. Hope you don't mind I take this one. Thanks!

[odubajDT]

Sure no issues, thanks for the info!

[Damian92666]

Hello @JelleSmet-TomTom,

Have you tried the new bug-fixed version of Open Telemetry?
For version 0.127.0 it doesn't work as it should. Can you tell me if it works for you?

Best regards,
Damian

[edmocosta]

Hi @Damian92666, could you please provide more details on that? I would be glad to take a look at it.
Regarding this bug, you can double check it by running the provided example using the 0.127.0 (see), and then comparing it to any <= 0.123.0 result (see). Thanks!

[Damian92666]

Hi @edmocosta,

Thank you for provided examples. You are right. This is working as expected.

I have a different issue, with resource attributes, but I think we have an answer here:

see

To avoid mixing labels, we should only use resource-related labels (like hostname, env_name...).

Thanks,
Damian

[edmocosta]

Thanks for confirming @Damian92666! BTW, if you need to set resource attributes using different log record data, you can enable the transform.flatten.logs feature gate, and set flatten_data: true, so the transform processor will provide each log record with a distinct copy of its resource and scope (see example).

[Damian92666]

Thank you @edmocosta! It works! This is what I wanted to see.. :)