Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

serversTransports.name.serviceName breaks TLS with HTTPS_PROXY #10403

Open
2 tasks done
chrillefkr opened this issue Feb 1, 2024 · 1 comment
Open
2 tasks done

serversTransports.name.serviceName breaks TLS with HTTPS_PROXY #10403

chrillefkr opened this issue Feb 1, 2024 · 1 comment
Assignees
@kevinpollet
Labels
area/server kind/bug/confirmed a confirmed bug (reproducible).

Comments

@chrillefkr
Copy link

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?

I set up Traefik to act as a reverse proxy for a third-party service. The idea is to hide the client IP address from the third party. The network environment this Traefik instance sits in requires the use of a forward proxy for outgoing traffic to the internet. So I configured Traefik like normal, with file provider, and with the environment variable HTTPS_PROXY=https://user@password:forward-proxy.local:443, which worked fine.

I then added the option serversTransports.myTransport.serviceName in hopes of enforcing Host header and SNI check for upstream server.

What did you see instead?

I get an error message similar to below:

{"level":"debug","msg":"'502 Bad Gateway' caused by: proxyconnect tcp: tls: failed to verify certificate: x509: certificate is valid for forward-proxy.local, not third-party.local","time":"2024-01-31T13:50:56Z"}

What version of Traefik are you using?

$ ./traefik version
Version:      2.11.0-rc2
Codename:     cheddar
Go version:   go1.21.6
Built:        2024-01-24T17:46:22Z
OS/Arch:      linux/amd64

From 2.11.0-rc2 release

What is your environment & configuration?

Something like below:

# /etc/traefik/traefik.yaml
global:
  checkNewVersion: false
  sendAnonymousUsage: false
accessLog:
  filePath: "/var/log/traefik/access.log"
  format: json
log:
  level: DEBUG
  filePath: "/var/log/traefik/traefik.log"
  format: json
api:
  dashboard: false
entryPoints:
  webSecure:
    address: ':8443'
    http:
      tls: {}
providers:
  file:
    filename:  /etc/traefik/traefik-provider.yaml
    watch: true
# /etc/traefik/traefik-provider.yaml
tls:
  stores:
    default:
      defaultCertificate:
        certFile: /etc/pki/tls/certs/reverse-proxy.local.crt
        keyFile: /etc/pki/tls/private/reverse-proxy.local.key
  certificates:
    - certFile: /etc/pki/tls/certs/reverse-proxy.local.crt
      keyFile: /etc/pki/tls/private/reverse-proxy.local.key
      stores: [ default ]
http:
  routers:
    reverseProxy:
      entryPoints: [ webSecure ]
      rule: "Host(`reverse-proxy.local`)"
      service: thirdParty
      tls: {}
  services:
    thirdParty:
      loadBalancer:
        passHostHeader: false
        servers:
          - url: "https://third-party.com:443"

Invocation:

HTTPS_PROXY=https://user@password:proxy.local:443 ./traefik --configfile /etc/traefik/traefik.yaml

I've created a tarball with tests for reproducing this: https://0x0.st/HDOL.tar.gz

If applicable, please paste the log output in DEBUG level

Debug JSON output from Traefik only:

