Skip to content

Commit

Permalink
[pkg/ottl] Add debug logging (open-telemetry#33274)
Browse files Browse the repository at this point in the history
**Description:**
Adds debug logging to `StatementSequence.Execute` to allow printing the
state of the `TransformContext` after each statement.

Example logs:

```
2024-05-28T16:19:29.198-0600    debug   [email protected]/parser.go:265     initial TransformContext        {"kind": "processor", "name": "transform", "pipeline": "logs", "tCtx": {"resource": {"attributes": {}, "dropped_attribute_count": 0}, "instrumentation_scope": {"attributes": {}, "dropped_attribute_count": 0, "name": "", "version": ""}, "log_record": {"attributes": {"log.file.name": "test.log"}, "body": "test", "dropped_attribute_count": 0, "flags": 0, "observed_time_unix_nano": "2024-05-28 22:19:29.098833 +0000 UTC", "severity_number": 0, "severity_text": "", "span_id": "", "time_unix_nano": "1970-01-01 00:00:00 +0000 UTC", "trace_id": ""}, "cache": {}}}
2024-05-28T16:19:29.199-0600    debug   [email protected]/parser.go:268     after transformation    {"kind": "processor", "name": "transform", "pipeline": "logs", "statement": "set(attributes[\"test\"], \"pass\")", "tCtx": {"resource": {"attributes": {}, "dropped_attribute_count": 0}, "instrumentation_scope": {"attributes": {}, "dropped_attribute_count": 0, "name": "", "version": ""}, "log_record": {"attributes": {"log.file.name": "test.log", "test": "pass"}, "body": "test", "dropped_attribute_count": 0, "flags": 0, "observed_time_unix_nano": "2024-05-28 22:19:29.098833 +0000 UTC", "severity_number": 0, "severity_text": "", "span_id": "", "time_unix_nano": "1970-01-01 00:00:00 +0000 UTC", "trace_id": ""}, "cache": {}}}
```

Formatted json

```json
{
    "kind": "processor",
    "name": "transform",
    "pipeline": "logs",
    "statement": "set(attributes[\"test\"], \"pass\")",
    "tCtx": {
        "resource": {
            "attributes": {},
            "dropped_attribute_count": 0
        },
        "instrumentation_scope": {
            "attributes": {},
            "dropped_attribute_count": 0,
            "name": "",
            "version": ""
        },
        "log_record": {
            "attributes": {
                "log.file.name": "test.log",
                "test": "pass"
            },
            "body": "test",
            "dropped_attribute_count": 0,
            "flags": 0,
            "observed_time_unix_nano": "2024-05-28 22:19:29.098833 +0000 UTC",
            "severity_number": 0,
            "severity_text": "",
            "span_id": "",
            "time_unix_nano": "1970-01-01 00:00:00 +0000 UTC",
            "trace_id": ""
        },
        "cache": {}
    }
}
```

**Link to tracking Issue:** <Issue number if applicable>
Related to
open-telemetry#30932
  • Loading branch information
TylerHelmuth committed Jun 10, 2024
1 parent 505332a commit 9396cd8
Show file tree
Hide file tree
Showing 14 changed files with 652 additions and 16 deletions.
27 changes: 27 additions & 0 deletions .chloggen/ottl-debug-statements.yaml
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
# Use this changelog template to create an entry for release notes.

# One of 'breaking', 'deprecation', 'new_component', 'enhancement', 'bug_fix'
change_type: enhancement

# The name of the component, or a single word describing the area of concern, (e.g. filelogreceiver)
component: pkg/ottl

# A brief description of the change. Surround your text with quotes ("") if it needs to start with a backtick (`).
note: Add debug logs to help troubleshoot OTTL statements/conditions

# Mandatory: One or more tracking issues related to the change. You can use the PR number here if no issue exists.
issues: [33274]

# (Optional) One or more lines of additional information to render under the primary note.
# These lines will be padded with 2 spaces and then inserted directly into the document.
# Use pipe (|) for multiline entries.
subtext:

# If your change doesn't affect end users or the exported elements of any package,
# you should instead start your pull request title with [chore] or use the "Skip Changelog" label.
# Optional: The change log or logs in which this entry should be included.
# e.g. '[user]' or '[user, api]'
# Include 'user' if the change is relevant to end users.
# Include 'api' if there is a change to a library API.
# Default: '[user]'
change_logs: []
21 changes: 21 additions & 0 deletions pkg/ottl/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -130,3 +130,24 @@ metrics:
traces:
set(attributes["test-passed"], true) where attributes["target-attribute"] != nil
```

## Troubleshooting

When using OTTL you can enable debug logging in the collector to print out useful information,
such as the current Statement/Condition and the current TransformContext, to help you troubleshoot
why a statement is not behaving as you expect. This feature is very verbose, but provides you an accurate
view into how OTTL views the underlying data.

```yaml
service:
telemetry:
logs:
level: debug
```

```
2024-05-29T16:38:09.600-0600 debug [email protected]/parser.go:265 initial TransformContext {"kind": "processor", "name": "transform", "pipeline": "logs", "TransformContext": {"resource": {"attributes": {}, "dropped_attribute_count": 0}, "scope": {"attributes": {}, "dropped_attribute_count": 0, "name": "", "version": ""}, "log_record": {"attributes": {"log.file.name": "test.log"}, "body": "test", "dropped_attribute_count": 0, "flags": 0, "observed_time_unix_nano": 1717022289500721000, "severity_number": 0, "severity_text": "", "span_id": "", "time_unix_nano": 0, "trace_id": ""}, "cache": {}}}
2024-05-29T16:38:09.600-0600 debug [email protected]/parser.go:268 TransformContext after statement execution {"kind": "processor", "name": "transform", "pipeline": "logs", "statement": "set(resource.attributes[\"test\"], \"pass\")", "condition matched": true, "TransformContext": {"resource": {"attributes": {"test": "pass"}, "dropped_attribute_count": 0}, "scope": {"attributes": {}, "dropped_attribute_count": 0, "name": "", "version": ""}, "log_record": {"attributes": {"log.file.name": "test.log"}, "body": "test", "dropped_attribute_count": 0, "flags": 0, "observed_time_unix_nano": 1717022289500721000, "severity_number": 0, "severity_text": "", "span_id": "", "time_unix_nano": 0, "trace_id": ""}, "cache": {}}}
2024-05-29T16:38:09.600-0600 debug [email protected]/parser.go:268 TransformContext after statement execution {"kind": "processor", "name": "transform", "pipeline": "logs", "statement": "set(instrumentation_scope.attributes[\"test\"], [\"pass\"])", "condition matched": true, "TransformContext": {"resource": {"attributes": {"test": "pass"}, "dropped_attribute_count": 0}, "scope": {"attributes": {"test": ["pass"]}, "dropped_attribute_count": 0, "name": "", "version": ""}, "log_record": {"attributes": {"log.file.name": "test.log"}, "body": "test", "dropped_attribute_count": 0, "flags": 0, "observed_time_unix_nano": 1717022289500721000, "severity_number": 0, "severity_text": "", "span_id": "", "time_unix_nano": 0, "trace_id": ""}, "cache": {}}}
2024-05-29T16:38:09.601-0600 debug [email protected]/parser.go:268 TransformContext after statement execution {"kind": "processor", "name": "transform", "pipeline": "logs", "statement": "set(attributes[\"test\"], true)", "condition matched": true, "TransformContext": {"resource": {"attributes": {"test": "pass"}, "dropped_attribute_count": 0}, "scope": {"attributes": {"test": ["pass"]}, "dropped_attribute_count": 0, "name": "", "version": ""}, "log_record": {"attributes": {"log.file.name": "test.log", "test": true}, "body": "test", "dropped_attribute_count": 0, "flags": 0, "observed_time_unix_nano": 1717022289500721000, "severity_number": 0, "severity_text": "", "span_id": "", "time_unix_nano": 0, "trace_id": ""}, "cache": {}}}
```
Loading

0 comments on commit 9396cd8

Please sign in to comment.