Certificate verify failed when using a proxy for the http sink

ntim commented 2 years ago

A note for the community

Please vote on this issue by adding a 👍 reaction to the original issue to help the community and maintainers prioritize this request
If you are interested in working on this issue or have submitted a pull request, please leave a comment

Problem

When enabling a proxy for the http sink, the TLS handshake with an internal PKI always fails (see debug output of the client below).

Simulating the same request using openssl succeeds:

openssl s_client -connect 172.17.0.2:10443 -CAfile ca.crt -cert client.crt -key client.key --proxy 172.17.0.3:3128

The example above uses client certificate auth. Hence the proxy in this setup is transparent for TLS (typical setup in our company). Nevertheless, the problem exists also when disabling the client certificate authentication. In this case, I could get TLS for the http sink to work by loading the CA cert into the openssl certificate store. It seems, that the implementation of the proxy simply forgets all TLS settings in case the proxy is enabled.

The configuration given below is actually a shell script which creates a self signed CA, signs certificates and runs three docker containers:

graph LR;
    client(vector with demo log source and http sink)--port 3128 -->proxy(squid);
    proxy-- port 10443 -->server(vector with http source and console sink);

Thanks in advance!

Configuration

#!/bin/bash
set -x
# CA
openssl genrsa -out ca.key 4096
openssl req -new -x509 -days 365 -key ca.key -out ca.crt -subj /CN=CA/L=DE
# Client cert
openssl genrsa -out client.key 4096
openssl req -new -key client.key -out client.csr -subj /CN=client
cat > client_cert_ext.cnf <<EOF
basicConstraints = CA:FALSE
nsCertType = client, email
nsComment = "OpenSSL Generated Client Certificate"
subjectKeyIdentifier = hash
authorityKeyIdentifier = keyid,issuer
keyUsage = critical, nonRepudiation, digitalSignature, keyEncipherment
extendedKeyUsage = clientAuth, emailProtection
EOF
openssl x509 -req -in client.csr -CA ca.crt -CAkey ca.key -out client.crt \
    -CAcreateserial -days 365 -sha256 -extfile client_cert_ext.cnf
# Server cert
openssl genrsa -out server.key 4096
cat > server_cert_ext.cnf <<EOF
[req]
distinguished_name = req_distinguished_name
req_extensions = v3_req
prompt = no

[req_distinguished_name]
C   = DE
CN  = server

[v3_req]
basicConstraints = CA:FALSE
nsCertType = server
nsComment = "OpenSSL Generated Server Certificate"
subjectKeyIdentifier = hash
keyUsage = critical, digitalSignature, keyEncipherment
extendedKeyUsage = serverAuth
subjectAltName = @alt_names

[alt_names]
IP.1 = 172.17.0.2
DNS.1 = servers
EOF
openssl req -new -key server.key -out server.csr -config server_cert_ext.cnf
openssl x509 -req -in server.csr -CA ca.crt -CAkey ca.key -out server.crt \
    -CAcreateserial -days 365 -sha256 -extfile server_cert_ext.cnf -extensions v3_req
# Vector Server
mkdir -p server
cp ca.crt server.key server.crt server/
cat > server/config.yaml <<EOF
sources:
  http_source:
    type: http
    address: 0.0.0.0:10443
    encoding: json
    path: /
    strict_path: true
    path_key: path
    tls:
      enabled: true
      ca_file: /etc/vector/ca.crt
      crt_file: /etc/vector/server.crt
      key_file: /etc/vector/server.key
      verify_certificate: true
    method: PUT
sinks:
  console_sink:
    type: console
    inputs: [http_source]
    target: stdout
    encoding:
      codec: json
EOF
sudo docker pull timberio/vector:0.23.0-debian
sudo docker run --detach --name server --publish 10443:10443 --ip 172.17.0.2 --rm \
    --mount type=bind,source=$(pwd)/server,destination=/etc/vector \
    timberio/vector:0.23.0-debian \
    --config-dir /etc/vector
# Test connection with:
# openssl s_client -connect 172.17.0.2:10443 -CAfile ca.crt -cert client.crt -key client.key
# HTTP proxy without TLS interception
mkdir -p proxy
cat > proxy/squid.conf <<EOF
http_port 3128
http_access allow all
EOF
sudo docker pull sameersbn/squid:3.5.27-2
sudo docker run --detach --name proxy --publish 3128:3128 --ip 172.17.0.3 --rm \
    --mount type=bind,source=$(pwd)/proxy/squid.conf,destination=/etc/squid/squid.conf \
    sameersbn/squid:3.5.27-2
# Test connection with:
# openssl s_client -connect 172.17.0.2:10443 -CAfile ca.crt -cert client.crt -key client.key --proxy 172.17.0.3:3128
# Vector Client
mkdir -p client
cp ca.crt client.key client.crt client/
cat > client/config.yaml <<EOF
sources:
  demo_source:
    type: demo_logs
    format: json
