External Processor Plugins Loaded But Not Available

[kadaan]

Relevant telegraf.conf:

[[processors.expression]]
  name_override = "foo"

System info:

Telegraf: 1.13.4
OS: Ubuntu 18.04
Go: go version go1.14 linux/amd64

Steps to reproduce:

1. Create external plugin project
2. Build plugins: CGO_ENABLED=1 go build -o /home/kadaan/plugins/telegraf-plugins.so -buildmode=plugin .
3. Build telegraf: CGO_ENABLED=1 go build -tags goplugin -o /home/kadaan/telegraf -ldflags /home/kadaan/go/src/github.com/influxdata/telegraf/cmd/telegraf/telegraf.go
4. Start telegraf: /home/kadaan/telegraf --config /home/kadaan/telegraf.comf --plugin-directory /home/kadaan/plugins --test

Expected behavior:

External plugin should load and be available for use

Actual behavior:

External plugin loads, but cannot be used

Additional info:

Added some logging to telegraf and the external plugin to identify the issue.
In Telegraf I added :

• plugins/processors/registry.go#Add
  • log.Printf("I! [processors] Processors (%v): Adding %s", reflect.ValueOf(Processors).Pointer(), name)
• internal/config/config.go#LoadConfig

  •  log.Printf("I! [config] init started")
     for k, _ := range processors.Processors {
         log.Printf("I! [config]     Processor: %s", k)
     }
    

In my external plugins I added log.Printf("I! [processors.expression] Processors (%v): ", reflect.ValueOf(processors.Processors).Pointer()) to the init function.

The output of this is:

2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding clone
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding converter
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding date
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding enum
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding override
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding parser
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding pivot
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding printer
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding regex
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding rename
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding strings
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding tag_limit
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding topk
2020/03/12 07:13:59 I! [processors] Processors (824634421568): Adding unpivot
2020-03-12T14:13:59Z I! Loading external plugins from: telegraf-plugins
2020-03-12T14:13:59Z I! [processors.expression] init started
2020-03-12T14:13:59Z I! [processors.expression] Processors (824639974256): 
2020-03-12T14:13:59Z I! [processors.expression]    Processor: expression
2020-03-12T14:13:59Z I! [processors.expression] init finish
2020-03-12T14:13:59Z I! Starting Telegraf 1.13.4
2020-03-12T14:13:59Z I! [config] init started
2020-03-12T14:13:59Z I! [config]     Processor: parser
2020-03-12T14:13:59Z I! [config]     Processor: regex
2020-03-12T14:13:59Z I! [config]     Processor: rename
2020-03-12T14:13:59Z I! [config]     Processor: strings
2020-03-12T14:13:59Z I! [config]     Processor: date
2020-03-12T14:13:59Z I! [config]     Processor: enum
2020-03-12T14:13:59Z I! [config]     Processor: printer
2020-03-12T14:13:59Z I! [config]     Processor: tag_limit
2020-03-12T14:13:59Z I! [config]     Processor: clone
2020-03-12T14:13:59Z I! [config]     Processor: converter
2020-03-12T14:13:59Z I! [config]     Processor: pivot
2020-03-12T14:13:59Z I! [config]     Processor: topk
2020-03-12T14:13:59Z I! [config]     Processor: override
2020-03-12T14:13:59Z I! [config]     Processor: unpivot
2020-03-12T14:13:59Z E! [telegraf] Error running agent: Error parsing telegraf.conf, Undefined but requested processor: expression

---

Referred to #7027 to work through getting the plugins to load

[kadaan]

@ssoroka FYI

[ssoroka]

Hey @kadaan,

I tested it locally and I was able to build and run an external processor in 1.13.4 and against master.

Can you share your code for the processor? If anything's sensitive/private, feel free to strip that part out.

[kadaan]

@ssoroka Here is example code that reproduces my issue: https://github.com/kadaan/telegraf-plugin-test

Pull that into your gopath and then run ./build.sh. It will:

1. Get plugin dependencies
2. Build the plugin
3. Pull telegraf
4. Checkout 1.13.4
5. Apply the logging patch
6. Get telegraf dependencies.
7. Compile telegraf
8. Run telegraf

[ssoroka]

Looks like I can replicate this in go 1.14, but not earlier versions of go

