type assertion in Execd processor when reading managed process's output fails, and large ILP lines fail to be tokenized

[nitti]

Relevant telegraf.conf

[[processors.execd]]
  command = ["/processor.sh"] # this script should emit a line of ILP longer than 262,144 bytes
  data_format = "influx"

[[inputs.cpu]]
[[inputs.mem]]
[[inputs.disk]]
[[inputs.net]]

[[outputs.file]]
  files = ["stdout"]

Logs from Telegraf

2024-09-19T20:33:23Z I! Loading config: /etc/telegraf/telegraf.conf
2024-09-19T20:33:23Z I! Starting Telegraf 1.32.0 brought to you by InfluxData the makers of InfluxDB
2024-09-19T20:33:23Z I! Available plugins: 235 inputs, 9 aggregators, 32 processors, 26 parsers, 62 outputs, 6 secret-stores
2024-09-19T20:33:23Z I! Loaded inputs: cpu disk mem net
2024-09-19T20:33:23Z I! Loaded aggregators:
2024-09-19T20:33:23Z I! Loaded processors: execd
2024-09-19T20:33:23Z I! Loaded secretstores:
2024-09-19T20:33:23Z I! Loaded outputs: file
2024-09-19T20:33:23Z I! Tags enabled: host=b4bb79fcfb5c
2024-09-19T20:33:23Z I! [agent] Config: Interval:10s, Quiet:false, Hostname:"b4bb79fcfb5c", Flush Interval:10s
2024-09-19T20:33:23Z D! [agent] Initializing plugins
2024-09-19T20:33:23Z W! DeprecationWarning: Value "false" for option "ignore_protocol_stats" of plugin "inputs.net" deprecated since version 1.27.3 and will be removed in 1.36.0: use the 'inputs.nstat' plugin instead for protocol stats
2024-09-19T20:33:23Z D! [agent] Connecting outputs
2024-09-19T20:33:23Z D! [agent] Attempting connection to [outputs.file]
2024-09-19T20:33:23Z D! [agent] Successfully connected to outputs.file
2024-09-19T20:33:23Z I! [processors.execd] Starting process: /Users/67468793/tgraf-debug/processor.sh []
2024-09-19T20:33:23Z D! [agent] Starting service inputs
2024-09-19T20:33:30Z E! [processors.execd] Error reading stdout: bufio.Scanner: token too long
2024-09-19T20:33:33Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:33:43Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:33:53Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:34:03Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:34:13Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:34:23Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:34:33Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:34:43Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:34:53Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:35:03Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:35:13Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:35:23Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:35:33Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:35:43Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:35:50Z D! [inputs.net] Previous collection has not completed; scheduled collection skipped
2024-09-19T20:35:50Z D! [inputs.cpu] Previous collection has not completed; scheduled collection skipped
2024-09-19T20:35:50Z W! [inputs.disk] Collection took longer than expected; not complete after interval of 10s
2024-09-19T20:35:50Z D! [inputs.disk] Previous collection has not completed; scheduled collection skipped
2024-09-19T20:35:50Z W! [inputs.net] Collection took longer than expected; not complete after interval of 10s
2024-09-19T20:35:50Z W! [inputs.cpu] Collection took longer than expected; not complete after interval of 10s
2024-09-19T20:35:53Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:36:00Z D! [inputs.cpu] Previous collection has not completed; scheduled collection skipped
2024-09-19T20:36:00Z D! [inputs.net] Previous collection has not completed; scheduled collection skipped
2024-09-19T20:36:00Z W! [inputs.disk] Collection took longer than expected; not complete after interval of 10s
2024-09-19T20:36:00Z D! [inputs.disk] Previous collection has not completed; scheduled collection skipped
2024-09-19T20:36:00Z W! [inputs.cpu] Collection took longer than expected; not complete after interval of 10s
2024-09-19T20:36:00Z D! [inputs.mem] Previous collection has not completed; scheduled collection skipped
2024-09-19T20:36:00Z W! [inputs.mem] Collection took longer than expected; not complete after interval of 10s
2024-09-19T20:36:00Z W! [inputs.net] Collection took longer than expected; not complete after interval of 10s
^C2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Process /Users/67468793/tgraf-debug/processor.sh exited: signal: interrupt
2024-09-19T20:36:02Z I! [processors.execd] Restarting in 10s...
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z D! [agent] Stopping service inputs
2024-09-19T20:36:02Z D! [agent] Input channel closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z E! [processors.execd] Error in plugin: error writing to process stdin: write |1: file already closed
2024-09-19T20:36:02Z D! [agent] Processor channel closed
2024-09-19T20:36:02Z I! [agent] Hang on, flushing any cached metrics before shutdown
2024-09-19T20:36:02Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2024-09-19T20:36:02Z I! [agent] Stopping running outputs
2024-09-19T20:36:02Z D! [agent] Stopped Successfully

System info

Telegraf 1.32.0, Docker engine 24.0.9 linux/amd64 running on MacOS 14.6.1 arm64 via Colima

Docker

No response

Steps to reproduce

1. Run telegraf with the provided config.
2. Check telegraf output logs. Note error token too long. Data is not emitted from the execd processor.

Expected behavior

The data should be processed using a stream parser. Data should be processed and emitted.

Actual behavior

Error bufio.Scanner: token too long and data is not emitted.

Additional info

issue

In the execd processor plugin, if the managed process emits ILP that exceeds the maximum buffer size of the bufio.Scanner, it fails to parse and emit the data due to the token size exceeding the maximum 262,144 bytes (https://github.com/influxdata/telegraf/blob/v1.32.0/plugins/processors/execd/execd.go#L110-L127). There's a type assertion on the parser at the top of cmdReadOut (https://github.com/influxdata/telegraf/blob/v1.32.0/plugins/processors/execd/execd.go#L105-L108), but in all cases (that I could see), the type of the parser is *models.RunningParser, so the assertion always fails and falls back to using a *bufio.Scanner to tokenize the input. In prior versions of Telegraf, this assertion would succeed and then hand off the input to a *influx.StreamParser which is able to handle large inputs.

The parser is set here: https://github.com/influxdata/telegraf/blob/v1.32.0/config/config.go#L1118. The call to addParser() always returns a *models.RunningParser. This type has a public field Parser which has a reference to the underlying parser: https://github.com/influxdata/telegraf/blob/v1.32.0/models/running_parsers.go#L12

Potentially a fix may look something like:

if runningParser, isRunningParser := e.parser.(*models.RunningParser); isRunningParser {
    if _, isInfluxParser := runningParser.Parser.(*influx.Parser); isInfluxParser {
        e.cmdReadOutStream(out)
        return
    }
}

other info

This is the script (processor.sh as referred to in the Telegraf config) I threw together to emit ILP, it just cats a sample file when run:

#!/bin/sh

terminate() {
    exit 0
}

trap 'terminate' TERM

while IFS= read -r line; do
    cat output.sample
    echo
done

file output.sample should contain one line of ILP data, and its length should exceed 262,144 bytes. example: https://gist.githubusercontent.com/nitti/ac86d986d77d1b2ac6d813fad6f13f5d/raw/758cfa849979b80ff27b45bd0b482b87d8628138/output.sample

Thank you for your time Telegraf team.