sinks:
  http_sink:
    type: http
    inputs: [demo_source]
    method: put
    uri: "https://172.17.0.2:10443"
    encoding:
      codec: json
    tls:
      ca_file: /etc/vector/ca.crt
      crt_file: /etc/vector/client.crt
      key_file: /etc/vector/client.key
      verify_certificate: true
    proxy:
      enabled: true
      http: "http://172.17.0.3:3128"
      https: "http://172.17.0.3:3128"
EOF
sudo docker run --detach --name client --ip 172.17.0.4 --rm \
    --env RUST_BACKTRACE=full \
    --mount type=bind,source=$(pwd)/client,destination=/etc/vector \
    timberio/vector:0.23.0-debian \
    --config-dir /etc/vector -vvv

Version

0.23.0

Debug Output

2022-07-22T11:24:10.522859Z TRACE vector: Beep.
2022-07-22T11:24:10.522908Z DEBUG sink{component_kind="sink" component_id=http_sink component_type=http component_name=http_sink}: vector::utilization: utilization=0.00009110134158646364
2022-07-22T11:24:10.522932Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector::internal_events::common: Bytes received. byte_size=0 protocol=none
2022-07-22T11:24:10.522940Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector::internal_events::demo_logs: Received one event.
2022-07-22T11:24:10.522964Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector_common::internal_event::events_received: Events received. count=1 byte_size=1026
2022-07-22T11:24:10.522975Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector_buffers::topology::channel::limited_queue: Sent item.
2022-07-22T11:24:10.522980Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector_common::internal_event::events_sent: Events sent. count=1 byte_size=687 output=_default
2022-07-22T11:24:10.522993Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector_buffers::topology::channel::limited_queue: Sent item.
2022-07-22T11:24:10.523001Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector_core::fanout: Sent item to fanout.
2022-07-22T11:24:10.523006Z TRACE sink{component_kind="sink" component_id=http_sink component_type=http component_name=http_sink}: vector_common::internal_event::events_received: Events received. count=1 byte_size=687
2022-07-22T11:24:10.568524Z DEBUG sink{component_kind="sink" component_id=http_sink component_type=http component_name=http_sink}:request{request_id=0}:http: vector::internal_events::http_client: Sending HTTP request. uri=https://172.17.0.2:10443/ method=PUT version=HTTP/1.1 headers={"content-type": "application/json", "user-agent": "Vector/0.23.0 (x86_64-unknown-linux-gnu 38c2435 2022-07-11)", "accept-encoding": "identity"} body=[716 bytes]
2022-07-22T11:24:10.578150Z ERROR sink{component_kind="sink" component_id=http_sink component_type=http component_name=http_sink}:request{request_id=0}:http: vector::internal_events::http_client: HTTP error. error=error trying to connect: error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed:ssl/statem/statem_clnt.c:1921: error_type="request_failed" stage="processing"
2022-07-22T11:24:10.578206Z  WARN sink{component_kind="sink" component_id=http_sink component_type=http component_name=http_sink}:request{request_id=0}: vector::sinks::util::retries: Retrying after error. error=Failed to make HTTP(S) request: error trying to connect: error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed:ssl/statem/statem_clnt.c:1921:
2022-07-22T11:24:10.578220Z DEBUG sink{component_kind="sink" component_id=http_sink component_type=http component_name=http_sink}:request{request_id=0}: vector::sinks::util::retries: Retrying request. delay_ms=3000
2022-07-22T11:24:11.523012Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector::internal_events::common: Bytes received. byte_size=0 protocol=none
2022-07-22T11:24:11.523036Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector::internal_events::demo_logs: Received one event.
2022-07-22T11:24:11.523060Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector_common::internal_event::events_received: Events received. count=1 byte_size=1029
2022-07-22T11:24:11.523071Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector_buffers::topology::channel::limited_queue: Sent item.
2022-07-22T11:24:11.523076Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector_common::internal_event::events_sent: Events sent. count=1 byte_size=690 output=_default
2022-07-22T11:24:11.523091Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector_buffers::topology::channel::limited_queue: Sent item.
2022-07-22T11:24:11.523098Z TRACE source{component_kind="source" component_id=demo_source component_type=demo_logs component_name=demo_source}: vector_core::fanout: Sent item to fanout.
2022-07-22T11:24:11.523106Z TRACE sink{component_kind="sink" component_id=http_sink component_type=http component_name=http_sink}: vector_common::internal_event::events_received: Events received. count=1 byte_size=690
2022-07-22T11:24:11.523131Z TRACE vector: Beep.

Example Data

No response

Additional Context

in the actual setup, vector is run in kubernetes using the distroless image
the setup above works when disabling the proxy in the http sink configuration

References

13238

jszwedko commented 2 years ago

Thanks for this detailed issue report @ntim !

ntim commented 2 years ago

Digging through the hyper-proxy implementation I found out that the ProxyConnector does not make use of the TlsConnector including the user supplied settings. Instead, a new TlsConnector is created in the constructor.

jszwedko commented 2 years ago

Closed by https://github.com/vectordotdev/vector/pull/13759. Thanks again for contributing that @ntim !

ntim commented 2 years ago

My treat! We migrated from logstash to vector and increased throughput by a factor of 15 while having much less resource consumption!

vectordotdev / vector