acouvreur / traefik-modsecurity-plugin

Traefik plugin to proxy requests to owasp/modsecurity-crs:apache container
https://plugins.traefik.io/plugins/628c9eadffc0cd18356a9799/modsecurity-plugin
Apache License 2.0
138 stars 25 forks source link

modsecurity.go:56:5: panic #5

Open igoooor opened 2 years ago

igoooor commented 2 years ago

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..

acouvreur commented 2 years ago

Can you share your traefik configuration with the version? Thanks

acouvreur commented 2 years ago

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.

igoooor commented 2 years ago

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 commented 2 years ago

Sorry I forgot to mention that this error is coming sporadically

acouvreur commented 2 years ago

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

igoooor commented 2 years ago

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 commented 2 years ago

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 commented 2 years ago

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

acouvreur commented 2 years ago

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

igoooor commented 2 years ago

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 commented 2 years ago

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 commented 2 years ago

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