Skip to content

Plugin panics on websocket upgrade #15

@IntermittentlyRupert

Description

@IntermittentlyRupert

I'm seeing this on Radarr v3, which uses a websocket for UI status updates. (The style is also not rewritten into the actual page's response body as described in #14, but this is a separate request.)

Here's a minimal environment that reproduces the issue:

# docker-compose.yaml
version: "3"
services:
  traefik:
    image: "traefik"
    ports:
      - "80:80"
      - "443:443"
    volumes:
      - "/var/run/docker.sock:/var/run/docker.sock:ro"
      - "./data:/data"
    command:
      - "--log.level=DEBUG"
      - "--accesslog=true"
      - "--accesslog.filters.statuscodes=400-599"

      - "--providers.docker=true"
      - "--providers.file=true"
      - "--providers.file.filename=/data/certs.yaml"

      - "--entrypoints.websecure=true"
      - "--entrypoints.websecure.address=:443"
      - "--entrypoints.websecure.http.tls=true"

      - "--pilot.token=${TRAEFIK_PILOT_TOKEN}"
      - "--experimental.plugins.rewrite.modulename=github.com/traefik/plugin-rewritebody"
      - "--experimental.plugins.rewrite.version=v0.3.1"
  radarr:
    image: "linuxserver/radarr:nightly"
    labels:
      - "traefik.http.routers.radarr.rule=Host(`${DOMAIN}`)"
      # Commenting out this line allows the socket to connect successfully.
      - "traefik.http.routers.radarr.middlewares=radarr"
      - "traefik.http.middlewares.radarr.plugin.rewrite.rewrites[0].regex=</head>"
      - 'traefik.http.middlewares.radarr.plugin.rewrite.rewrites[0].replacement=<link rel="stylesheet" type="text/css" href="https://gilbn.github.io/theme.park/CSS/themes/radarr/plex.css"></head>'

# ./data/certs.yaml
tls:
  stores:
    default:
      defaultCertificate:
        certFile: "/data/cert.fullchain.pem"
        keyFile: "/data/cert.key.pem"
  certificates:
    - certFile: "/data/cert.fullchain.pem"
      keyFile: "/data/cert.key.pem"
      stores:
        - "default"

Logs:

