Plugin not working

[scrazy77]

Welcome!

• Yes, I've searched similar issues on GitHub and didn't find any.
• Yes, I've searched similar issues on the Traefik community forum and didn't find any.

What did you do?

I tested custom plugin in EKS traefik deployment, but it's not working.
helm chart config:

additionalArguments: 
  - "--log.level=DEBUG"
  - "--experimental.plugins.example.modulename=github.com/traefik/plugindemo"
  - "--experimental.plugins.example.version=v0.2.2"

the pod error message:

time="2022-11-08T15:42:07Z" level=debug msg="loading of plugin: example: github.com/traefik/plugindemo@v0.2.2"
time="2022-11-08T15:42:12Z" level=error msg="Plugins are disabled because an error has occurred." error="failed to download plugin github.com/traefik/plugindemo: failed to call service: Get \"https://plugins.traefik.io/public/download/github.com/traefik/plugindemo/v0.2.2\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)"

the network is ok, I can wget https://plugins.traefik.io/public/download/github.com/traefik/plugindemo/v0.2.2 in the pod

Then I test different version of traefik docker image:

Custom plugin working fine:
v2.7.0
v2.8.0
v2.8.1
v2.8.3

Custom plugin not working:
v2.8.4
v2.8.8
v2.9.4

Conclusion:
The latest working version is Traefik v2.8.3

What did you see instead?

time="2022-11-08T15:42:07Z" level=debug msg="loading of plugin: example: github.com/traefik/plugindemo@v0.2.2"
time="2022-11-08T15:42:12Z" level=error msg="Plugins are disabled because an error has occurred." error="failed to download plugin github.com/traefik/plugindemo: failed to call service: Get \"https://plugins.traefik.io/public/download/github.com/traefik/plugindemo/v0.2.2\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)"

What version of Traefik are you using?

v2.9.4

What is your environment & configuration?

additionalArguments: 
  - "--log.level=DEBUG"
  - "--experimental.plugins.example.modulename=github.com/traefik/plugindemo"
  - "--experimental.plugins.example.version=v0.2.2"

If applicable, please paste the log output in DEBUG level

time="2022-11-08T15:42:07Z" level=debug msg="loading of plugin: example: github.com/traefik/plugindemo@v0.2.2"
time="2022-11-08T15:42:12Z" level=error msg="Plugins are disabled because an error has occurred." error="failed to download plugin github.com/traefik/plugindemo: failed to call service: Get \"https://plugins.traefik.io/public/download/github.com/traefik/plugindemo/v0.2.2\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)"

[rtribotte]

Hello @scrazy77,

Thanks for your interest in Traefik!

To debug this further, can you share with us the version of the HelmChart you are using?
Can you also share the command and the values.yaml file?

[scrazy77]

Chart.yaml

apiVersion: v2
name: traefik
description: A Traefik based Kubernetes ingress controller
type: application
version: 18.3.0
appVersion: 2.9.4
keywords:
  - traefik
  - ingress
home: https://traefik.io/
sources:
  - https://github.com/traefik/traefik
  - https://github.com/traefik/traefik-helm-chart
maintainers:
  - name: emilevauge
    email: emile@vauge.com
  - name: dtomcej
    email: daniel.tomcej@gmail.com
  - name: ldez
    email: ldez@traefik.io
  - name: mloiseleur
    email: michel.loiseleur@traefik.io
  - name: charlie-haley
    email: charlie.haley@traefik.io
icon: https://raw.githubusercontent.com/traefik/traefik/v2.3/docs/content/assets/img/traefik.logo.png
annotations:
  artifacthub.io/changes: |
    - ⬆️  Update Traefik appVersion to 2.9.4

values.yaml

# Default values for Traefik
image:
  name: traefik
  # defaults to appVersion
  tag: v2.9.4
  pullPolicy: IfNotPresent
hub:
  enabled: false
deployment:
  enabled: true
  kind: Deployment
  replicas: 2
  terminationGracePeriodSeconds: 60
  minReadySeconds: 0
  annotations: {}
  labels: {}
  podAnnotations: {}
  podLabels: {}
  additionalContainers: []
  additionalVolumes: []
  initContainers: []
  shareProcessNamespace: false
  imagePullSecrets: []
  lifecycle: {}
podDisruptionBudget:
  enabled: false
ingressClass:
  enabled: false
  isDefaultClass: false
experimental:
  plugins:
    enabled: true 
    plugin-requestid:
      modulename: github.com/pipe01/plugin-requestid
      version: v1.0.0
    traefikxrequeststart:
      modulename: github.com/EasySolutionsIO/traefikxrequeststart
      version: v0.0.3    
  kubernetesGateway:
    enabled: false
    gateway:
      enabled: true
ingressRoute:
  dashboard:
    enabled: true
    annotations: {}
    labels: {}
    entryPoints: ["traefik"]

rollingUpdate:
  maxUnavailable: 0
  maxSurge: 1
readinessProbe:
  failureThreshold: 1
  initialDelaySeconds: 2
  periodSeconds: 10
  successThreshold: 1
  timeoutSeconds: 2

livenessProbe:
  failureThreshold: 3
  initialDelaySeconds: 2
  periodSeconds: 10
  successThreshold: 1
  timeoutSeconds: 2
providers:
  kubernetesCRD:
    enabled: true
    allowCrossNamespace: false
    allowExternalNameServices: true
    allowEmptyServices: false
    namespaces:
      - "default"
      - "traefik"

  kubernetesIngress:
    enabled: true
    allowExternalNameServices: false
    allowEmptyServices: false
    namespaces: 
      - "default"
      - "traefik"    
    publishedService:
      enabled: false
volumes: []
additionalVolumeMounts: []
logs:
  general:
    level: ERROR
  access:
    enabled: true
    filters: {}
    fields:
      general:
        defaultmode: keep
        names: {}
      headers:
        defaultmode: drop
        names: {}
metrics:
  prometheus:
    entryPoint: metrics
tracing: {}
globalArguments:
  - "--global.checknewversion"
additionalArguments: 
  - "--log.level=DEBUG"
  - "--experimental.plugins.plugin-requestid.modulename=github.com/pipe01/plugin-requestid"
  - "--experimental.plugins.plugin-requestid.version=v1.0.0"
  - "--experimental.plugins.traefikxrequeststart.modulename=github.com/EasySolutionsIO/traefikxrequeststart"
  - "--experimental.plugins.traefikxrequeststart.version=v0.0.3"
env: []
envFrom: []
ports:
  traefik:
    port: 9000
    expose: false
    exposedPort: 9000
    protocol: TCP
  web:
    port: 8000
    expose: true
    exposedPort: 80
    protocol: TCP
  websecure:
    port: 8443
    expose: true
    exposedPort: 443
    protocol: TCP
    http3:
      enabled: false
    tls:
      enabled: true
      options: ""
      certResolver: ""
      domains: []
    middlewares: []
  metrics:
    port: 9100
    expose: false
    exposedPort: 9100
    protocol: TCP
tlsOptions: {}
tlsStore: {}
service:
  enabled: true
  single: true
  type: LoadBalancer
  annotationsTCP: {}
  annotationsUDP: {}
  labels: {}
  spec: {}
  loadBalancerSourceRanges: []
  externalIPs: []
autoscaling:
  enabled: false
persistence:
  enabled: false
  name: data
  accessMode: ReadWriteOnce
  size: 128Mi
  path: /data
  annotations: {}
certResolvers: {}
hostNetwork: false
rbac:
  enabled: true
  namespaced: false
podSecurityPolicy:
  enabled: false
serviceAccount:
  name: ""
serviceAccountAnnotations: {}
resources: {}
nodeSelector: {}
tolerations: []
topologySpreadConstraints: []
securityContext:
  capabilities:
    drop: [ALL]
  readOnlyRootFilesystem: true
  runAsGroup: 65532
  runAsNonRoot: true
  runAsUser: 65532

podSecurityContext:
  fsGroup: 65532
extraObjects: []

[rtribotte]

Hello @scrazy77,