[kadaan]

I updated my repo (https://github.com/kadaan/telegraf-plugin-test) with a docker container which sets everything up with go 1.13. I can still repo the issue with:

git clone  https://github.com/kadaan/telegraf-plugin-test
cd telegraf-plugin-test
docker image build -t telegrafplugintest:latest .

...
Step 16/17 : RUN echo "/dist/telegraf --config /dist/telegraf.conf --plugin-directory /dist --test" > /dist/run_telegraf.sh &&     chmod +x /dist/run_telegraf.sh &&     /dist/run_telegraf.sh
 ---> Running in 6fcddb763ddd
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding clone
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding converter
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding date
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding enum
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding override
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding parser
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding pivot
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding printer
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding regex
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding rename
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding strings
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding tag_limit
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding topk
2020/03/12 18:22:55 I! [processors] Processors (824634953376): Adding unpivot
2020-03-12T18:22:55Z I! Loading external plugins from: /dist
2020-03-12T18:22:55Z I! [processors.example] init started
2020-03-12T18:22:55Z I! [processors.example] Processors (824637709152):
2020-03-12T18:22:55Z I! [processors.example]    Processor: example
2020-03-12T18:22:55Z I! [processors.example] init finish
2020-03-12T18:22:55Z I! Starting Telegraf 1.13.4
2020-03-12T18:22:55Z I! [config] init started
2020-03-12T18:22:55Z I! [config]     Processor: strings
2020-03-12T18:22:55Z I! [config]     Processor: topk
2020-03-12T18:22:55Z I! [config]     Processor: unpivot
2020-03-12T18:22:55Z I! [config]     Processor: clone
2020-03-12T18:22:55Z I! [config]     Processor: pivot
2020-03-12T18:22:55Z I! [config]     Processor: printer
2020-03-12T18:22:55Z I! [config]     Processor: regex
2020-03-12T18:22:55Z I! [config]     Processor: converter
2020-03-12T18:22:55Z I! [config]     Processor: enum
2020-03-12T18:22:55Z I! [config]     Processor: rename
2020-03-12T18:22:55Z I! [config]     Processor: date
2020-03-12T18:22:55Z I! [config]     Processor: override
2020-03-12T18:22:55Z I! [config]     Processor: parser
2020-03-12T18:22:55Z I! [config]     Processor: tag_limit
2020-03-12T18:22:55Z E! [telegraf] Error running agent: Error parsing /dist/telegraf.conf, Undefined but requested processor: example
The command '/bin/sh -c echo "/dist/telegraf --config /dist/telegraf.conf --plugin-directory /dist --test" > /dist/run_telegraf.sh &&     chmod +x /dist/run_telegraf.sh &&     /dist/run_telegraf.sh' returned a non-zero code: 1```

[danielnelson]

Might be helpful to check out #7027, we were recently able to get this working with an input plugin.

[ssoroka]

So I managed to get to the bottom of this. The example uses dep, and dep is vendoring Telegraf. As a result, the version the plugin is using is not the same version as the version Telegraf is using, and the processor.Add() function adds it to a separate instance. The fix was to remove the vendor folder and to not vendor Telegraf.

This raises the question "what do you do if you want to manage plugin dependencies with dep"? To that I'd say two things:

• dep is going away in future versions of Telegraf, and we've already removed it in master. Ideally you just don't use it, but that's not an answer for everyone.
• Exclude Telegraf from being managed by dep, or I think you can just delete it from the vendor folder before building the plugin. As long as you've checked out the Telegraf repo and you're building that as well (which is the easiest way to make sure you won't have build inconsistencies between the two), then this should work fine.

TL;DR: don't vendor the Telegraf dependency.

[ssoroka]

I did a bit more digging and this is easier to manage with go modules. Go modules has a go.mod replace directive that lets you say "Don't use the module you downloaded, use the package in my path instead", eg:

replace github.com/influxdata/telegraf => $GO_PATH/src/github.com/influxdata/telegraf

where $GO_PATH is the path to your go folder. eg, /Users/me/go.

This way even if you're running a custom build of Telegraf, you can get the library versions to match exactly, and avoid the above issue (also the "plugin was built with a different version of package" issue).

[kadaan]

@ssoroka @danielnelson Thanks again for all the help.