(There's some Organizr cookies in there, but I was loading the site directly for this pageload.)

time="2020-11-29T10:41:09Z" level=debug msg="vulcand/oxy/roundrobin/rr: begin ServeHttp on request" Request="{\"Method\":\"GET\",\"URL\":{\"Scheme\":\"\",\"Opaque\":\"\",\"User\":null,\"Host\":\"\",\"Path\":\"/signalr/messages\",\"RawPath\":\"\",\"ForceQuery\":false,\"RawQuery\":\"access_token=<snip>\\u0026id=<snip>\",\"Fragment\":\"\",\"RawFragment\":\"\"},\"Proto\":\"HTTP/1.1\",\"ProtoMajor\":1,\"ProtoMinor\":1,\"Header\":{\"Accept\":[\"*/*\"],\"Accept-Encoding\":[\"gzip, deflate, br\"],\"Accept-Language\":[\"en-GB,en;q=0.5\"],\"Cache-Control\":[\"no-cache\"],\"Connection\":[\"keep-alive, Upgrade\"],\"Cookie\":[\"Organizr_Token=<snip>; cookiePassword=; PHPSESSID=<snip>; organizrLanguage=en; organizr_token_7d7ec244-f6cd-46b7-8aaf-e6d9a3ad2a62=<snip>\"],\"Dnt\":[\"1\"],\"Origin\":[\"https://ijm.zone\"],\"Pragma\":[\"no-cache\"],\"Sec-Websocket-Extensions\":[\"permessage-deflate\"],\"Sec-Websocket-Key\":[\"<snip>\"],\"Sec-Websocket-Version\":[\"13\"],\"Upgrade\":[\"websocket\"],\"User-Agent\":[\"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:83.0) Gecko/20100101 Firefox/83.0\"],\"X-Forwarded-Host\":[\"ijm.zone\"],\"X-Forwarded-Port\":[\"443\"],\"X-Forwarded-Proto\":[\"wss\"],\"X-Forwarded-Server\":[\"5ea811ad2500\"],\"X-Real-Ip\":[\"192.168.0.1\"]},\"ContentLength\":0,\"TransferEncoding\":null,\"Host\":\"ijm.zone\",\"Form\":null,\"PostForm\":null,\"MultipartForm\":null,\"Trailer\":null,\"RemoteAddr\":\"192.168.0.1:52436\",\"RequestURI\":\"/signalr/messages?access_token=<snip>\\u0026id=<snip>\",\"TLS\":null}"
time="2020-11-29T10:41:09Z" level=debug msg="vulcand/oxy/roundrobin/rr: Forwarding this request to URL" Request="{\"Method\":\"GET\",\"URL\":{\"Scheme\":\"\",\"Opaque\":\"\",\"User\":null,\"Host\":\"\",\"Path\":\"/signalr/messages\",\"RawPath\":\"\",\"ForceQuery\":false,\"RawQuery\":\"access_token=<snip>\\u0026id=<snip>\",\"Fragment\":\"\",\"RawFragment\":\"\"},\"Proto\":\"HTTP/1.1\",\"ProtoMajor\":1,\"ProtoMinor\":1,\"Header\":{\"Accept\":[\"*/*\"],\"Accept-Encoding\":[\"gzip, deflate, br\"],\"Accept-Language\":[\"en-GB,en;q=0.5\"],\"Cache-Control\":[\"no-cache\"],\"Connection\":[\"keep-alive, Upgrade\"],\"Cookie\":[\"Organizr_Token=<snip>; cookiePassword=; PHPSESSID=<snip>; organizrLanguage=en; organizr_token_7d7ec244-f6cd-46b7-8aaf-e6d9a3ad2a62=<snip>\"],\"Dnt\":[\"1\"],\"Origin\":[\"https://ijm.zone\"],\"Pragma\":[\"no-cache\"],\"Sec-Websocket-Extensions\":[\"permessage-deflate\"],\"Sec-Websocket-Key\":[\"<snip>\"],\"Sec-Websocket-Version\":[\"13\"],\"Upgrade\":[\"websocket\"],\"User-Agent\":[\"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:83.0) Gecko/20100101 Firefox/83.0\"],\"X-Forwarded-Host\":[\"ijm.zone\"],\"X-Forwarded-Port\":[\"443\"],\"X-Forwarded-Proto\":[\"wss\"],\"X-Forwarded-Server\":[\"5ea811ad2500\"],\"X-Real-Ip\":[\"192.168.0.1\"]},\"ContentLength\":0,\"TransferEncoding\":null,\"Host\":\"ijm.zone\",\"Form\":null,\"PostForm\":null,\"MultipartForm\":null,\"Trailer\":null,\"RemoteAddr\":\"192.168.0.1:52436\",\"RequestURI\":\"/signalr/messages?access_token=<snip>\\u0026id=<snip>\",\"TLS\":null}" ForwardURL="http://192.168.0.2:7878"
time="2020-11-29T10:41:09Z" level=debug msg="vulcand/oxy/roundrobin/rr: completed ServeHttp on request" Request="{\"Method\":\"GET\",\"URL\":{\"Scheme\":\"\",\"Opaque\":\"\",\"User\":null,\"Host\":\"\",\"Path\":\"/signalr/messages\",\"RawPath\":\"\",\"ForceQuery\":false,\"RawQuery\":\"access_token=<snip>\\u0026id=<snip>\",\"Fragment\":\"\",\"RawFragment\":\"\"},\"Proto\":\"HTTP/1.1\",\"ProtoMajor\":1,\"ProtoMinor\":1,\"Header\":{\"Accept\":[\"*/*\"],\"Accept-Encoding\":[\"gzip, deflate, br\"],\"Accept-Language\":[\"en-GB,en;q=0.5\"],\"Cache-Control\":[\"no-cache\"],\"Connection\":[\"keep-alive, Upgrade\"],\"Cookie\":[\"Organizr_Token=<snip>; cookiePassword=; PHPSESSID=<snip>; organizrLanguage=en; organizr_token_7d7ec244-f6cd-46b7-8aaf-e6d9a3ad2a62=<snip>\"],\"Dnt\":[\"1\"],\"Origin\":[\"https://ijm.zone\"],\"Pragma\":[\"no-cache\"],\"Sec-Websocket-Extensions\":[\"permessage-deflate\"],\"Sec-Websocket-Key\":[\"<snip>\"],\"Sec-Websocket-Version\":[\"13\"],\"Upgrade\":[\"websocket\"],\"User-Agent\":[\"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:83.0) Gecko/20100101 Firefox/83.0\"],\"X-Forwarded-Host\":[\"ijm.zone\"],\"X-Forwarded-Port\":[\"443\"],\"X-Forwarded-Proto\":[\"wss\"],\"X-Forwarded-Server\":[\"5ea811ad2500\"],\"X-Real-Ip\":[\"192.168.0.1\"]},\"ContentLength\":0,\"TransferEncoding\":null,\"Host\":\"ijm.zone\",\"Form\":null,\"PostForm\":null,\"MultipartForm\":null,\"Trailer\":null,\"RemoteAddr\":\"192.168.0.1:52436\",\"RequestURI\":\"/signalr/messages?access_token=<snip>\\u0026id=<snip>\",\"TLS\":null}"
plugins-storage/sources/gop-045836040/src/github.com/traefik/plugin-rewritebody/rewritebody.go:93:3: panic
time="2020-11-29T10:41:09Z" level=error msg="Recovered from panic in HTTP handler [192.168.0.1:52436 - /signalr/messages?access_token=<snip>&id=<snip>]: interface conversion: stdlib._net_http_ResponseWriter is not http.Hijacker: missing method Hijack" middlewareName=traefik-internal-recovery middlewareType=Recovery
time="2020-11-29T10:41:09Z" level=error msg="Stack: goroutine 175 [running]:\ngithub.com/traefik/traefik/v2/pkg/middlewares/recovery.recoverFunc(0x39f5d40, 0xc0009363f0, 0x7fca511bb998, 0xc00011e0c0, 0xc000906200)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/recovery/recovery.go:47 +0x1fb\npanic(0x2efb860, 0xc000a3e030)\n\t/usr/local/go/src/runtime/panic.go:969 +0x1b9\ngithub.com/traefik/yaegi/interp.runCfg.func1(0xc000928000, 0xc000a18200, 0xc00049ec30)\n\t/go/pkg/mod/github.com/traefik/[email protected]/interp/run.go:171 +0x247\npanic(0x2efb860, 0xc000a3e030)\n\t/usr/local/go/src/runtime/panic.go:969 +0x1b9\ngithub.com/traefik/traefik/v2/pkg/middlewares/metrics.(*responseRecorder).Hijack(0xc0007c4b20, 0x7fca511bba88, 0xc0007c4b20, 0x7fca50e8fd58, 0xc0007c4b20, 0xaf6825)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/metrics/recorder.go:55 +0x47\ngithub.com/traefik/traefik/v2/pkg/middlewares/pipelining.(*writerWithoutCloseNotify).Hijack(0xc000a88d40, 0x35e5700, 0xc000906800, 0xc000ca0180, 0x39e9fc0, 0xc0007b0020)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/pipelining/pipelining.go:69 +0x5b\nnet/http/httputil.(*ReverseProxy).handleUpgradeResponse(0xc000d07860, 0x39dc400, 0xc000a88d40, 0xc000906800, 0xc000752510)\n\t/usr/local/go/src/net/http/httputil/reverseproxy.go:574 +0x382\nnet/http/httputil.(*ReverseProxy).ServeHTTP(0xc000d07860, 0x39dc400, 0xc000a88d40, 0xc000906700)\n\t/usr/local/go/src/net/http/httputil/reverseproxy.go:299 +0xf37\ngithub.com/traefik/traefik/v2/pkg/middlewares/pipelining.(*pipelining).ServeHTTP(0xc000aad050, 0x7fca511bba88, 0xc0007c4b20, 0xc000906700)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/pipelining/pipelining.go:36 +0xee\ngithub.com/traefik/traefik/v2/pkg/middlewares/accesslog.AddServiceFields(0x7fca511bba88, 0xc0007c4b20, 0xc000906700, 0x3981980, 0xc000aad050, 0xc000676140)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/accesslog/field_middleware.go:47 +0x13d\ngithub.com/traefik/traefik/v2/pkg/middlewares/accesslog.(*FieldHandler).ServeHTTP(0xc00077e100, 0x7fca511bba88, 0xc0007c4b20, 0xc000906700)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/accesslog/field_middleware.go:36 +0x10b\ngithub.com/traefik/traefik/v2/pkg/middlewares/metrics.(*metricsMiddleware).ServeHTTP(0xc0000a68c0, 0x7fca511bba38, 0xc0007c43e0, 0xc000906700)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/metrics/metrics.go:101 +0x5b2\ngithub.com/vulcand/oxy/roundrobin.(*RoundRobin).ServeHTTP(0xc0000a6a10, 0x7fca511bba38, 0xc0007c43e0, 0xc000906400)\n\t/go/pkg/mod/github.com/vulcand/[email protected]/roundrobin/rr.go:147 +0x15a\ngithub.com/traefik/traefik/v2/pkg/middlewares/emptybackendhandler.(*emptyBackend).ServeHTTP(0xc000aad1c0, 0x7fca511bba38, 0xc0007c43e0, 0xc000906400)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/emptybackendhandler/empty_backend_handler.go:31 +0x16d\ngithub.com/traefik/traefik/v2/pkg/middlewares/tracing.(*forwarderMiddleware).ServeHTTP(0xc00015b230, 0x7fca511bba38, 0xc0007c43e0, 0xc000906400)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/tracing/forwarder.go:38 +0x606\nreflect.Value.call(0x2f19480, 0xc00077e550, 0x293, 0x3494d13, 0x4, 0xc000936540, 0x2, 0x2, 0xc000676340, 0x2fb3020, ...)\n\t/usr/local/go/src/reflect/value.go:476 +0x8c7\nreflect.Value.Call(0x2f19480, 0xc00077e550, 0x293, 0xc000936540, 0x2, 0x2, 0x347b440, 0xc00077e501, 0xc000936540)\n\t/usr/local/go/src/reflect/value.go:337 +0xb9\ngithub.com/traefik/yaegi/interp.callBin.func1(0x2f19480, 0xc00077e550, 0x293, 0xc000936540, 0x2, 0x2, 0x1, 0x14, 0xc00076cc00)\n\t/go/pkg/mod/github.com/traefik/[email protected]/interp/run.go:1149 +0x65\ngithub.com/traefik/yaegi/interp.callBin.func10(0xc000928000, 0xc00027fae0)\n\t/go/pkg/mod/github.com/traefik/[email protected]/interp/run.go:1305 +0x1c2\ngithub.com/traefik/yaegi/interp.runCfg(0xc000a18200, 0xc000928000)\n\t/go/pkg/mod/github.com/traefik/[email protected]/interp/run.go:177 +0x87\ngithub.com/traefik/yaegi/interp.genFunctionWrapper.func2.1(0xc0009364e0, 0x2, 0x2, 0xc0009364e0, 0xc00076ce50, 0x4044d0)\n\t/go/pkg/mod/github.com/traefik/[email protected]/interp/run.go:787 +0x3e7\nreflect.callReflect(0xc00015b920, 0xc00049ef50, 0xc00049ef38)\n\t/usr/local/go/src/reflect/value.go:565 +0x32a\nreflect.makeFuncStub(0x7fca511bb998, 0xc00011e0c0, 0xc000906400, 0xc00049efb8, 0x2978424, 0xc00015b920, 0x7fca511bb998, 0xc00011e0c0, 0xc000906400, 0xc000e1eae8, ...)\n\t/usr/local/go/src/reflect/asm_amd64.s:20 +0x42\ngithub.com/traefik/yaegi/stdlib._net_http_Handler.ServeHTTP(0xc00015b920, 0x7fca511bb998, 0xc00011e0c0, 0xc000906400)\n\t/go/pkg/mod/github.com/traefik/[email protected]/stdlib/go1_15_net_http.go:260 +0x44\ngithub.com/traefik/traefik/v2/pkg/middlewares/accesslog.(*FieldHandler).ServeHTTP(0xc00077e600, 0x7fca511bb998, 0xc00011e0c0, 0xc000906400)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/accesslog/field_middleware.go:38 +0x144\ngithub.com/gorilla/mux.(*Router).ServeHTTP(0xc00066db60, 0x7fca511bb998, 0xc00011e0c0, 0xc000906200)\n\t/go/pkg/mod/github.com/containous/[email protected]/mux.go:133 +0x106\ngithub.com/traefik/traefik/v2/pkg/middlewares/recovery.(*recovery).ServeHTTP(0xc0004c9140, 0x7fca511bb998, 0xc00011e0c0, 0xc000906200)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/recovery/recovery.go:33 +0x104\ngithub.com/traefik/traefik/v2/pkg/middlewares/accesslog.AddOriginFields(0x7fca511bb9e8, 0xc00011e040, 0xc000906200, 0x39819c0, 0xc0004c9140, 0xc000676140)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/accesslog/field_middleware.go:55 +0x19f\ngithub.com/traefik/traefik/v2/pkg/middlewares/accesslog.(*FieldHandler).ServeHTTP(0xc00077e700, 0x7fca511bb9e8, 0xc00011e040, 0xc000906200)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/accesslog/field_middleware.go:36 +0x10b\ngithub.com/traefik/traefik/v2/pkg/middlewares/requestdecorator.(*RequestDecorator).ServeHTTP(0xc00000f260, 0x7fca511bb9e8, 0xc00011e040, 0xc000906100, 0xc00076d3d0)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/requestdecorator/request_decorator.go:47 +0x389\ngithub.com/traefik/traefik/v2/pkg/middlewares/requestdecorator.WrapHandler.func1.1(0x7fca511bb9e8, 0xc00011e040, 0xc000906100)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/requestdecorator/request_decorator.go:84 +0x87\nnet/http.HandlerFunc.ServeHTTP(0xc0004c91a0, 0x7fca511bb9e8, 0xc00011e040, 0xc000906100)\n\t/usr/local/go/src/net/http/server.go:2042 +0x44\ngithub.com/traefik/traefik/v2/pkg/middlewares/metrics.(*metricsMiddleware).ServeHTTP(0xc0000a7110, 0x7fca511bb998, 0xc00011e030, 0xc000906100)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/metrics/metrics.go:101 +0x5b2\ngithub.com/traefik/traefik/v2/pkg/middlewares/accesslog.(*Handler).ServeHTTP(0xc00066d140, 0x39ea000, 0xc0004fe700, 0xc000906000, 0x3981940, 0xc0000a7110)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/accesslog/logger.go:223 +0xafc\ngithub.com/traefik/traefik/v2/pkg/middlewares/accesslog.WrapHandler.func1.1(0x39ea000, 0xc0004fe700, 0xc000906000)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/accesslog/logger.go:69 +0x5a\nnet/http.HandlerFunc.ServeHTTP(0xc0004c91e0, 0x39ea000, 0xc0004fe700, 0xc000906000)\n\t/usr/local/go/src/net/http/server.go:2042 +0x44\ngithub.com/traefik/traefik/v2/pkg/server/router/tcp.(*Manager).buildEntryPointHandler.func1(0x39ea000, 0xc0004fe700, 0xc000906000)\n\t/go/src/github.com/traefik/traefik/pkg/server/router/tcp/router.go:194 +0x172\nnet/http.HandlerFunc.ServeHTTP(0xc0004c92e0, 0x39ea000, 0xc0004fe700, 0xc000906000)\n\t/usr/local/go/src/net/http/server.go:2042 +0x44\ngithub.com/traefik/traefik/v2/pkg/middlewares.(*HTTPHandlerSwitcher).ServeHTTP(0xc00000f258, 0x39ea000, 0xc0004fe700, 0xc000906000)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/handler_switcher.go:23 +0x70\ngithub.com/traefik/traefik/v2/pkg/middlewares/forwardedheaders.(*XForwarded).ServeHTTP(0xc000742730, 0x39ea000, 0xc0004fe700, 0xc000906000)\n\t/go/src/github.com/traefik/traefik/pkg/middlewares/forwardedheaders/forwarded_header.go:173 +0x108\nnet/http.serverHandler.ServeHTTP(0xc00004c620, 0x39ea000, 0xc0004fe700, 0xc000906000)\n\t/usr/local/go/src/net/http/server.go:2843 +0xa3\nnet/http.(*conn).serve(0xc000928aa0, 0x39f5c80, 0xc000676000)\n\t/usr/local/go/src/net/http/server.go:1925 +0x8ad\ncreated by net/http.(*Server).Serve\n\t/usr/local/go/src/net/http/server.go:2969 +0x36c\n" middlewareType=Recovery middlewareName=traefik-internal-recovery
192.168.0.1 - - [29/Nov/2020:10:41:09 +0000] "GET /signalr/messages?access_token=<snip>&id=<snip> HTTP/1.1" 500 22 "-" "-" 19 "radarr@docker" "http://192.168.0.2:7878" 10ms

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions