Wrong Status code since 2.9.9 with header middleware

[j-gourdon]

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?

Since our last upgrade of traefik in 2.10.1, we saw an increase in http 401 response on some of our backends, but not on traefik side.

What did you see instead?

• Backend process the request and returns : http 401
• Traefik returns http 200 to the client.
• Traefik logs only http 100 in accesslog.
• Traefik reports a 401 in metrics

After some investigation :

• We tried to downgrade traefik, the issue starts occurring in 2.9.9.
• Disabling header middleware also solve the issue.
• It's not specifically related to 401 response, we also observe this behaviour on others calls which are responding 201/204 for example.

This occurs when all those conditions are met :

• Client make a POST request. (I didn't check but I assume we would have the same behaviour on a PUT request.)
• Client send a Expect: 100-continue Header
• Middleware header is used. (Not tied to a specific header, I use sts headers, but a random custom header give the same result)
• Http1.1

I'll post below the minimal setup I used to reproduce. (On the backend side I juste used a go backend, 1.20.4, which just store the uploaded file and return a http 201.)

What version of Traefik are you using?

Version:      2.9.9
Codename:     banon
Go version:   go1.20.2
Built:        2023-03-21T15:52:28Z
OS/Arch:      darwin/arm64

What is your environment & configuration?

traefik.yaml :

api:
  dashboard: true
  insecure: true
entryPoints:
  http:
    address: ':80'
  traefik:
    address: ':8081'
log:
  level: DEBUG
providers:
  file:
    filename: dynamic.yaml
accessLog:
  filePath: "access.log"
  format: json
metrics:
  prometheus: {}

dynamic.yaml :

http:
  middlewares:
    headers-hsts:
      headers:
        forceSTSHeader: true
        frameDeny: true
        stsIncludeSubdomains: true
        stsSeconds: 15724800
    ratelimit:
      rateLimit:
        average: 30
        burst: 60
  routers:
    local-router:
      rule: Host(`traefik.local`)
      service: upload
      middlewares:
        - "ratelimit"
        - "headers-hsts"
  services:
    upload:
      loadBalancer:
        servers:
          - url: 'http://REDACTED:8082'

If applicable, please paste the log output in DEBUG level

Traefik 2.9.9, headers middleware ON :

curl --http1.1 \                                                                                 
    -H "multipart/form-data" \
    -H "Expect: 100-continue" \
    -vk \
    http://traefik.local/upload \
    -F uploadFile=@testFile
*   Trying REDACTED:80...
* Connected to traefik.local (REDACTED) port 80 (#0)
> POST /upload HTTP/1.1
> Host: traefik.local
> User-Agent: curl/7.87.0
> Accept: */*
> Expect: 100-continue
> Content-Length: 4043747
> Content-Type: multipart/form-data; boundary=------------------------2ecc540804f95d37
>
* Mark bundle as not supporting multiuse
< HTTP/1.1 100 Continue
< Strict-Transport-Security: max-age=15724800; includeSubDomains
< X-Frame-Options: DENY
* We are completely uploaded and fine
* Mark bundle as not supporting multiuse
< HTTP/1.1 200 OK
< Content-Length: 1
< Content-Type: text/plain; charset=utf-8
< Date: Wed, 31 May 2023 15:21:24 GMT
< X-Content-Type-Options: nosniff
<

* Connection #0 to host traefik.local left intact

accesslog :

{"ClientAddr":"REDACTED:52691","ClientHost":"REDACTED","ClientPort":"52691","ClientUsername":"-","DownstreamContentSize":1,"DownstreamStatus":100,"Duration":33810000,"OriginContentSize":1,"OriginDuration":33732000,"OriginStatus":100,"Overhead":78000,"RequestAddr":"traefik.local","RequestContentSize":4043747,"RequestCount":1,"RequestHost":"traefik.local","RequestMethod":"POST","RequestPath":"/upload","RequestPort":"-","RequestProtocol":"HTTP/1.1","RequestScheme":"http","RetryAttempts":0,"RouterName":"local-router@file","ServiceAddr":"REDACTED:8082","ServiceName":"upload@file","ServiceURL":{"Scheme":"http","Opaque":"","User":null,"Host":"REDACTED:8082","Path":"","RawPath":"","OmitHost":false,"ForceQuery":false,"RawQuery":"","Fragment":"","RawFragment":""},"StartLocal":"2023-05-31T17:21:23.980574+02:00","StartUTC":"2023-05-31T15:21:23.980574Z","entryPointName":"http","level":"info","msg":"","time":"2023-05-31T17:21:24+02:00"}

Traefik 2.9.9, headers middleware OFF :

curl --http1.1 \                                                                                  
    -H "multipart/form-data" \
    -H "Expect: 100-continue" \
    -vk \
    http://traefik.local/upload \
    -F uploadFile=@testFile
*   Trying REDACTED:80...
* Connected to traefik.local (REDACTED) port 80 (#0)
> POST /upload HTTP/1.1
> Host: traefik.local
> User-Agent: curl/7.87.0
> Accept: */*
> Expect: 100-continue
> Content-Length: 4043747
> Content-Type: multipart/form-data; boundary=------------------------21c93b5e4e11755a
>
* Mark bundle as not supporting multiuse
< HTTP/1.1 100 Continue
* We are completely uploaded and fine
* Mark bundle as not supporting multiuse
< HTTP/1.1 201 Created
< Content-Length: 1
< Content-Type: text/plain; charset=utf-8
< Date: Wed, 31 May 2023 15:26:56 GMT
< X-Content-Type-Options: nosniff
<

* Connection #0 to host traefik.local left intact

accesslog :

{"ClientAddr":"REDACTED:52707","ClientHost":"REDACTED","ClientPort":"52707","ClientUsername":"-","DownstreamContentSize":1,"DownstreamStatus":201,"Duration":22132000,"OriginContentSize":1,"OriginDuration":22026000,"OriginStatus":201,"Overhead":106000,"RequestAddr":"traefik.local","RequestContentSize":4043747,"RequestCount":4,"RequestHost":"traefik.local","RequestMethod":"POST","RequestPath":"/upload","RequestPort":"-","RequestProtocol":"HTTP/1.1","RequestScheme":"http","RetryAttempts":0,"RouterName":"local-router@file","ServiceAddr":"REDACTED:8082","ServiceName":"upload@file","ServiceURL":{"Scheme":"http","Opaque":"","User":null,"Host":"REDACTED:8082","Path":"","RawPath":"","OmitHost":false,"ForceQuery":false,"RawQuery":"","Fragment":"","RawFragment":""},"StartLocal":"2023-05-31T17:26:56.175075+02:00","StartUTC":"2023-05-31T15:26:56.175075Z","entryPointName":"http","level":"info","msg":"","time":"2023-05-31T17:26:56+02:00"}

Traefik 2.9.8, headers middleware ON :

curl --http1.1 \                                                                                  
    -H "multipart/form-data" \
    -H "Expect: 100-continue" \
    -vk \
    http://traefik.local/upload \
    -F uploadFile=@testFile
*   Trying REDACTED:80...
* Connected to traefik.local (REDACTED) port 80 (#0)
> POST /upload HTTP/1.1
> Host: traefik.local
> User-Agent: curl/7.87.0
> Accept: */*
> Expect: 100-continue
> Content-Length: 4043747
> Content-Type: multipart/form-data; boundary=------------------------d457858debf8cf0d
>
* Mark bundle as not supporting multiuse
< HTTP/1.1 100 Continue
* We are completely uploaded and fine
* Mark bundle as not supporting multiuse
< HTTP/1.1 201 Created
< Content-Length: 1
< Content-Type: text/plain; charset=utf-8
< Date: Wed, 31 May 2023 15:31:21 GMT
< Strict-Transport-Security: max-age=15724800; includeSubDomains
< X-Content-Type-Options: nosniff
< X-Frame-Options: DENY
<

* Connection #0 to host traefik.local left intact

accesslog :

{"ClientAddr":"REDACTED:52729","ClientHost":"REDACTED","ClientPort":"52729","ClientUsername":"-","DownstreamContentSize":1,"DownstreamStatus":201,"Duration":48922000,"OriginContentSize":1,"OriginDuration":48833000,"OriginStatus":201,"Overhead":89000,"RequestAddr":"traefik.local","RequestContentSize":4043747,"RequestCount":1,"RequestHost":"traefik.local","RequestMethod":"POST","RequestPath":"/upload","RequestPort":"-","RequestProtocol":"HTTP/1.1","RequestScheme":"http","RetryAttempts":0,"RouterName":"local-router@file","ServiceAddr":"REDACTED:8082","ServiceName":"upload@file","ServiceURL":{"Scheme":"http","Opaque":"","User":null,"Host":"REDACTED:8082","Path":"","RawPath":"","OmitHost":false,"ForceQuery":false,"RawQuery":"","Fragment":"","RawFragment":""},"StartLocal":"2023-05-31T17:31:21.820605+02:00","StartUTC":"2023-05-31T15:31:21.820605Z","entryPointName":"http","level":"info","msg":"","time":"2023-05-31T17:31:21+02:00"}

[ldez]

Hello,

there are no changes related to middleware between v2.9.8 and v2.9.9 v2.9.8...v2.9.9

The only variation that I can see is the Go version, it can be related to 1xx support.

[gerdos82]

We experience the exact same issue, especially with .NET http clients which send the Expect: 100-continue header by default.

[j-gourdon]

Hello,

Thanks.
For sure it's somehow related to supporting Expect header.
I didn't mention, but of course if we remove the Expect header in the middleware, the issue is also gone :

spec:
  headers:
    customRequestHeaders:
      Expect: ""
    ....

Couldn't this also be related to #9750 ?
Building a 2.9.9 after reverting this one, traefik and header middleware behave as intended.

[ldez]

Couldn't this also be related to #9750 ?

No, this PR is about an error message inside the buffer middleware

[j-gourdon]

It also includes a bump of net package. But let's forgot it if it's not relevant.

[traefiker]

Closed by #9938.