traefik-modsecurity-plugin icon indicating copy to clipboard operation
traefik-modsecurity-plugin copied to clipboard

modsecurity.go:56:5: panic

Open igoooor opened this issue 1 year ago • 12 comments

Hello,

traefik threw this error:

level=error msg="plugins-storage/sources/gop-310462375/src/github.com/acouvreur/traefik-modsecurity-plugin/modsecurity.go:56:5: panic" plugin=plugin-traefik-modsecurity-plugin module=github.com/acouvreur/traefik-modsecurity-plugin

Unfortunately I don't have much more information as I don't have any traefik logs enabled at the moment..

igoooor avatar Jul 27 '22 18:07 igoooor

Can you share your traefik configuration with the version? Thanks

acouvreur avatar Jul 27 '22 18:07 acouvreur

From what I see with the log, its related to https://github.com/acouvreur/traefik-modsecurity-plugin/blob/19cdb477b8cee1966ad95278d168ae90a93df663/modsecurity.go#L56-L59

https://github.com/acouvreur/traefik-modsecurity-plugin/blob/19cdb477b8cee1966ad95278d168ae90a93df663/modsecurity.go#L107-L114

Which tries to determines if the incoming connection is a WebSocket init request.

acouvreur avatar Jul 27 '22 18:07 acouvreur

I'm on traefik v2.8.1 (latest I believe) and here is my config:

        - --serversTransport.maxIdleConnsPerHost=-1
        - --api
        - --api.dashboard=true
        - --api.insecure=true
        - --metrics.prometheus=true
        - --metrics.prometheus.addRoutersLabels=true
        - --metrics.prometheus.buckets=0.1,0.3,1.2,5.0
        - --experimental.plugins.traefik-modsecurity-plugin.modulename=github.com/acouvreur/traefik-modsecurity-plugin
        - --experimental.plugins.traefik-modsecurity-plugin.version=v1.1.0
        - --experimental.hub=true
        - --hub
        - --entrypoints.web.Address=:80
        - --entrypoints.websecure.Address=:443
        - --entrypoints.websecure.forwardedHeaders.insecure=true
        - --providers.kubernetescrd
        - --providers.kubernetescrd.allowExternalNameServices=true
        - --providers.kubernetescrd.allowCrossNamespace=true
        - --providers.kubernetesingress=true
        - --providers.kubernetesingress.allowExternalNameServices=true
        - --providers.kubernetesingress.ingressclass=traefik-cert-manager
        - --ping=true

igoooor avatar Jul 27 '22 18:07 igoooor

Sorry I forgot to mention that this error is coming sporadically

igoooor avatar Jul 27 '22 21:07 igoooor

It is related to a request, if you could correlate the incoming request to the panic that would help a lot.

acouvreur avatar Jul 28 '22 15:07 acouvreur

I'm gonna enable full logs again and see what I can find when this happens. I will let you know, thanks for your support!

igoooor avatar Jul 28 '22 17:07 igoooor

Ok so I could reproduce it (by reloading my page over and over). Here is the json payload of the request that randomly failed (most of the time that same request worked):

jsonPayload: {
	ClientAddr: "MASKED:MASKED"
	ClientHost: "MASKED"
	ClientPort: "MASKED"
	ClientUsername: "-"
	DownstreamContentSize: 1019392
	DownstreamStatus: 200
	Duration: 12983123
	OriginContentSize: 1019392
	OriginDuration: 12871244
	OriginStatus: 200
	Overhead: 111879
	RequestAddr: "MASKED"
	RequestContentSize: 0
	RequestCount: 22669
	RequestHost: "MASKED"
	RequestMethod: "GET"
	RequestPath: "/build/fonts/fa-light-300.c92b45dd.ttf"
	RequestPort: "-"
	RequestProtocol: "HTTP/2.0"
	RequestScheme: "https"
	RetryAttempts: 0
	RouterName: "MASKED-dedc34fe700f15d34300@kubernetescrd"
	ServiceAddr: "10.2.50.76:8000"
	ServiceName: "MASKED-dedc34fe700f15d34300@kubernetescrd"
	ServiceURL: {10}
	StartLocal: "2022-07-28T21:38:51.273304691Z"
	StartUTC: "2022-07-28T21:38:51.273304691Z"
	TLSCipher: "TLS_AES_128_GCM_SHA256"
	TLSVersion: "1.3"
	entryPointName: "websecure"
	level: "info"
	msg: ""
}