Thanks for sharing! So far, I should say that the issue looks to be related (only) to a network issue. Unfortunately, this means that we will probably not be able to reproduce it.

Thus, you are mentioning having this error message (Plugins are disabled because an error has occurred) only starting with the v2.8.4.
Can you please share with us the full debug logs trace of execution with the v2.8.3?

[scrazy77]

v2.8.3

2 plugins:

• plugin-requestid: github.com/pipe01/plugin-requestid@v1.0.0"
• traefikxrequeststart: github.com/EasySolutionsIO/traefikxrequeststart@v0.0.3"

plugin load without errors.

> kubectl logs traefik-78997fb4d8-g2j2n -n traefik
time="2022-11-17T02:36:52Z" level=info msg="Configuration loaded from flags."
time="2022-11-17T02:36:52Z" level=info msg="Traefik version 2.8.3 built on 2022-08-12T14:24:34Z"
time="2022-11-17T02:36:52Z" level=debug msg="Static configuration loaded {\"global\":{\"checkNewVersion\":true},\"serversTransport\":{\"maxIdleConnsPerHost\":200},\"entryPoints\":{\"metrics\":{\"address\":\":9100/tcp\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":\"10s\"},\"respondingTimeouts\":{\"idleTimeout\":\"3m0s\"}},\"forwardedHeaders\":{},\"http\":{},\"http2\":{\"maxConcurrentStreams\":250},\"udp\":{\"timeout\":\"3s\"}},\"traefik\":{\"address\":\":9000/tcp\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":\"10s\"},\"respondingTimeouts\":{\"idleTimeout\":\"3m0s\"}},\"forwardedHeaders\":{},\"http\":{},\"http2\":{\"maxConcurrentStreams\":250},\"udp\":{\"timeout\":\"3s\"}},\"web\":{\"address\":\":8000/tcp\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":\"10s\"},\"respondingTimeouts\":{\"idleTimeout\":\"3m0s\"}},\"forwardedHeaders\":{},\"http\":{},\"http2\":{\"maxConcurrentStreams\":250},\"udp\":{\"timeout\":\"3s\"}},\"websecure\":{\"address\":\":8443/tcp\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":\"10s\"},\"respondingTimeouts\":{\"idleTimeout\":\"3m0s\"}},\"forwardedHeaders\":{},\"http\":{\"tls\":{}},\"http2\":{\"maxConcurrentStreams\":250},\"udp\":{\"timeout\":\"3s\"}}},\"providers\":{\"providersThrottleDuration\":\"2s\",\"kubernetesIngress\":{\"namespaces\":[\"default\",\"traefik\"]},\"kubernetesCRD\":{\"namespaces\":[\"default\",\"traefik\"],\"allowExternalNameServices\":true}},\"api\":{\"dashboard\":true},\"metrics\":{\"prometheus\":{\"buckets\":[0.1,0.3,1.2,5],\"addEntryPointsLabels\":true,\"addServicesLabels\":true,\"entryPoint\":\"metrics\"}},\"ping\":{\"entryPoint\":\"traefik\",\"terminatingStatusCode\":503},\"log\":{\"level\":\"DEBUG\",\"format\":\"common\"},\"accessLog\":{\"format\":\"common\",\"filters\":{},\"fields\":{\"defaultMode\":\"keep\",\"headers\":{\"defaultMode\":\"drop\"}}},\"pilot\":{\"dashboard\":true},\"experimental\":{\"plugins\":{\"plugin-requestid\":{\"moduleName\":\"github.com/pipe01/plugin-requestid\",\"version\":\"v1.0.0\"},\"traefikxrequeststart\":{\"moduleName\":\"github.com/EasySolutionsIO/traefikxrequeststart\",\"version\":\"v0.0.3\"}}}}"
time="2022-11-17T02:36:52Z" level=info msg="\nStats collection is disabled.\nHelp us improve Traefik by turning this feature on :)\nMore details on: https://doc.traefik.io/traefik/contributing/data-collection/\n"
time="2022-11-17T02:36:52Z" level=warning msg="Traefik Pilot is deprecated and will be removed soon. Please check our Blog for migration instructions later this year."
time="2022-11-17T02:36:52Z" level=debug msg="loading of plugin: plugin-requestid: github.com/pipe01/plugin-requestid@v1.0.0"
time="2022-11-17T02:36:54Z" level=debug msg="loading of plugin: traefikxrequeststart: github.com/EasySolutionsIO/traefikxrequeststart@v0.0.3"
time="2022-11-17T02:36:55Z" level=debug msg="Configured Prometheus metrics" metricsProviderName=prometheus
time="2022-11-17T02:36:55Z" level=info msg="Starting provider aggregator aggregator.ProviderAggregator"
time="2022-11-17T02:36:55Z" level=debug msg="Starting TCP Server" entryPointName=metrics
time="2022-11-17T02:36:55Z" level=debug msg="Starting TCP Server" entryPointName=traefik
time="2022-11-17T02:36:55Z" level=debug msg="Starting TCP Server" entryPointName=web
time="2022-11-17T02:36:55Z" level=debug msg="Starting TCP Server" entryPointName=websecure
time="2022-11-17T02:36:55Z" level=info msg="Starting provider *traefik.Provider"
time="2022-11-17T02:36:55Z" level=info msg="Starting provider *ingress.Provider"
time="2022-11-17T02:36:55Z" level=debug msg="*traefik.Provider provider configuration: {}"
time="2022-11-17T02:36:55Z" level=debug msg="*ingress.Provider provider configuration: {\"namespaces\":[\"default\",\"traefik\"]}"
time="2022-11-17T02:36:55Z" level=info msg="ingress label selector is: \"\"" providerName=kubernetes
time="2022-11-17T02:36:55Z" level=info msg="Creating in-cluster Provider client" providerName=kubernetes
time="2022-11-17T02:36:55Z" level=info msg="Starting provider *crd.Provider"
time="2022-11-17T02:36:55Z" level=debug msg="*crd.Provider provider configuration: {\"namespaces\":[\"default\",\"traefik\"],\"allowExternalNameServices\":true}"
time="2022-11-17T02:36:55Z" level=info msg="label selector is: \"\"" providerName=kubernetescrd
time="2022-11-17T02:36:55Z" level=info msg="Creating in-cluster Provider client" providerName=kubernetescrd
time="2022-11-17T02:36:55Z" level=info msg="Starting provider *acme.ChallengeTLSALPN"
time="2022-11-17T02:36:55Z" level=debug msg="*acme.ChallengeTLSALPN provider configuration: {}"
time="2022-11-17T02:36:55Z" level=warning msg="ExternalName service loading is enabled, please ensure that this is expected (see AllowExternalNameServices option)" providerName=kubernetescrd
time="2022-11-17T02:36:55Z" level=debug msg="Configuration received: {\"http\":{\"routers\":{\"ping\":{\"entryPoints\":[\"traefik\"],\"service\":\"ping@internal\",\"rule\":\"PathPrefix(`/ping`)\",\"priority\":2147483647},\"prometheus\":{\"entryPoints\":[\"metrics\"],\"service\":\"prometheus@internal\",\"rule\":\"PathPrefix(`/metrics`)\",\"priority\":2147483647}},\"services\":{\"api\":{},\"dashboard\":{},\"noop\":{},\"ping\":{},\"prometheus\":{}},\"models\":{\"websecure\":{\"tls\":{}}},\"serversTransports\":{\"default\":{\"maxIdleConnsPerHost\":200}}},\"tcp\":{},\"udp\":{},\"tls\":{}}" providerName=internal
time="2022-11-17T02:36:55Z" level=debug msg="No default certificate, generating one" tlsStoreName=default
time="2022-11-17T02:36:55Z" level=debug msg="Added outgoing tracing middleware ping@internal" routerName=ping@internal entryPointName=traefik middlewareName=tracing middlewareType=TracingForwarder
time="2022-11-17T02:36:55Z" level=debug msg="Creating middleware" middlewareType=Recovery entryPointName=traefik middlewareName=traefik-internal-recovery
time="2022-11-17T02:36:55Z" level=debug msg="Added outgoing tracing middleware prometheus@internal" entryPointName=metrics routerName=prometheus@internal middlewareName=tracing middlewareType=TracingForwarder
time="2022-11-17T02:36:55Z" level=debug msg="Creating middleware" middlewareName=traefik-internal-recovery middlewareType=Recovery entryPointName=metrics
time="2022-11-17T02:36:55Z" level=debug msg="Creating middleware" entryPointName=traefik middlewareName=metrics-entrypoint middlewareType=Metrics
time="2022-11-17T02:36:55Z" level=debug msg="Creating middleware" entryPointName=web middlewareType=Metrics middlewareName=metrics-entrypoint
time="2022-11-17T02:36:55Z" level=debug msg="Creating middleware" entryPointName=websecure middlewareType=Metrics middlewareName=metrics-entrypoint
time="2022-11-17T02:36:55Z" level=debug msg="Creating middleware" middlewareName=metrics-entrypoint middlewareType=Metrics entryPointName=metrics
time="2022-11-17T02:36:55Z" level=debug msg="Creating middleware" middlewareName=metrics-entrypoint middlewareType=Metrics entryPointName=traefik
time="2022-11-17T02:36:55Z" level=debug msg="Creating middleware" entryPointName=web middlewareName=metrics-entrypoint middlewareType=Metrics
time="2022-11-17T02:36:55Z" level=debug msg="Creating middleware" middlewareType=Metrics middlewareName=metrics-entrypoint entryPointName=websecure
time="2022-11-17T02:36:55Z" level=debug msg="Creating middleware" entryPointName=metrics middlewareName=metrics-entrypoint middlewareType=Metrics

[scrazy77]

v2.8.4

Plugins are disabled because an error has occurred.

> kubectl logs traefik-78cbff6d78-6k787 -n traefik
time="2022-11-16T06:25:25Z" level=info msg="Configuration loaded from flags."
time="2022-11-16T06:25:25Z" level=info msg="Traefik version 2.8.4 built on 2022-09-02T14:42:59Z"
time="2022-11-16T06:25:25Z" level=debug msg="Static configuration loaded {\"global\":{\"checkNewVersion\":true},\"serversTransport\":{\"maxIdleConnsPerHost\":200},\"entryPoints\":{\"metrics\":{\"address\":\":9100/tcp\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":\"10s\"},\"respondingTimeouts\":{\"idleTimeout\":\"3m0s\"}},\"forwardedHeaders\":{},\"http\":{},\"http2\":{\"maxConcurrentStreams\":250},\"udp\":{\"timeout\":\"3s\"}},\"traefik\":{\"address\":\":9000/tcp\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":\"10s\"},\"respondingTimeouts\":{\"idleTimeout\":\"3m0s\"}},\"forwardedHeaders\":{},\"http\":{},\"http2\":{\"maxConcurrentStreams\":250},\"udp\":{\"timeout\":\"3s\"}},\"web\":{\"address\":\":8000/tcp\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":\"10s\"},\"respondingTimeouts\":{\"idleTimeout\":\"3m0s\"}},\"forwardedHeaders\":{},\"http\":{},\"http2\":{\"maxConcurrentStreams\":250},\"udp\":{\"timeout\":\"3s\"}},\"websecure\":{\"address\":\":8443/tcp\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":\"10s\"},\"respondingTimeouts\":{\"idleTimeout\":\"3m0s\"}},\"forwardedHeaders\":{},\"http\":{\"tls\":{}},\"http2\":{\"maxConcurrentStreams\":250},\"udp\":{\"timeout\":\"3s\"}}},\"providers\":{\"providersThrottleDuration\":\"2s\",\"kubernetesIngress\":{\"namespaces\":[\"default\",\"traefik\"]},\"kubernetesCRD\":{\"namespaces\":[\"default\",\"traefik\"],\"allowExternalNameServices\":true}},\"api\":{\"dashboard\":true},\"metrics\":{\"prometheus\":{\"buckets\":[0.1,0.3,1.2,5],\"addEntryPointsLabels\":true,\"addServicesLabels\":true,\"entryPoint\":\"metrics\"}},\"ping\":{\"entryPoint\":\"traefik\",\"terminatingStatusCode\":503},\"log\":{\"level\":\"DEBUG\",\"format\":\"common\"},\"accessLog\":{\"format\":\"common\",\"filters\":{},\"fields\":{\"defaultMode\":\"keep\",\"headers\":{\"defaultMode\":\"drop\"}}},\"pilot\":{\"dashboard\":true},\"experimental\":{\"plugins\":{\"plugin-requestid\":{\"moduleName\":\"github.com/pipe01/plugin-requestid\",\"version\":\"v1.0.0\"}}}}"
time="2022-11-16T06:25:25Z" level=info msg="\nStats collection is disabled.\nHelp us improve Traefik by turning this feature on :)\nMore details on: https://doc.traefik.io/traefik/contributing/data-collection/\n"
time="2022-11-16T06:25:25Z" level=warning msg="Traefik Pilot is deprecated and will be removed soon. Please check our Blog for migration instructions later this year."
time="2022-11-16T06:25:25Z" level=debug msg="loading of plugin: plugin-requestid: github.com/pipe01/plugin-requestid@v1.0.0"
time="2022-11-16T06:25:30Z" level=error msg="Plugins are disabled because an error has occurred." error="failed to download plugin github.com/pipe01/plugin-requestid: failed to call service: Get \"https://plugin.pilot.traefik.io/public/download/github.com/pipe01/plugin-requestid/v1.0.0\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)"
time="2022-11-16T06:25:30Z" level=debug msg="Configured Prometheus metrics" metricsProviderName=prometheus
time="2022-11-16T06:25:30Z" level=info msg="Starting provider aggregator aggregator.ProviderAggregator"
time="2022-11-16T06:25:30Z" level=debug msg="Starting TCP Server" entryPointName=metrics
time="2022-11-16T06:25:30Z" level=debug msg="Starting TCP Server" entryPointName=traefik
time="2022-11-16T06:25:30Z" level=info msg="Starting provider *traefik.Provider"
time="2022-11-16T06:25:30Z" level=debug msg="*traefik.Provider provider configuration: {}"
time="2022-11-16T06:25:30Z" level=info msg="Starting provider *ingress.Provider"
time="2022-11-16T06:25:30Z" level=debug msg="*ingress.Provider provider configuration: {\"namespaces\":[\"default\",\"traefik\"]}"
time="2022-11-16T06:25:30Z" level=info msg="ingress label selector is: \"\"" providerName=kubernetes
time="2022-11-16T06:25:30Z" level=info msg="Creating in-cluster Provider client" 