time="2024-02-01T13:32:10+01:00" level=info msg="Configuration loaded from file: /tmp/bug-report-test/traefik.yaml"
{"level":"info","msg":"Traefik version 2.11.0-rc2 built on 2024-01-24T17:46:22Z","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Static configuration loaded {\"global\":{},\"serversTransport\":{\"rootCAs\":[\"./pki/ca.crt\"],\"maxIdleConnsPerHost\":200},\"entryPoints\":{\"webSecure\":{\"address\":\":8443\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":\"10s\"},\"respondingTimeouts\":{\"idleTimeout\":\"3m0s\"}},\"forwardedHeaders\":{},\"http\":{\"tls\":{}},\"http2\":{\"maxConcurrentStreams\":250},\"udp\":{\"timeout\":\"3s\"}}},\"providers\":{\"providersThrottleDuration\":\"2s\",\"file\":{\"watch\":true,\"filename\":\"./traefik-provider.yaml\"}},\"api\":{},\"log\":{\"level\":\"DEBUG\",\"format\":\"json\"},\"accessLog\":{\"format\":\"json\",\"filters\":{},\"fields\":{\"defaultMode\":\"keep\",\"headers\":{\"defaultMode\":\"drop\"}}}}","time":"2024-02-01T13:32:10+01:00"}
{"level":"info","msg":"\nStats collection is disabled.\nHelp us improve Traefik by turning this feature on :)\nMore details on: https://doc.traefik.io/traefik/contributing/data-collection/\n","time":"2024-02-01T13:32:10+01:00"}
{"level":"info","msg":"Starting provider aggregator aggregator.ProviderAggregator","time":"2024-02-01T13:32:10+01:00"}
{"level":"info","msg":"Starting provider *file.Provider","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Starting TCP Server","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"*file.Provider provider configuration: {\"watch\":true,\"filename\":\"./traefik-provider.yaml\"}","time":"2024-02-01T13:32:10+01:00"}
{"level":"info","msg":"Starting provider *traefik.Provider","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"*traefik.Provider provider configuration: {}","time":"2024-02-01T13:32:10+01:00"}
{"level":"info","msg":"Starting provider *acme.ChallengeTLSALPN","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"*acme.ChallengeTLSALPN provider configuration: {}","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Configuration received: {\"http\":{\"routers\":{\"reverse-proxy-1\":{\"entryPoints\":[\"webSecure\"],\"service\":\"third-party-1\",\"rule\":\"Host(`reverse-proxy-1.local`)\",\"tls\":{}},\"reverse-proxy-2\":{\"entryPoints\":[\"webSecure\"],\"service\":\"third-party-2\",\"rule\":\"Host(`reverse-proxy-2.local`)\",\"tls\":{}}},\"services\":{\"third-party-1\":{\"loadBalancer\":{\"servers\":[{\"url\":\"https://third-party.local:8002\"}],\"passHostHeader\":false}},\"third-party-2\":{\"loadBalancer\":{\"servers\":[{\"url\":\"https://third-party.local:8002\"}],\"passHostHeader\":false,\"serversTransport\":\"test\"}}},\"serversTransports\":{\"test\":{\"serverName\":\"third-party.local\"}}},\"tcp\":{},\"udp\":{},\"tls\":{}}","providerName":"file","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Configuration received: {\"http\":{\"services\":{\"api\":{},\"noop\":{}},\"models\":{\"webSecure\":{\"tls\":{}}},\"serversTransports\":{\"default\":{\"maxIdleConnsPerHost\":200}}},\"tcp\":{},\"udp\":{},\"tls\":{}}","providerName":"internal","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Adding certificate for domain(s) reverse-proxy-1.local","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Adding certificate for domain(s) reverse-proxy-2.local","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"No default certificate, fallback to the internal generated certificate","time":"2024-02-01T13:32:10+01:00","tlsStoreName":"default"}
{"entryPointName":"webSecure","level":"debug","middlewareName":"pipelining","middlewareType":"Pipelining","msg":"Creating middleware","routerName":"reverse-proxy-1@file","serviceName":"third-party-1","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Creating load-balancer","routerName":"reverse-proxy-1@file","serviceName":"third-party-1","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Creating server 0 https://third-party.local:8002","routerName":"reverse-proxy-1@file","serverName":0,"serviceName":"third-party-1","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"child https://third-party.local:8002 now UP","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Propagating new UP status","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","middlewareName":"tracing","middlewareType":"TracingForwarder","msg":"Added outgoing tracing middleware third-party-1","routerName":"reverse-proxy-1@file","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","middlewareName":"pipelining","middlewareType":"Pipelining","msg":"Creating middleware","routerName":"reverse-proxy-2@file","serviceName":"third-party-2","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Creating load-balancer","routerName":"reverse-proxy-2@file","serviceName":"third-party-2","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Creating server 0 https://third-party.local:8002","routerName":"reverse-proxy-2@file","serverName":0,"serviceName":"third-party-2","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"child https://third-party.local:8002 now UP","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Propagating new UP status","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","middlewareName":"tracing","middlewareType":"TracingForwarder","msg":"Added outgoing tracing middleware third-party-2","routerName":"reverse-proxy-2@file","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","middlewareName":"traefik-internal-recovery","middlewareType":"Recovery","msg":"Creating middleware","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Adding route for reverse-proxy-2.local with TLS options default","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Adding route for reverse-proxy-1.local with TLS options default","time":"2024-02-01T13:32:10+01:00"}
{"ClientAddr":"127.0.0.1:38870","ClientHost":"127.0.0.1","ClientPort":"38870","ClientUsername":"-","DownstreamContentSize":1,"DownstreamStatus":200,"Duration":49749739,"OriginContentSize":1,"OriginDuration":49692300,"OriginStatus":200,"Overhead":57439,"RequestAddr":"reverse-proxy-1.local:8443","RequestContentSize":0,"RequestCount":1,"RequestHost":"reverse-proxy-1.local","RequestMethod":"GET","RequestPath":"/","RequestPort":"8443","RequestProtocol":"HTTP/2.0","RequestScheme":"https","RetryAttempts":0,"RouterName":"reverse-proxy-1@file","ServiceAddr":"third-party.local:8002","ServiceName":"third-party-1@file","ServiceURL":{"Scheme":"https","Opaque":"","User":null,"Host":"third-party.local:8002","Path":"","RawPath":"","OmitHost":false,"ForceQuery":false,"RawQuery":"","Fragment":"","RawFragment":""},"StartLocal":"2024-02-01T13:32:11.086929538+01:00","StartUTC":"2024-02-01T12:32:11.086929538Z","TLSCipher":"TLS_AES_128_GCM_SHA256","TLSVersion":"1.3","entryPointName":"webSecure","level":"info","msg":"","time":"2024-02-01T13:32:11+01:00"}
{"level":"debug","msg":"'502 Bad Gateway' caused by: proxyconnect tcp: tls: failed to verify certificate: x509: certificate is valid for forward-proxy.local, not third-party.local","time":"2024-02-01T13:32:16+01:00"}
{"ClientAddr":"127.0.0.1:54656","ClientHost":"127.0.0.1","ClientPort":"54656","ClientUsername":"-","DownstreamContentSize":11,"DownstreamStatus":502,"Duration":16929825,"OriginContentSize":11,"OriginDuration":16887597,"OriginStatus":502,"Overhead":42228,"RequestAddr":"reverse-proxy-2.local:8443","RequestContentSize":0,"RequestCount":2,"RequestHost":"reverse-proxy-2.local","RequestMethod":"GET","RequestPath":"/","RequestPort":"8443","RequestProtocol":"HTTP/2.0","RequestScheme":"https","RetryAttempts":0,"RouterName":"reverse-proxy-2@file","ServiceAddr":"third-party.local:8002","ServiceName":"third-party-2@file","ServiceURL":{"Scheme":"https","Opaque":"","User":null,"Host":"third-party.local:8002","Path":"","RawPath":"","OmitHost":false,"ForceQuery":false,"RawQuery":"","Fragment":"","RawFragment":""},"StartLocal":"2024-02-01T13:32:16.148909041+01:00","StartUTC":"2024-02-01T12:32:16.148909041Z","TLSCipher":"TLS_AES_128_GCM_SHA256","TLSVersion":"1.3","entryPointName":"webSecure","level":"info","msg":"","time":"2024-02-01T13:32:16+01:00"}
{"level":"info","msg":"I have to go...","time":"2024-02-01T13:32:21+01:00"}
{"level":"info","msg":"Stopping server gracefully","time":"2024-02-01T13:32:21+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Waiting 10s seconds before killing connections.","time":"2024-02-01T13:32:21+01:00"}
{"entryPointName":"webSecure","level":"error","msg":"accept tcp [::]:8443: use of closed network connection","time":"2024-02-01T13:32:21+01:00"}
{"entryPointName":"webSecure","level":"error","msg":"close tcp [::]:8443: use of closed network connection","time":"2024-02-01T13:32:21+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Entry point webSecure closed","time":"2024-02-01T13:32:21+01:00"}
{"level":"info","msg":"Server stopped","time":"2024-02-01T13:32:21+01:00"}
{"level":"info","msg":"Shutting down","time":"2024-02-01T13:32:21+01:00"}

Full log from test (see tarball):

+ trap 'pkill -P $$' EXIT
+ for fqdn in forward-proxy.local reverse-proxy-1.local third-party.local
+ getent hosts forward-proxy.local
+ grep -qE '^::1|127.0.0.1'
+ for fqdn in forward-proxy.local reverse-proxy-1.local third-party.local
+ getent hosts reverse-proxy-1.local
+ grep -qE '^::1|127.0.0.1'
+ for fqdn in forward-proxy.local reverse-proxy-1.local third-party.local
+ getent hosts third-party.local
+ grep -qE '^::1|127.0.0.1'
+ tinyproxy_pid=638884
+ ./tinyproxy -d -c ./tinyproxy.conf
+ nc_pid=638886
+ echo -n 'HTTP/1.1 200 OK
Content-Length: 1
Content-Type: text/plain

a'
+ nc -l 8001
+ cat
+ stunnel_pid=638888
+ ./stunnel -fd 0
+ traefik_pid=638889
+ sleep 1s
+ TRAEFIK_SERVERSTRANSPORT_ROOTCAS=./pki/ca.crt
+ HTTPS_PROXY=https://forward-proxy.local:8102
+ ./traefik --configfile=./traefik.yaml
NOTICE    Feb 01 13:32:10.076 [638884]: Initializing tinyproxy ...
NOTICE    Feb 01 13:32:10.076 [638884]: Reloading config file
INFO      Feb 01 13:32:10.076 [638884]: Added address [127.0.0.1] to listen addresses.
NOTICE    Feb 01 13:32:10.076 [638884]: Reloading config file finished
INFO      Feb 01 13:32:10.076 [638884]: listen_sock called with addr = '127.0.0.1'
INFO      Feb 01 13:32:10.076 [638884]: trying to listen on host[127.0.0.1], family[2], socktype[1], proto[6]
INFO      Feb 01 13:32:10.076 [638884]: listening on fd [3]
INFO      Feb 01 13:32:10.076 [638884]: Not running as root, so not changing UID/GID.
INFO      Feb 01 13:32:10.076 [638884]: Setting the various signals.
INFO      Feb 01 13:32:10.076 [638884]: Starting main loop. Accepting connections.
2024.02.01 13:32:10 LOG5[ui]: stunnel 5.71 on x86_64-pc-linux-gnu platform
2024.02.01 13:32:10 LOG5[ui]: Compiled/running with OpenSSL 3.0.12 24 Oct 2023
2024.02.01 13:32:10 LOG5[ui]: Threading:PTHREAD Sockets:POLL,IPv6 TLS:ENGINE,OCSP,PSK,SNI
2024.02.01 13:32:10 LOG5[ui]: Reading configuration from descriptor 0
2024.02.01 13:32:10 LOG5[ui]: UTF-8 byte order mark not detected
2024.02.01 13:32:10 LOG5[ui]: FIPS mode disabled
2024.02.01 13:32:10 LOG5[ui]: Configuration successful
time="2024-02-01T13:32:10+01:00" level=info msg="Configuration loaded from file: /tmp/bug-report-test/traefik.yaml"
{"level":"info","msg":"Traefik version 2.11.0-rc2 built on 2024-01-24T17:46:22Z","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Static configuration loaded {\"global\":{},\"serversTransport\":{\"rootCAs\":[\"./pki/ca.crt\"],\"maxIdleConnsPerHost\":200},\"entryPoints\":{\"webSecure\":{\"address\":\":8443\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":\"10s\"},\"respondingTimeouts\":{\"idleTimeout\":\"3m0s\"}},\"forwardedHeaders\":{},\"http\":{\"tls\":{}},\"http2\":{\"maxConcurrentStreams\":250},\"udp\":{\"timeout\":\"3s\"}}},\"providers\":{\"providersThrottleDuration\":\"2s\",\"file\":{\"watch\":true,\"filename\":\"./traefik-provider.yaml\"}},\"api\":{},\"log\":{\"level\":\"DEBUG\",\"format\":\"json\"},\"accessLog\":{\"format\":\"json\",\"filters\":{},\"fields\":{\"defaultMode\":\"keep\",\"headers\":{\"defaultMode\":\"drop\"}}}}","time":"2024-02-01T13:32:10+01:00"}
{"level":"info","msg":"\nStats collection is disabled.\nHelp us improve Traefik by turning this feature on :)\nMore details on: https://doc.traefik.io/traefik/contributing/data-collection/\n","time":"2024-02-01T13:32:10+01:00"}
{"level":"info","msg":"Starting provider aggregator aggregator.ProviderAggregator","time":"2024-02-01T13:32:10+01:00"}
{"level":"info","msg":"Starting provider *file.Provider","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Starting TCP Server","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"*file.Provider provider configuration: {\"watch\":true,\"filename\":\"./traefik-provider.yaml\"}","time":"2024-02-01T13:32:10+01:00"}
{"level":"info","msg":"Starting provider *traefik.Provider","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"*traefik.Provider provider configuration: {}","time":"2024-02-01T13:32:10+01:00"}
{"level":"info","msg":"Starting provider *acme.ChallengeTLSALPN","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"*acme.ChallengeTLSALPN provider configuration: {}","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Configuration received: {\"http\":{\"routers\":{\"reverse-proxy-1\":{\"entryPoints\":[\"webSecure\"],\"service\":\"third-party-1\",\"rule\":\"Host(`reverse-proxy-1.local`)\",\"tls\":{}},\"reverse-proxy-2\":{\"entryPoints\":[\"webSecure\"],\"service\":\"third-party-2\",\"rule\":\"Host(`reverse-proxy-2.local`)\",\"tls\":{}}},\"services\":{\"third-party-1\":{\"loadBalancer\":{\"servers\":[{\"url\":\"https://third-party.local:8002\"}],\"passHostHeader\":false}},\"third-party-2\":{\"loadBalancer\":{\"servers\":[{\"url\":\"https://third-party.local:8002\"}],\"passHostHeader\":false,\"serversTransport\":\"test\"}}},\"serversTransports\":{\"test\":{\"serverName\":\"third-party.local\"}}},\"tcp\":{},\"udp\":{},\"tls\":{}}","providerName":"file","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Configuration received: {\"http\":{\"services\":{\"api\":{},\"noop\":{}},\"models\":{\"webSecure\":{\"tls\":{}}},\"serversTransports\":{\"default\":{\"maxIdleConnsPerHost\":200}}},\"tcp\":{},\"udp\":{},\"tls\":{}}","providerName":"internal","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Adding certificate for domain(s) reverse-proxy-1.local","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Adding certificate for domain(s) reverse-proxy-2.local","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"No default certificate, fallback to the internal generated certificate","time":"2024-02-01T13:32:10+01:00","tlsStoreName":"default"}
{"entryPointName":"webSecure","level":"debug","middlewareName":"pipelining","middlewareType":"Pipelining","msg":"Creating middleware","routerName":"reverse-proxy-1@file","serviceName":"third-party-1","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Creating load-balancer","routerName":"reverse-proxy-1@file","serviceName":"third-party-1","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Creating server 0 https://third-party.local:8002","routerName":"reverse-proxy-1@file","serverName":0,"serviceName":"third-party-1","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"child https://third-party.local:8002 now UP","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Propagating new UP status","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","middlewareName":"tracing","middlewareType":"TracingForwarder","msg":"Added outgoing tracing middleware third-party-1","routerName":"reverse-proxy-1@file","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","middlewareName":"pipelining","middlewareType":"Pipelining","msg":"Creating middleware","routerName":"reverse-proxy-2@file","serviceName":"third-party-2","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Creating load-balancer","routerName":"reverse-proxy-2@file","serviceName":"third-party-2","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Creating server 0 https://third-party.local:8002","routerName":"reverse-proxy-2@file","serverName":0,"serviceName":"third-party-2","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"child https://third-party.local:8002 now UP","time":"2024-02-01T13:32:10+01:00"}
{"level":"debug","msg":"Propagating new UP status","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","middlewareName":"tracing","middlewareType":"TracingForwarder","msg":"Added outgoing tracing middleware third-party-2","routerName":"reverse-proxy-2@file","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","middlewareName":"traefik-internal-recovery","middlewareType":"Recovery","msg":"Creating middleware","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Adding route for reverse-proxy-2.local with TLS options default","time":"2024-02-01T13:32:10+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Adding route for reverse-proxy-1.local with TLS options default","time":"2024-02-01T13:32:10+01:00"}
+ echo -e '\n\n############## This should work ##############\n\n'


############## This should work ##############


+ curl -sv --cacert pki/ca.crt https://reverse-proxy-1.local:8443/
2024.02.01 13:32:10 LOG5[ui]: stunnel 5.71 on x86_64-pc-linux-gnu platform
2024.02.01 13:32:10 LOG5[ui]: Compiled/running with OpenSSL 3.0.12 24 Oct 2023
2024.02.01 13:32:10 LOG5[ui]: Threading:PTHREAD Sockets:POLL,IPv6 TLS:ENGINE,OCSP,PSK,SNI
2024.02.01 13:32:10 LOG5[ui]: Reading configuration from descriptor 0
2024.02.01 13:32:10 LOG5[ui]: UTF-8 byte order mark not detected
2024.02.01 13:32:10 LOG5[ui]: FIPS mode disabled
2024.02.01 13:32:10 LOG5[ui]: Configuration successful
*   Trying 127.0.0.1:8443...
* Connected to reverse-proxy-1.local (127.0.0.1) port 8443
* ALPN: curl offers h2,http/1.1
} [5 bytes data]
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
*  CAfile: pki/ca.crt
*  CApath: none
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Server hello (2):
{ [122 bytes data]
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
{ [15 bytes data]
* TLSv1.3 (IN), TLS handshake, Certificate (11):
{ [821 bytes data]
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
{ [264 bytes data]
* TLSv1.3 (IN), TLS handshake, Finished (20):
{ [36 bytes data]
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
} [1 bytes data]
* TLSv1.3 (OUT), TLS handshake, Finished (20):
} [36 bytes data]
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256
* ALPN: server accepted h2
* Server certificate:
*  subject: CN=reverse-proxy-1.local
*  start date: Feb  1 11:46:58 2024 GMT
*  expire date: Mar  2 11:46:58 2024 GMT
*  subjectAltName: host "reverse-proxy-1.local" matched cert's "reverse-proxy-1.local"
*  issuer: CN=Dumy CA
*  SSL certificate verify ok.
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
{ [122 bytes data]
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://reverse-proxy-1.local:8443/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: reverse-proxy-1.local:8443]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.4.0]
* [HTTP/2] [1] [accept: */*]
} [5 bytes data]
> GET / HTTP/2
> Host: reverse-proxy-1.local:8443
> User-Agent: curl/8.4.0
> Accept: */*
> 
{ [5 bytes data]
2024.02.01 13:32:11 LOG5[0]: Service [forward-proxy] accepted connection from 127.0.0.1:46230
2024.02.01 13:32:11 LOG5[0]: s_connect: connected 127.0.0.1:8101
2024.02.01 13:32:11 LOG5[0]: Service [forward-proxy] connected remote server from 127.0.0.1:35880
CONNECT   Feb 01 13:32:11.091 [638884]: Connect (file descriptor 4): 127.0.0.1
CONNECT   Feb 01 13:32:11.091 [638884]: Request (file descriptor 4): CONNECT third-party.local:8002 HTTP/1.1
INFO      Feb 01 13:32:11.091 [638884]: No upstream proxy for third-party.local
INFO      Feb 01 13:32:11.091 [638884]: opensock: opening connection to third-party.local:8002
INFO      Feb 01 13:32:11.091 [638884]: opensock: getaddrinfo returned for third-party.local:8002
CONNECT   Feb 01 13:32:11.091 [638884]: Established connection to host "third-party.local" using file descriptor 5.
INFO      Feb 01 13:32:11.091 [638884]: Not sending client headers to remote machine
2024.02.01 13:32:11 LOG5[1]: Service [third-party] accepted connection from 127.0.0.1:50902
2024.02.01 13:32:11 LOG5[1]: s_connect: connected 127.0.0.1:8001
2024.02.01 13:32:11 LOG5[1]: Service [third-party] connected remote server from 127.0.0.1:56214
GET / HTTP/1.1
Host: third-party.local:8002
User-Agent: curl/8.4.0
Accept: */*
X-Forwarded-For: 127.0.0.1
X-Forwarded-Host: reverse-proxy-1.local:8443
X-Forwarded-Port: 8443
X-Forwarded-Proto: https
X-Forwarded-Server: <redacted>
X-Real-Ip: 127.0.0.1
Accept-Encoding: gzip

{"ClientAddr":"127.0.0.1:38870","ClientHost":"127.0.0.1","ClientPort":"38870","ClientUsername":"-","DownstreamContentSize":1,"DownstreamStatus":200,"Duration":49749739,"OriginContentSize":1,"OriginDuration":49692300,"OriginStatus":200,"Overhead":57439,"RequestAddr":"reverse-proxy-1.local:8443","RequestContentSize":0,"RequestCount":1,"RequestHost":"reverse-proxy-1.local","RequestMethod":"GET","RequestPath":"/","RequestPort":"8443","RequestProtocol":"HTTP/2.0","RequestScheme":"https","RetryAttempts":0,"RouterName":"reverse-proxy-1@file","ServiceAddr":"third-party.local:8002","ServiceName":"third-party-1@file","ServiceURL":{"Scheme":"https","Opaque":"","User":null,"Host":"third-party.local:8002","Path":"","RawPath":"","OmitHost":false,"ForceQuery":false,"RawQuery":"","Fragment":"","RawFragment":""},"StartLocal":"2024-02-01T13:32:11.086929538+01:00","StartUTC":"2024-02-01T12:32:11.086929538Z","TLSCipher":"TLS_AES_128_GCM_SHA256","TLSVersion":"1.3","entryPointName":"webSecure","level":"info","msg":"","time":"2024-02-01T13:32:11+01:00"}
< HTTP/2 200 
< content-type: text/plain
< content-length: 1
< date: Thu, 01 Feb 2024 12:32:11 GMT
< 
{ [1 bytes data]
* Connection #0 to host reverse-proxy-1.local left intact
a+ sleep 5s
2024.02.01 13:32:11 LOG5[0]: Service [forward-proxy] accepted connection from 127.0.0.1:46230
2024.02.01 13:32:11 LOG5[0]: s_connect: connected 127.0.0.1:8101
2024.02.01 13:32:11 LOG5[0]: Service [forward-proxy] connected remote server from 127.0.0.1:35880
2024.02.01 13:32:11 LOG5[1]: Service [third-party] accepted connection from 127.0.0.1:50902
2024.02.01 13:32:11 LOG5[1]: s_connect: connected 127.0.0.1:8001
2024.02.01 13:32:11 LOG5[1]: Service [third-party] connected remote server from 127.0.0.1:56214
+ nc_pid=638919
+ echo -e '\n\n############## This breaks ##############\n\n'


############## This breaks ##############


+ curl -sv --cacert pki/ca.crt https://reverse-proxy-2.local:8443/
+ echo -n 'HTTP/1.1 200 OK
Content-Length: 1
Content-Type: text/plain

a'
+ nc -l 8001
*   Trying 127.0.0.1:8443...
* Connected to reverse-proxy-2.local (127.0.0.1) port 8443
* ALPN: curl offers h2,http/1.1
} [5 bytes data]
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
*  CAfile: pki/ca.crt
*  CApath: none
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Server hello (2):
{ [122 bytes data]
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
{ [15 bytes data]
* TLSv1.3 (IN), TLS handshake, Certificate (11):
{ [821 bytes data]
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
{ [264 bytes data]
* TLSv1.3 (IN), TLS handshake, Finished (20):
{ [36 bytes data]
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
} [1 bytes data]
* TLSv1.3 (OUT), TLS handshake, Finished (20):
} [36 bytes data]
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256
* ALPN: server accepted h2
* Server certificate:
*  subject: CN=reverse-proxy-2.local
*  start date: Feb  1 11:46:58 2024 GMT
*  expire date: Mar  2 11:46:58 2024 GMT
*  subjectAltName: host "reverse-proxy-2.local" matched cert's "reverse-proxy-2.local"
*  issuer: CN=Dumy CA
*  SSL certificate verify ok.
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
{ [122 bytes data]
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://reverse-proxy-2.local:8443/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: reverse-proxy-2.local:8443]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.4.0]
* [HTTP/2] [1] [accept: */*]
} [5 bytes data]
> GET / HTTP/2
> Host: reverse-proxy-2.local:8443
> User-Agent: curl/8.4.0
> Accept: */*
> 
{ [5 bytes data]
2024.02.01 13:32:16 LOG5[2]: Service [forward-proxy] accepted connection from 127.0.0.1:48324
{"level":"debug","msg":"'502 Bad Gateway' caused by: proxyconnect tcp: tls: failed to verify certificate: x509: certificate is valid for forward-proxy.local, not third-party.local","time":"2024-02-01T13:32:16+01:00"}
2024.02.01 13:32:16 LOG3[2]: SSL_accept: ssl/record/rec_layer_s3.c:1586: error:0A000412:SSL routines::sslv3 alert bad certificat{"ClientAddr":"127.0.0.1:54656","ClientHost":"127.0.0.1","ClientPort":"54656","ClientUsername":"-","DownstreamContentSize":11,"DownstreamStatus":502,"Duration":16929825,"OriginContentSize":11,"OriginDuration":16887597,"OriginStatus":502,"Overhead":42228,"RequestAddr":"reverse-proxy-2.local:8443","RequestContentSize":0,"RequestCount":2,"RequestHost":"reverse-proxy-2.local","RequestMethod":"GET","RequestPath":"/","RequestPort":"8443","RequestProtocol":"HTTP/2.0","RequestScheme":"https","RetryAttempts":0,"RouterName":"reverse-proxy-2@file","ServiceAddr":"third-party.local:8002","ServiceName":"third-party-2@file","ServiceURL":{"Scheme":"https","Opaque":"","User":null,"Host":"third-party.local:8002","Path":"","RawPath":"","OmitHost":false,"ForceQuery":false,"RawQuery":"","Fragment":"","RawFragment":""},"StartLocal":"2024-02-01T13:32:16.148909041+01:00","StartUTC":"2024-02-01T12:32:16.148909041Z","TLSCipher":"TLS_AES_128_GCM_SHA256","TLSVersion":"1.3","entryPointName":"webSecure","level":"info","msg":"","time":"2024-02-01T13:32:16+01:00"}
e
2024.02.01 13:32:16 LOG5[2]: Connection reset/closed: 0 byte(s) sent to TLS, 0 byte(s) sent to socket
< HTTP/2 502 
< content-type: text/plain; charset=utf-8
< content-length: 11
< date: Thu, 01 Feb 2024 12:32:16 GMT
< 
{ [11 bytes data]
* Connection #0 to host reverse-proxy-2.local left intact
Bad Gateway+ sleep 5s
2024.02.01 13:32:16 LOG5[2]: Service [forward-proxy] accepted connection from 127.0.0.1:48324
2024.02.01 13:32:16 LOG3[2]: SSL_accept: ssl/record/rec_layer_s3.c:1586: error:0A000412:SSL routines::sslv3 alert bad certificate
2024.02.01 13:32:16 LOG5[2]: Connection reset/closed: 0 byte(s) sent to TLS, 0 byte(s) sent to socket
+ echo Bye
Bye
+ kill 638884 638919 638888 638889
+ pkill -P 638876
NOTICE    Feb 01 13:32:21.170 [638884]: Shutting down.
INFO      Feb 01 13:32:21.170 [638884]: trying to bring down 1 threads...
ERROR     Feb 01 13:32:21.170 [638884]: relay_connection: poll() error "Interrupted system call". Closing connection (client_fd:4, server_fd:5)
INFO      Feb 01 13:32:21.170 [638884]: Closed connection between local client (fd:4) and remote client (fd:5)
2024.02.01 13:32:21 LOG5[ui]: Terminated
{"level":"info","msg":"I have to go...","time":"2024-02-01T13:32:21+01:00"}
{"level":"info","msg":"Stopping server gracefully","time":"2024-02-01T13:32:21+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Waiting 10s seconds before killing connections.","time":"2024-02-01T13:32:21+01:00"}
2024.02.01 13:32:21 LOG5[ui]: Terminated
{"entryPointName":"webSecure","level":"error","msg":"accept tcp [::]:8443: use of closed network connection","time":"2024-02-01T13:32:21+01:00"}
{"entryPointName":"webSecure","level":"error","msg":"close tcp [::]:8443: use of closed network connection","time":"2024-02-01T13:32:21+01:00"}
{"entryPointName":"webSecure","level":"debug","msg":"Entry point webSecure closed","time":"2024-02-01T13:32:21+01:00"}
{"level":"info","msg":"Server stopped","time":"2024-02-01T13:32:21+01:00"}
{"level":"info","msg":"Shutting down","time":"2024-02-01T13:32:21+01:00"}
+ wait
+ pkill -P 638876
@emilevauge emilevauge added the kind/bug/possible a possible bug that needs analysis before it is confirmed or fixed. label Feb 1, 2024
@kevinpollet kevinpollet added kind/bug/confirmed a confirmed bug (reproducible). area/server and removed status/0-needs-triage kind/bug/possible a possible bug that needs analysis before it is confirmed or fixed. labels Feb 1, 2024
@juliens juliens mentioned this issue Feb 8, 2024
Open
2 tasks
@kevinpollet
Copy link
Member

kevinpollet commented Feb 8, 2024 •
edited
Loading

Hello @chrillefkr and thanks for bringing this issue to our attention,

After conducting investigations, we have determined that the problem is not with Traefik, but with Go itself. Within the net/http stack, the TLS configuration utilized for connecting to the backend is also employed for connecting to the HTTPS_PROXY.

Consequently, configuring the serverName results in the proxyconnect tcp: tls: failed to verify certificate error because the HTTPS_PROXY certificate does not match the expected serverName.

We will now explore potential solutions to rectify this issue within the Go net/http stack.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@kevinpollet kevinpollet

Labels
area/server kind/bug/confirmed a confirmed bug (reproducible).
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@kevinpollet @chrillefkr @emilevauge @traefiker