And traefik logs were:

time="2022-07-28T21:38:51Z" level=error msg="plugins-storage/sources/gop-843596063/src/github.com/acouvreur/traefik-modsecurity-plugin/modsecurity.go:56:5: panic" plugin=plugin-traefik-modsecurity-plugin module=github.com/acouvreur/traefik-modsecurity-plugin
time="2022-07-28T21:38:51Z" level=debug msg="Request has been aborted [MASKED - /build/fonts/fa-light-300.c92b45dd.ttf]: net/http: abort Handler" middlewareName=traefik-internal-recovery middlewareType=Recovery

I was not able to see if that request failed on my browser though, I will try again to catch that. But according to my logs, it's not just that request that fails, all kind of requests are failing (i.e. not just static assets)

igoooor avatar Jul 28 '22 21:07 igoooor

do you see maybe any debug logs I could add somewhere to try to identify the issue? I could easily make a fork and use it as local-plugin, but I'm just not sure what to look for

igoooor avatar Jul 30 '22 10:07 igoooor

Thanks for the info, I'll look into it :)

acouvreur avatar Jul 30 '22 22:07 acouvreur

Just FYI, I wanted to be sure it was not coming from the version of kubernetes I was using, so I created a new cluster, with a more stable version (1.23.6-gke.2200) but I still have the same issue

igoooor avatar Aug 01 '22 22:08 igoooor

FYI, since I still have this issue frequently, I created a fork with a new option (to a.next.ServeHTTP(rw, req) in case of error), you can find it here: https://github.com/igoooor/traefik-modsecurity-plugin/commit/2449ccedce3c8055aaa11d479d0a44c91f8112db

If this is a feature you would like to have, I can create a PR if you want, otherwise I will keep using my fork. This at least allows me to not interrupt requests when this problem happens. I checked the logs already and this is what it tells me, maybe that helps you in anyway? Recovered Panic. Error: net/http: abort Handler

EDIT: I also added a Print of the req *http.Request when a net/http: abort Handler happened and here it is:

{GET /build/fonts/fa-regular-400.b5c92e45.woff2 HTTP/2.0 2 0 map[Accept:[*/*] Accept-Encoding:[gzip, deflate, br] Accept-Language:[de-DE,de;q=0.9] Cookie:[cookie_consent_level=%7B%22strictly-necessary%22%3Atrue%2C%22functionality%22%3Afalse%2C%22tracking%22%3Afalse%2C%22targeting%22%3Afalse%7D] Referer:[https://MASKED/en] User-Agent:[Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/15.6.1 Safari/605.1.15] X-Forwarded-Host:[MASKED] X-Forwarded-Port:[443] X-Forwarded-Proto:[https] X-Forwarded-Server:[traefik-94b76f6bf-pj847] X-Real-Ip:[MASKED]] {0xc000ec9350} <nil> 0 [] false MASKED map[] map[] <nil> map[] MASKED:49677 /build/fonts/fa-regular-400.b5c92e45.woff2 0xc0036f8210 <nil> <nil> 0xc000ec9110}

seems pretty normal to me, weird that isWebsocket would give a panic no?

igoooor avatar Oct 03 '22 11:10 igoooor

I also added another config to ignore 500errors from the owasp container https://github.com/igoooor/traefik-modsecurity-plugin/commit/8808205a8deb2aef836ca779497b7d172665e61c

igoooor avatar Oct 03 '22 11:10 igoooor