traefik: Plugins panic

Hey @mpl,

Thanks for the detailed description of what is happening. Clear on my side. I think it would be great if we did not see the panic message since it is not really an error 😃

Mathieu

@mpl it’s included in the repo - https://github.com/Thor77/traefik-plugin-panic/tree/master/forward and mounted to the correct location in the docker-compose file. If there’s any difference between the local plugin mode and plugins fetched remotely I can also create a separate repo for it.

I found an easier way to reproduce this using httpbin: https://github.com/Thor77/traefik-plugin-panic It looks like there’s an issue with streaming connections, code for the response generation in httpbin: https://github.com/postmanlabs/httpbin/blob/f8ec666b4d1b654e4ff6aedd356f510dcac09f83/httpbin/core.py

Thank you, I’ll see if I can reproduce as well with the new information.

Hello,

I’ve observed the same issue with Traefik 2.9.6 and a basic plugin which only serves the requests.

func (bouncer *Bouncer) ServeHTTP(rw http.ResponseWriter, req *http.Request) {
	if !bouncer.enabled {
		bouncer.next.ServeHTTP(rw, req)
		return
	}
...
}

An issue #60 is open in a plugin repository, but I believe the error could come from Traefik.

I’ve found a way to reproduce the “panic” at each request.

The dozzle container triggers this error each time you change container logs.

Here is a following docker-compose that can be used:

version: "3.8"

services:
  traefik:
    image: "traefik:v2.9.6"
    container_name: "traefik"
    restart: unless-stopped
    command:
      - "--log.level=DEBUG"
      - "--accesslog"
      - "--accesslog.filepath=/var/log/traefik/access.log"
      - "--api.insecure=true"
      - "--providers.docker=true"
      - "--providers.docker.exposedbydefault=false"
      - "--entrypoints.web.address=:80"

      - "--experimental.plugins.bouncer.modulename=github.com/maxlerebourg/crowdsec-bouncer-traefik-plugin"
      - "--experimental.plugins.bouncer.version=v1.1.5"
    volumes:
      - "/var/run/docker.sock:/var/run/docker.sock:ro"
      - "logs:/var/log/traefik"
    ports:
      - 8000:80
      - 8080:8080
    depends_on:
      - 'crowdsec'

  crowdsec:
    image: crowdsecurity/crowdsec:v1.4.1
    container_name: "crowdsec"
    restart: unless-stopped
    environment:
      COLLECTIONS: crowdsecurity/traefik
      CUSTOM_HOSTNAME: crowdsec
      # We need to register one api key per service we will use
      BOUNCER_KEY_TRAEFIK_1: FIXME-LAPI-KEY-1
    volumes:
      - ./acquis.yaml:/etc/crowdsec/acquis.yaml:ro
      - logs:/var/log/traefik:ro
      - crowdsec-db:/var/lib/crowdsec/data/
      - crowdsec-config:/etc/crowdsec/
    labels:
      - "traefik.enable=false"
  
  dozzle:
    container_name: dozzle
    image: amir20/dozzle:latest
    volumes:
      - /var/run/docker.sock:/var/run/docker.sock
    labels:
      - "traefik.enable=true"
      - "traefik.http.routers.router-doz.rule=Host(`localhost`)"
      - "traefik.http.routers.router-doz.entrypoints=web"
      - "traefik.http.routers.router-doz.middlewares=crowdsec-doz@docker" 
      - "traefik.http.services.service-doz.loadbalancer.server.port=8080"
      - "traefik.http.middlewares.crowdsec-doz.plugin.bouncer.enabled=false"
      - "traefik.http.middlewares.crowdsec-doz.plugin.bouncer.crowdseclapikey=FIXME-LAPI-KEY-1"
      - "traefik.http.middlewares.crowdsec-doz.plugin.bouncer.loglevel=DEBUG"

volumes:
  logs:
  crowdsec-db:
  crowdsec-config:

Navigate to http://localhost:8000/ Change container by switching from Crowdsec to Traefik to dozzle.

This will trigger the following logs:

time="2022-12-09T19:17:40Z" level=debug msg="Request has been aborted [10.0.XX.XX:57628 - /api/logs/stream?id=fd7b0e109a4c&lastEventId=]: net/http: abort Handler" middlewareName=traefik-internal-recovery middlewareType=Recovery
time="2022-12-09T19:17:51Z" level=error msg="plugins-storage/sources/gop-2381581510/src/github.com/maxlerebourg/crowdsec-bouncer-traefik-plugin/bouncer.go:176:6: panic" plugin=plugin-bouncer module=github.com/maxlerebourg/crowdsec-bouncer-traefik-plugin
time="2022-12-09T19:17:51Z" level=debug msg="Request has been aborted [10.0.XX.XX:57630 - /api/logs/stream?id=68b1c915e432&lastEventId=]: net/http: abort Handler" middlewareName=traefik-internal-recovery middlewareType=Recovery
time="2022-12-09T19:18:04Z" level=error msg="plugins-storage/sources/gop-2381581510/src/github.com/maxlerebourg/crowdsec-bouncer-traefik-plugin/bouncer.go:176:6: panic" module=github.com/maxlerebourg/crowdsec-bouncer-traefik-plugin plugin=plugin-bouncer
time="2022-12-09T19:18:04Z" level=debug msg="Request has been aborted [10.0.XX.XX:57631 - /api/logs/stream?id=fd7b0e109a4c&lastEventId=]: net/http: abort Handler" middlewareType=Recovery middlewareName=traefik-internal-recovery

It happens every time a new request is closed and open. Requests appears to be websockets.

We’re seeing the same problem, only in our production environment as well which makes this really hard to debug as there’s quite a lot of traffic so we can’t just enable debug mode and I don’t see anything strange in the access log (if it would even be logged in that case). For us this occurs with a custom middleware in this line:

url, _ := url.Parse(req.RequestURI)

so I assume the request is null in that case as described above. The only useful information I can add: we have this issue since at least Traefik 2.7.1 with this middleware.