[nmengin]

Hello @scrazy77,

Thank you for the information.
We'll try to reproduce the error on our side, and we'll keep you updated according to the results.

In the meantime, you can try to install Traefik using the latest version of the Helm Chart (20.2.1) instead of the version 18.3.0 you are currently using.
It brings some modifications to the Traefik configuration.

[scrazy77]

In the meantime, you can try to install Traefik using the latest version of the Helm Chart (20.2.1) instead of the version

Hi @nmengin :
I try helm chart v20.2.1 today, the results still same:
traefik v2.8.3 load all plugins and works well.
traefik v2.8.4 can't load plugins.

[ldez]

There is only 1 difference between v2.8.3 and v2.8.4: in v2.8.4, Traefik logs the error when an error occurs during communication with the plugin server instead of stopping Traefik.

v2.8.3...v2.8.4

So I think you have a problem with your network, you have something randomly slowing down your network, but it's not related to a specific version of Traefik.

[scrazy77]

So I think you have a problem with your network, you have something randomly slowing down your network, but it's not related to a specific version of Traefik.

Hi @nmengin
Thanks for help.
I think it shouldn't be a "random" network problem,
because I can reproduce it easily in every version >= v2.8.4.
and version <= v2.8.3 all work fine.
All test in the same AWS EKS cluster & same node group & same VPC network...
Very strange... and no idea....