connect to server through WebSocket with SSL, the higress gateway response 503 Service Unavailable

chaoyoung commented 10 months ago

Ⅰ. Issue Description

curl -v https://uass.dev.com
*   Trying 10.20.30.0:443...
* Connected to uass.dev.com (10.20.30.0) port 443 (#0)
* ALPN: offers h2,http/1.1
* (304) (OUT), TLS handshake, Client hello (1):
*  CAfile: /etc/ssl/cert.pem
*  CApath: none
* (304) (IN), TLS handshake, Server hello (2):
* (304) (IN), TLS handshake, Unknown (8):
* (304) (IN), TLS handshake, Certificate (11):
* (304) (IN), TLS handshake, CERT verify (15):
* (304) (IN), TLS handshake, Finished (20):
* (304) (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / AEAD-CHACHA20-POLY1305-SHA256
* ALPN: server accepted http/1.1
* Server certificate:
*  subject: [NONE]
*  start date: Aug 28 17:52:04 2023 GMT
*  expire date: Nov 26 17:52:04 2023 GMT
*  subjectAltName: host "uass.dev.com" matched cert's "uass.dev.com"
*  issuer: C=CN; ST=ZheJiang; L=HangZhou; O=XXX Inc.; OU=DevOps; CN=XXX DevOps Self Signed Root CA
*  SSL certificate verify ok.
* using HTTP/1.1
> GET / HTTP/1.1
> Host: uass.dev.com
> User-Agent: curl/8.1.2
> Accept: */*
>
< HTTP/1.1 503 Service Unavailable
< content-length: 273
< content-type: text/plain
< date: Fri, 01 Sep 2023 05:57:13 GMT
< server: istio-envoy
<
* Connection #0 to host uass.dev.com left intact
upstream connect error or disconnect/reset before headers. reset reason: connection failure, transport failure reason: TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO%

Ⅱ. Describe what happened

higress gateway response 503 Service Unavailable and some SSL Error.

higress-gateway log:

{"authority":"uass.dev.com","bytes_received":"0","bytes_sent":"273","downstream_local_address":"10.244.120.141:443","downstream_remote_address":"10.20.0.105:11437","duration":"43","istio_policy_status":"-","method":"GET","path":"/","protocol":"HTTP/1.1","request_id":"f5844422-1ab0-4816-b0b3-6dd3c04addae","requested_server_name":"uass.dev.com","response_code":"503","response_flags":"UF,URX","route_name":"default/freeswitch-uas-wss","start_time":"2023-09-01T05:41:51.677Z","trace_id":"e3143f92fd68377c77d6e5098baaaad7","upstream_cluster":"outbound|7443||freeswitch-uas.default.svc.cluster.local","upstream_host":"10.20.0.104:7443","upstream_local_address":"-","upstream_service_time":"-","upstream_transport_failure_reason":"TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36","x_forwarded_for":"10.20.0.105"}

Problems related to envoy: https://github.com/envoyproxy/envoy/issues/13047
Problems related to istio: https://github.com/istio/istio/issues/36301

Ⅲ. Describe what you expected to happen

No Error.

Ⅳ. How to reproduce it (as minimally and precisely as possible)

xxx
xxx
xxx

Ⅴ. Anything else we need to know?

Ⅵ. Environment:

Higress version: 1.1.1
OS : CentOS 7
Others:

johnlanni commented 10 months ago

https://github.com/istio/istio/issues/36301#issuecomment-983413360

可以试下这个方式，需要先安装 istio crd，并开启 higress 的 istio api 支持，可以参考：https://higress.io/zh-cn/docs/ops/deploy-by-helm#%E6%94%AF%E6%8C%81-istio-crd%E5%8F%AF%E9%80%89

chaoyoung commented 10 months ago

@johnlanni istio CRDs is enabled

johnlanni commented 10 months ago

@chaoyoung 试一下这个enovyfilter

apiVersion: networking.istio.io/v1alpha3
kind: EnvoyFilter
metadata:
  name: enable-secp384r1
spec:
  configPatches:
  - applyTo: CLUSTER
    match:
      cluster:
        # 例如  service:  foobar.default.svc.cluster.local
        service: <your service name>
      context: GATEWAY
    patch:
      operation: MERGE
      value:
        transport_socket:
          name: envoy.transport_sockets.tls
          typed_config:
            "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
            common_tls_context:
              tls_params:
                ecdh_curves:
                - secp384r1

chaoyoung commented 10 months ago

@johnlanni it doesn't work.

apiVersion: networking.k8s.io/v1
kind: Ingress
metadata:
  name: freeswitch-uas
  namespace: default
  annotations:
    cert-manager.io/cluster-issuer: "ca-issuer"
    nginx.ingress.kubernetes.io/proxy-http-version: "1.1"
    nginx.ingress.kubernetes.io/proxy-connect-timeout: "10"
    nginx.ingress.kubernetes.io/proxy-send-timeout: "3600"
    nginx.ingress.kubernetes.io/proxy-read-timeout: "3600"
    nginx.ingress.kubernetes.io/ssl-redirect: "false"
    nginx.ingress.kubernetes.io/secure-backends: "true"
    nginx.ingress.kubernetes.io/backend-protocol: "HTTPS"
    nginx.ingress.kubernetes.io/use-regex: "true"
    nginx.ingress.kubernetes.io/rewrite-target: "/"
    nginx.ingress.kubernetes.io/enable-websocket: "true"
    nginx.ingress.kubernetes.io/websocket-services : "freeswitch-uas"
    nginx.ingress.kubernetes.io/configuration-snippet: |
      proxy_http_version 1.1;
      proxy_set_header Upgrade "$http_upgrade";
      proxy_set_header Connection "Upgrade";
      proxy_set_header Host $host;
      proxy_set_header X-Forwarded-Host $http_host;
      proxy_set_header X-Forwarded-Proto $scheme;
      proxy_set_header X-Forwarded-For $remote_addr;
      proxy_set_header X-Real-IP $remote_addr;
spec:
  ingressClassName: higress
  tls:
  - hosts:
    - uas.dev.com
    secretName: uas-dev-com-tls
  rules:
  - host: uas.dev.com
    http:
      paths:
      - path: /ws
        pathType: Prefix
        backend:
          service:
            name: freeswitch-uas
            port:
              name: ws
      - path: /wss
        pathType: Prefix
        backend:
          service:
            name: freeswitch-uas
            port:
              name: wss
---
apiVersion: networking.istio.io/v1alpha3
kind: EnvoyFilter
metadata:
  name: freeswitch-uas-enable-secp384r1
  namespace: default
spec:
  configPatches:
  - applyTo: CLUSTER
    match:
      cluster:
        service: freeswitch-uas.default.svc.cluster.local
      context: GATEWAY
    patch:
      operation: MERGE
      value:
        transport_socket:
          name: envoy.transport_sockets.tls
          typed_config:
            "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
            common_tls_context:
              tls_params:
                ecdh_curves:
                - secp384r1
---
apiVersion: v1
kind: Service
metadata:
  name: freeswitch-uas
  namespace: default
  labels:
    app: freeswitch-uas
spec:
  type: ClusterIP
  selector:
    app: freeswitch-uas
  ports:
  - name: 'http'
    port: 8021
    protocol: TCP
    targetPort: 8021
  - name: ws
    port: 5066
    protocol: TCP
    targetPort: 5066
  - name: wss
    port: 7443
    protocol: TCP
    targetPort: 7443

➜ curl -kv https://uas.dev.com/wss -H 'Connection: Upgrade' -H 'Upgrade: websocket' -H 'Sec-Websocket-Protocol: sip' -H 'Sec-Websocket-Key: iDA5KxziwFqKlGYaO3EXSg=='
*   Trying 10.20.30.0:443...
* Connected to uas.dev.com (10.20.30.0) port 443 (#0)
* ALPN: offers h2,http/1.1
* (304) (OUT), TLS handshake, Client hello (1):
* (304) (IN), TLS handshake, Server hello (2):
* (304) (IN), TLS handshake, Unknown (8):
* (304) (IN), TLS handshake, Certificate (11):
* (304) (IN), TLS handshake, CERT verify (15):
* (304) (IN), TLS handshake, Finished (20):
* (304) (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / AEAD-CHACHA20-POLY1305-SHA256
* ALPN: server accepted http/1.1
* Server certificate:
*  subject: [NONE]
*  start date: Sep  1 16:28:36 2023 GMT
*  expire date: Nov 30 16:28:36 2023 GMT
*  issuer: C=CN; ST=ZheJiang; L=HangZhou; O=XXX Inc.; OU=DevOps; CN=XXX DevOps Self Signed Root CA
*  SSL certificate verify ok.
* using HTTP/1.1
> GET /wss HTTP/1.1
> Host: uas.dev.com
> User-Agent: curl/8.1.2
> Accept: */*
> Connection: Upgrade
> Upgrade: websocket
> Sec-Websocket-Protocol: sip
> Sec-Websocket-Key: iDA5KxziwFqKlGYaO3EXSg==
>
< HTTP/1.1 503 Service Unavailable
< content-length: 273
< content-type: text/plain
< date: Sat, 02 Sep 2023 15:30:46 GMT
< server: istio-envoy
< connection: close
<
* Closing connection 0
upstream connect error or disconnect/reset before headers. reset reason: connection failure, transport failure reason: TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO%

johnlanni commented 10 months ago

@chaoyoung 可以提供下 freeswitch-uas 这个服务的镜像吗，我这边测试复现下

chaoyoung commented 10 months ago

@chaoyoung 可以提供下 freeswitch-uas 这个服务的镜像吗，我这边测试复现下

@johnlanni

apiVersion: networking.k8s.io/v1
kind: Ingress
metadata:
  name: uas-test
  namespace: default
  annotations:
    cert-manager.io/cluster-issuer: "ca-issuer"
    nginx.ingress.kubernetes.io/ssl-redirect: "false"
    nginx.ingress.kubernetes.io/secure-backends: "true"
    nginx.ingress.kubernetes.io/backend-protocol: "HTTPS"
    nginx.ingress.kubernetes.io/use-regex: "true"
    nginx.ingress.kubernetes.io/rewrite-target: "/"
    nginx.ingress.kubernetes.io/enable-websocket: "true"
    nginx.ingress.kubernetes.io/websocket-services : "uas-test"
    nginx.ingress.kubernetes.io/configuration-snippet: |
      proxy_http_version 1.1;
      proxy_set_header Upgrade "$http_upgrade";
      proxy_set_header Connection "Upgrade";
      proxy_set_header Host $host;
      proxy_set_header X-Forwarded-Host $http_host;
      proxy_set_header X-Forwarded-Proto $scheme;
      proxy_set_header X-Forwarded-For $remote_addr;
      proxy_set_header X-Real-IP $remote_addr;
    nginx.ingress.kubernetes.io/proxy-http-version: "1.1"
    nginx.ingress.kubernetes.io/proxy-connect-timeout: "10"
    nginx.ingress.kubernetes.io/proxy-send-timeout: "3600"
    nginx.ingress.kubernetes.io/proxy-read-timeout: "3600"
spec:
  ingressClassName: higress
  tls:
  - hosts:
    - uas-test.dev.com
    secretName: uas-test-dev-com-tls
  rules:
  - host: uas-test.dev.com
    http:
      paths:
      - path: /ws
        pathType: Exact
        backend:
          service:
            name: uas-test
            port:
              name: ws
      - path: /wss
        pathType: Exact
        backend:
          service:
            name: uas-test
            port:
              name: wss
---
apiVersion: v1
kind: Service
metadata:
  name: uas-test
  namespace: default
  labels:
    app: uas-test
spec:
  type: ClusterIP
  selector:
    app: uas-test
  ports:
  - name: ws
    port: 5066
    protocol: TCP
    targetPort: 5066
  - name: wss
    port: 7443
    protocol: TCP
    targetPort: 7443
---
apiVersion: apps/v1
kind: StatefulSet
metadata:
  name: uas-test
  namespace: default
  labels:
    app: uas-test
spec:
  serviceName: uas-test
  replicas: 1
  podManagementPolicy: OrderedReady
  revisionHistoryLimit: 10
  selector:
    matchLabels:
      app: uas-test
  template:
    metadata:
      labels:
        app: uas-test
    spec:
      containers:
      - name: uas-test
        image: registry.cn-hangzhou.aliyuncs.com/cspace/freeswitch-uas:latest
        imagePullPolicy: IfNotPresent
        ports:
        - containerPort: 5066
          protocol: TCP
        - containerPort: 7443
          protocol: TCP
        resources:
          requests:
            cpu: "1"
            memory: 500Mi
          limits:
            cpu: "2"
            memory: 1Gi
        lifecycle:
          preStop:
            exec:
              command: ["/bin/sh", "-c", "/usr/local/freeswitch/bin/fs_cli -p lsrobot -x shutdown"]
        volumeMounts:
        - name: log
          mountPath: /usr/local/freeswitch/var/log/freeswitch
        - name: tls
          mountPath: /usr/local/freeswitch/etc/freeswitch/tls/tls.crt
          subPath: tls.crt
          readOnly: true
        - name: tls
          mountPath: /usr/local/freeswitch/etc/freeswitch/tls/tls.key
          subPath: tls.key
          readOnly: true
      volumes:
      - name: log
        hostPath:
          path: /opt/uas-test/logs
      - name: tls
        secret:
          secretName: uas-test-dev-com-tls
      restartPolicy: Always

chaoyoung commented 9 months ago

@johnlanni 这个问题查出原因了吗？

johnlanni commented 9 months ago

@chaoyoung 抱歉这段时间比较忙还没来得及复现问题，你先试一下这个envoyfilter能否解决

apiVersion: networking.istio.io/v1alpha3
kind: EnvoyFilter
metadata:
  name: freeswitch-uas-enable-secp384r1
  namespace: default
spec:
  configPatches:
  - applyTo: CLUSTER
    match:
      cluster:
        service: freeswitch-uas.default.svc.cluster.local
      context: GATEWAY
    patch:
      operation: MERGE
      value:
        transport_socket:
          name: envoy.transport_sockets.tls
          typed_config:
            "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
            common_tls_context:
              tls_params:
                ecdh_curves:
                - P-521
                - P-384
                - P-256
                - X25519

chaoyoung commented 9 months ago

@chaoyoung 抱歉这段时间比较忙还没来得及复现问题，你先试一下这个envoyfilter能否解决

apiVersion: networking.istio.io/v1alpha3
kind: EnvoyFilter
metadata:
  name: freeswitch-uas-enable-secp384r1
  namespace: default
spec:
  configPatches:
  - applyTo: CLUSTER
    match:
      cluster:
        service: freeswitch-uas.default.svc.cluster.local
      context: GATEWAY
    patch:
      operation: MERGE
      value:
        transport_socket:
          name: envoy.transport_sockets.tls
          typed_config:
            "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
            common_tls_context:
              tls_params:
                ecdh_curves:
                - P-521
                - P-384
                - P-256
                - X25519

不行呢。

curl -kv https://uas-test.dev.com/wss -H 'Connection: Upgrade' -H 'Upgrade: websocket' -H 'Sec-Websocket-Protocol: sip' -H 'Sec-Websocket-Key: iDA5KxziwFqKlGYaO3EXSg=='
* About to connect() to uas-test.dev.com port 443 (#0)
*   Trying 10.20.30.0...
* Connected to uas-test.dev.com (10.20.30.0) port 443 (#0)
* Initializing NSS with certpath: sql:/etc/pki/nssdb
* skipping SSL peer certificate verification
* SSL connection using TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
* Server certificate:
*       subject: (nil)
*       start date: Sep 13 08:11:34 2023 GMT
*       expire date: Dec 12 08:11:34 2023 GMT
*       common name: (nil)
*       issuer: CN=XXX DevOps Self Signed Root CA,OU=DevOps,O=XXX Inc.,L=HangZhou,ST=ZheJiang,C=CN
> GET /wss HTTP/1.1
> User-Agent: curl/7.29.0
> Host: uas-test.dev.com
> Accept: */*
> Connection: Upgrade
> Upgrade: websocket
> Sec-Websocket-Protocol: sip
> Sec-Websocket-Key: iDA5KxziwFqKlGYaO3EXSg==
> 
< HTTP/1.1 503 Service Unavailable
< content-length: 273
< content-type: text/plain
< date: Wed, 13 Sep 2023 08:12:01 GMT
< server: istio-envoy
< connection: close
< 
* Closing connection 0
upstream connect error or disconnect/reset before headers. reset reason: connection failure, transport failure reason: TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO

johnlanni commented 9 months ago

你进网关的pod 执行下 curl localhost:15000/config_dump ，把内容发一下

chaoyoung commented 9 months ago

你进网关的pod 执行下 curl localhost:15000/config_dump ，把内容发一下

config_dump1.txt

johnlanni commented 9 months ago

你的配置中只有这些服务，并没有 freeswitch-uas.default.svc.cluster.local，所以上面的envoyfilter没有生效

chaoyoung commented 9 months ago

你的配置中只有这些服务，并没有 freeswitch-uas.default.svc.cluster.local，所以上面的envoyfilter没有生效

我这里为了测试，部署了一个新的服务：uas-test，你找找这个名称。新的完整的YAML Manifest如下：

# curl -kv http://uas-test.dev2.com/ws -H 'Connection: Upgrade' -H 'Upgrade: websocket' -H 'Sec-Websocket-Protocol: sip' -H 'Sec-Websocket-Key: iDA5KxziwFqKlGYaO3EXSg=='
# curl -kv https://uas-test.dev2.com/wss -H 'Connection: Upgrade' -H 'Upgrade: websocket' -H 'Sec-Websocket-Protocol: sip' -H 'Sec-Websocket-Key: iDA5KxziwFqKlGYaO3EXSg=='
---
apiVersion: networking.k8s.io/v1
kind: Ingress
metadata:
  name: uas-test
  namespace: default
  annotations:
    cert-manager.io/cluster-issuer: "ca-issuer"
    # nginx.ingress.kubernetes.io/ssl-protocols: "TLSv1.2"
    nginx.ingress.kubernetes.io/ssl-redirect: "false"
    nginx.ingress.kubernetes.io/secure-backends: "true"
    nginx.ingress.kubernetes.io/backend-protocol: "HTTPS"
    nginx.ingress.kubernetes.io/rewrite-target: "/"
    nginx.ingress.kubernetes.io/websocket-services : "uas-test"
    nginx.ingress.kubernetes.io/configuration-snippet: |
      proxy_set_header Upgrade "$http_upgrade";
      proxy_set_header Connection "Upgrade";
      proxy_set_header Host $host;
      proxy_set_header X-Forwarded-Host $http_host;
      proxy_set_header X-Forwarded-Proto $scheme;
      proxy_set_header X-Forwarded-For $remote_addr;
      proxy_set_header X-Real-IP $remote_addr;
    # nginx.ingress.kubernetes.io/proxy-http-version: "1.1"
    nginx.ingress.kubernetes.io/proxy-connect-timeout: "10"
    nginx.ingress.kubernetes.io/proxy-send-timeout: "3600"
    nginx.ingress.kubernetes.io/proxy-read-timeout: "3600"
    # nginx.ingress.kubernetes.io/proxy-ssl-secret: "default/uas-test-dev-com-tls"
    # nginx.ingress.kubernetes.io/proxy-ssl-protocols: "TLSv1.2"
spec:
  ingressClassName: higress
  tls:
  - hosts:
    - uas-test.dev2.com
    secretName: uas-test-dev-com-tls
  rules:
  - host: uas-test.dev2.com
    http:
      paths:
      - path: /ws
        pathType: Exact
        backend:
          service:
            name: uas-test
            port:
              name: ws
      - path: /wss
        pathType: Exact
        backend:
          service:
            name: uas-test
            port:
              name: wss
---
apiVersion: networking.istio.io/v1alpha3
kind: EnvoyFilter
metadata:
  name: uas-test-enable-secp384r1
  namespace: default
spec:
  configPatches:
  - applyTo: CLUSTER
    match:
      cluster:
        service: uas-test.default.svc.cluster.local
      context: GATEWAY
    patch:
      operation: MERGE
      value:
        transport_socket:
          name: envoy.transport_sockets.tls
          typed_config:
            "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
            common_tls_context:
              tls_params:
                ecdh_curves:
                # - secp384r1
                - P-521
                - P-384
                - P-256
                - X25519
---
apiVersion: v1
kind: Service
metadata:
  name: uas-test
  namespace: default
  labels:
    app: uas-test
spec:
  type: ClusterIP
  selector:
    app: uas-test
  ports:
  - name: ws
    port: 80
    protocol: TCP
    targetPort: ws
  - name: wss
    port: 443
    protocol: TCP
    targetPort: wss
---
apiVersion: apps/v1
kind: StatefulSet
metadata:
  name: uas-test
  namespace: default
  labels:
    app: uas-test
spec:
  serviceName: uas-test
  replicas: 1
  podManagementPolicy: OrderedReady
  revisionHistoryLimit: 10
  selector:
    matchLabels:
      app: uas-test
  template:
    metadata:
      labels:
        app: uas-test
    spec:
      containers:
      - name: uas-test
        image: registry.cn-hangzhou.aliyuncs.com/cspace/freeswitch-uas:latest
        imagePullPolicy: IfNotPresent
        ports:
        - name: ws
          containerPort: 5066
          protocol: TCP
        - name: wss
          containerPort: 7443
          protocol: TCP
        resources:
          requests:
            cpu: "1"
            memory: 500Mi
          limits:
            cpu: "2"
            memory: 1Gi
        # lifecycle:
        #   preStop:
        #     exec:
        #       command: ["/bin/sh", "-c", "/usr/local/freeswitch/bin/fs_cli -p lsrobot -x shutdown"]
        volumeMounts:
        - name: log
          mountPath: /usr/local/freeswitch/var/log/freeswitch
        - name: tls
          mountPath: /usr/local/freeswitch/etc/freeswitch/tls/tls.crt
          subPath: tls.crt
          readOnly: true
        - name: tls
          mountPath: /usr/local/freeswitch/etc/freeswitch/tls/tls.key
          subPath: tls.key
          readOnly: true
      volumes:
      - name: log
        hostPath:
          path: /opt/uas-test/logs
      - name: tls
        secret:
          secretName: uas-test-dev-com-tls
      restartPolicy: Always

johnlanni commented 9 months ago

envoyfilter 的 patch 看上去没有生效，你看下 gateway 的 pod 日志，有没有报错信息

chaoyoung commented 9 months ago

@johnlanni gateway log

2023-09-13T07:39:50.831678Z info    xdsproxy    connected to upstream XDS server: higress-controller.higress-system.svc:15012
2023-09-13T08:09:55.505991Z info    xdsproxy    connected to upstream XDS server: higress-controller.higress-system.svc:15012
{"authority":"uas-test.dev2.com","bytes_received":"0","bytes_sent":"0","downstream_local_address":"10.244.23.205:80","downstream_remote_address":"10.244.232.2:35436","duration":"2450","istio_policy_status":"-","method":"GET","path":"/ws","protocol":"HTTP/1.1","request_id":"1d83ba78-f6d1-4d19-8df2-e70d8cc9ee31","requested_server_name":"-","response_code":"0","response_flags":"DC","route_name":"default/uas-test","start_time":"2023-09-13T08:11:51.969Z","trace_id":"04beea3fbcc5e24f2571adcdda5584bb","upstream_cluster":"outbound|80||uas-test.default.svc.cluster.local","upstream_host":"-","upstream_local_address":"-","upstream_service_time":"-","upstream_transport_failure_reason":"-","user_agent":"curl/7.29.0","x_forwarded_for":"10.244.232.2"}
[Envoy (Epoch 0)] [2023-09-13 08:12:01.968][28][warning][client] [C319221] Connection is closed by self during connecting.
[Envoy (Epoch 0)] [2023-09-13 08:12:01.982][28][warning][client] [C319227] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 08:12:02.005][28][warning][client] [C319229] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 08:12:02.035][28][warning][client] [C319231] Connection is closed by peer during connecting.
{"authority":"uas-test.dev2.com","bytes_received":"0","bytes_sent":"273","downstream_local_address":"10.244.23.205:443","downstream_remote_address":"10.244.232.2:44212","duration":"2983","istio_policy_status":"-","method":"GET","path":"/wss","protocol":"HTTP/1.1","request_id":"3c7c2bb0-5cda-4421-b04f-8e46e1d987bd","requested_server_name":"uas-test.dev2.com","response_code":"503","response_flags":"UF,URX","route_name":"default/uas-test","start_time":"2023-09-13T08:11:59.066Z","trace_id":"81078ffbee4c9a09451e2cb8bf13cec1","upstream_cluster":"outbound|443||uas-test.default.svc.cluster.local","upstream_host":"10.244.232.17:7443","upstream_local_address":"-","upstream_service_time":"-","upstream_transport_failure_reason":"TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO","user_agent":"curl/7.29.0","x_forwarded_for":"10.244.232.2"}
[Envoy (Epoch 0)] [2023-09-13 08:15:35.721][28][warning][client] [C319339] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 08:15:35.739][28][warning][client] [C319340] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 08:15:35.783][28][warning][client] [C319341] Connection is closed by peer during connecting.
{"authority":"uas-test.dev2.com","bytes_received":"0","bytes_sent":"273","downstream_local_address":"10.244.23.205:443","downstream_remote_address":"10.244.232.2:46598","duration":"80","istio_policy_status":"-","method":"GET","path":"/wss","protocol":"HTTP/1.1","request_id":"7427baa7-cc01-4e61-9ea0-8e3ed27ad1b1","requested_server_name":"uas-test.dev2.com","response_code":"503","response_flags":"UF,URX","route_name":"default/uas-test","start_time":"2023-09-13T08:15:35.712Z","trace_id":"9cc72e3af4425c23ec71ad2ae7fbf6ee","upstream_cluster":"outbound|443||uas-test.default.svc.cluster.local","upstream_host":"10.244.232.18:7443","upstream_local_address":"-","upstream_service_time":"-","upstream_transport_failure_reason":"TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO","user_agent":"curl/7.29.0","x_forwarded_for":"10.244.232.2"}

chaoyoung commented 9 months ago

@johnlanni 目前已知freeswitch-uas这个镜像不支持TLSv1.3版本，只支持到TLSv1.2。跟这个有关系吗？能指定TLSv1.2么？

chaoyoung commented 9 months ago

johnlanni commented 9 months ago

@chaoyoung 默认支持 v1.2 的

johnlanni commented 9 months ago

@johnlanni gateway log

2023-09-13T07:39:50.831678Z   info    xdsproxy    connected to upstream XDS server: higress-controller.higress-system.svc:15012
2023-09-13T08:09:55.505991Z   info    xdsproxy    connected to upstream XDS server: higress-controller.higress-system.svc:15012
{"authority":"uas-test.dev2.com","bytes_received":"0","bytes_sent":"0","downstream_local_address":"10.244.23.205:80","downstream_remote_address":"10.244.232.2:35436","duration":"2450","istio_policy_status":"-","method":"GET","path":"/ws","protocol":"HTTP/1.1","request_id":"1d83ba78-f6d1-4d19-8df2-e70d8cc9ee31","requested_server_name":"-","response_code":"0","response_flags":"DC","route_name":"default/uas-test","start_time":"2023-09-13T08:11:51.969Z","trace_id":"04beea3fbcc5e24f2571adcdda5584bb","upstream_cluster":"outbound|80||uas-test.default.svc.cluster.local","upstream_host":"-","upstream_local_address":"-","upstream_service_time":"-","upstream_transport_failure_reason":"-","user_agent":"curl/7.29.0","x_forwarded_for":"10.244.232.2"}
[Envoy (Epoch 0)] [2023-09-13 08:12:01.968][28][warning][client] [C319221] Connection is closed by self during connecting.
[Envoy (Epoch 0)] [2023-09-13 08:12:01.982][28][warning][client] [C319227] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 08:12:02.005][28][warning][client] [C319229] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 08:12:02.035][28][warning][client] [C319231] Connection is closed by peer during connecting.
{"authority":"uas-test.dev2.com","bytes_received":"0","bytes_sent":"273","downstream_local_address":"10.244.23.205:443","downstream_remote_address":"10.244.232.2:44212","duration":"2983","istio_policy_status":"-","method":"GET","path":"/wss","protocol":"HTTP/1.1","request_id":"3c7c2bb0-5cda-4421-b04f-8e46e1d987bd","requested_server_name":"uas-test.dev2.com","response_code":"503","response_flags":"UF,URX","route_name":"default/uas-test","start_time":"2023-09-13T08:11:59.066Z","trace_id":"81078ffbee4c9a09451e2cb8bf13cec1","upstream_cluster":"outbound|443||uas-test.default.svc.cluster.local","upstream_host":"10.244.232.17:7443","upstream_local_address":"-","upstream_service_time":"-","upstream_transport_failure_reason":"TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO","user_agent":"curl/7.29.0","x_forwarded_for":"10.244.232.2"}
[Envoy (Epoch 0)] [2023-09-13 08:15:35.721][28][warning][client] [C319339] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 08:15:35.739][28][warning][client] [C319340] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 08:15:35.783][28][warning][client] [C319341] Connection is closed by peer during connecting.
{"authority":"uas-test.dev2.com","bytes_received":"0","bytes_sent":"273","downstream_local_address":"10.244.23.205:443","downstream_remote_address":"10.244.232.2:46598","duration":"80","istio_policy_status":"-","method":"GET","path":"/wss","protocol":"HTTP/1.1","request_id":"7427baa7-cc01-4e61-9ea0-8e3ed27ad1b1","requested_server_name":"uas-test.dev2.com","response_code":"503","response_flags":"UF,URX","route_name":"default/uas-test","start_time":"2023-09-13T08:15:35.712Z","trace_id":"9cc72e3af4425c23ec71ad2ae7fbf6ee","upstream_cluster":"outbound|443||uas-test.default.svc.cluster.local","upstream_host":"10.244.232.18:7443","upstream_local_address":"-","upstream_service_time":"-","upstream_transport_failure_reason":"TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO","user_agent":"curl/7.29.0","x_forwarded_for":"10.244.232.2"}

你把envoyfilter删除然后再重新apply一下，看看日志，如果没有gateway日志，你看下 controller 日志

chaoyoung commented 9 months ago

@johnlanni 删除envoyfilter并重新apply后，通过curl访问，controller没有日志输出，gateway有日志输出:

[Envoy (Epoch 0)] [2023-09-13 08:46:47.142][27][warning][client] [C2377693] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 08:46:47.153][27][warning][client] [C2377694] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 08:46:47.200][27][warning][client] [C2377695] Connection is closed by peer during connecting.
{"authority":"uas-test.dev2.com","bytes_received":"0","bytes_sent":"273","downstream_local_address":"10.244.149.73:443","downstream_remote_address":"10.244.232.2:38522","duration":"81","istio_policy_status":"-","method":"GET","path":"/wss","protocol":"HTTP/1.1","request_id":"3c2a33aa-dab7-456c-bd52-e830ec35d0b0","requested_server_name":"uas-test.dev2.com","response_code":"503","response_flags":"UF,URX","route_name":"default/uas-test","start_time":"2023-09-13T08:46:47.131Z","trace_id":"d0aa2d0e814d6369ec5dfbfc2673980b","upstream_cluster":"outbound|443||uas-test.default.svc.cluster.local","upstream_host":"10.244.232.19:7443","upstream_local_address":"-","upstream_service_time":"-","upstream_transport_failure_reason":"TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO","user_agent":"curl/7.29.0","x_forwarded_for":"10.244.232.2"}

johnlanni commented 9 months ago

@johnlanni 看下 controller pod 里 discovery 容器的日志

johnlanni commented 9 months ago

不用 curl 请求，是看配置下发时的错误信息

johnlanni commented 9 months ago

哦知道里，你的 envoyfilter 的namespace 得是 higress-system 才行，你填了default

johnlanni commented 9 months ago

apiVersion: networking.istio.io/v1alpha3
kind: EnvoyFilter
metadata:
  name: uas-test-enable-secp384r1
  namespace: higress-system
spec:
  configPatches:
  - applyTo: CLUSTER
    match:
      cluster:
        service: uas-test.default.svc.cluster.local
      context: GATEWAY
    patch:
      operation: MERGE
      value:
        transport_socket:
          name: envoy.transport_sockets.tls
          typed_config:
            "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
            common_tls_context:
              tls_params:
                ecdh_curves:
                # - secp384r1
                - P-521
                - P-384
                - P-256
                - X25519

chaoyoung commented 9 months ago

@johnlanni 看下 controller pod 里 discovery 容器的日志

2023-09-13T08:56:45.124585Z info    ads Push debounce stable[15911] 1 for config EnvoyFilter/default/uas-test-enable-secp384r1: 101.963549ms since last change, 101.962879ms since last push, full=true
2023-09-13T08:56:45.126880Z info    ads XDS: Pushing:2023-09-13T08:56:45Z/604 Services:70 ConnectedEndpoints:2  Version:2023-09-13T08:56:45Z/604
2023-09-13T08:56:45.128006Z info    ads CDS: PUSH for node:higress-gateway-f88fbd4c5-rtxhn.higress-system resources:9 size:3.3kB cached:8/8
2023-09-13T08:56:45.128349Z info    ads EDS: PUSH for node:higress-gateway-f88fbd4c5-rtxhn.higress-system resources:8 size:1.2kB empty:0 cached:8/8
2023-09-13T08:56:45.129206Z info    ads LDS: PUSH for node:higress-gateway-f88fbd4c5-rtxhn.higress-system resources:3 size:10.5kB
2023-09-13T08:56:45.129898Z info    ads RDS: PUSH for node:higress-gateway-f88fbd4c5-rtxhn.higress-system resources:2 size:2.1kB cached:0/0
2023-09-13T08:56:45.131545Z info    ads CDS: PUSH for node:higress-gateway-f88fbd4c5-2pzd8.higress-system resources:9 size:3.3kB cached:8/8
2023-09-13T08:56:45.131758Z info    ads EDS: PUSH for node:higress-gateway-f88fbd4c5-2pzd8.higress-system resources:8 size:1.2kB empty:0 cached:8/8
2023-09-13T08:56:45.132382Z info    ads LDS: PUSH for node:higress-gateway-f88fbd4c5-2pzd8.higress-system resources:3 size:10.5kB
2023-09-13T08:56:45.132939Z info    ads RDS: PUSH for node:higress-gateway-f88fbd4c5-2pzd8.higress-system resources:2 size:2.1kB cached:0/0

chaoyoung commented 9 months ago

@johnlanni envoyfilter 的namespace改为higress-system也不行呢。 controller discovery log

2023-09-13T08:58:42.785669Z info    ads Push debounce stable[15919] 1 for config EnvoyFilter/higress-system/uas-test-enable-secp384r1: 100.681742ms since last change, 100.681212ms since last push, full=true
2023-09-13T08:58:42.787460Z info    ads XDS: Pushing:2023-09-13T08:58:42Z/608 Services:70 ConnectedEndpoints:2  Version:2023-09-13T08:58:42Z/608
2023-09-13T08:58:42.790304Z info    ads CDS: PUSH for node:higress-gateway-f88fbd4c5-rtxhn.higress-system resources:9 size:3.3kB cached:3/8
2023-09-13T08:58:42.790343Z info    ads CDS: PUSH for node:higress-gateway-f88fbd4c5-2pzd8.higress-system resources:9 size:3.3kB cached:0/8
2023-09-13T08:58:42.790671Z info    ads EDS: PUSH for node:higress-gateway-f88fbd4c5-rtxhn.higress-system resources:8 size:1.2kB empty:0 cached:8/8
2023-09-13T08:58:42.791960Z info    ads EDS: PUSH for node:higress-gateway-f88fbd4c5-2pzd8.higress-system resources:8 size:1.2kB empty:0 cached:8/8
2023-09-13T08:58:42.792078Z info    ads LDS: PUSH for node:higress-gateway-f88fbd4c5-rtxhn.higress-system resources:3 size:10.5kB
2023-09-13T08:58:42.792793Z info    ads RDS: PUSH for node:higress-gateway-f88fbd4c5-rtxhn.higress-system resources:2 size:2.1kB cached:0/0
2023-09-13T08:58:42.794767Z info    ads LDS: PUSH for node:higress-gateway-f88fbd4c5-2pzd8.higress-system resources:3 size:10.5kB
2023-09-13T08:58:42.795560Z info    ads RDS: PUSH for node:higress-gateway-f88fbd4c5-2pzd8.higress-system resources:2 size:2.1kB cached:0/0

johnlanni commented 9 months ago

@chaoyoung 看下configdump里搜一下 curve ，看看配置生效了吗

chaoyoung commented 9 months ago

@chaoyoung 看下configdump里搜一下 curve ，看看配置生效了吗

johnlanni commented 9 months ago

apiVersion: networking.istio.io/v1alpha3
kind: EnvoyFilter
metadata:
  name: uas-test-enable-secp384r1
  namespace: higress-system
spec:
  configPatches:
  - applyTo: CLUSTER
    match:
      cluster:
        service: uas-test.default.svc.cluster.local
      context: GATEWAY
    patch:
      operation: MERGE
      value:
        transport_socket:
          name: envoy.transport_sockets.tls
          typed_config:
            "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
            common_tls_context:
              tls_params:
                tls_minimum_protocol_version: TLSv1_0
                tls_maximum_protocol_version: TLSv1_2
                ecdh_curves:
                - P-521
                - P-384
                - P-256
                - X25519

这样试试，去掉 tls 1.3

chaoyoung commented 9 months ago

apiVersion: networking.istio.io/v1alpha3
kind: EnvoyFilter
metadata:
  name: uas-test-enable-secp384r1
  namespace: higress-system
spec:
  configPatches:
  - applyTo: CLUSTER
    match:
      cluster:
        service: uas-test.default.svc.cluster.local
      context: GATEWAY
    patch:
      operation: MERGE
      value:
        transport_socket:
          name: envoy.transport_sockets.tls
          typed_config:
            "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
            common_tls_context:
              tls_params:
                tls_minimum_protocol_version: TLSv1_0
                tls_maximum_protocol_version: TLSv1_2
                ecdh_curves:
                - P-521
                - P-384
                - P-256
                - X25519

这样试试，去掉 tls 1.3

还是不行。

johnlanni commented 9 months ago

进 gateway 容器，执行：

curl localhost:15000/logging?level=debug -X POST

然后看下日志，看看有没有tls相关的错误

chaoyoung commented 9 months ago

@johnlanni

[Envoy (Epoch 0)] [2023-09-13 09:56:59.591][27][debug][filter] tls inspector: new connection accepted
[Envoy (Epoch 0)] [2023-09-13 09:56:59.827][27][debug][filter] tls:onServerName(), requestedServerName: uas-test.dev2.com
[Envoy (Epoch 0)] [2023-09-13 09:56:59.828][27][debug][conn_handler] [C2379825] new connection from 10.244.232.2:55332
[Envoy (Epoch 0)] [2023-09-13 09:56:59.847][27][debug][http] [C2379825] new stream
[Envoy (Epoch 0)] [2023-09-13 09:56:59.848][27][debug][http] [C2379825][S18308753407744783148] request headers complete (end_stream=false):
':authority', 'uas-test.dev2.com'
':path', '/wss'
':method', 'GET'
'user-agent', 'curl/7.29.0'
'accept', '*/*'
'connection', 'Upgrade'
'upgrade', 'websocket'
'sec-websocket-protocol', 'sip'
'sec-websocket-key', 'iDA5KxziwFqKlGYaO3EXSg=='

[Envoy (Epoch 0)] [2023-09-13 09:56:59.848][27][debug][rbac] checking request: requestedServerName: uas-test.dev2.com, sourceIP: 10.244.232.2:55332, directRemoteIP: 10.244.232.2:55332, remoteIP: 10.244.232.2:55332,localAddress: 10.244.149.73:443, ssl: uriSanPeerCertificate: , dnsSanPeerCertificate: , subjectPeerCertificate: , headers: ':authority', 'uas-test.dev2.com'
':path', '/wss'
':method', 'GET'
':scheme', 'https'
'user-agent', 'curl/7.29.0'
'accept', '*/*'
'connection', 'Upgrade'
'upgrade', 'websocket'
'sec-websocket-protocol', 'sip'
'sec-websocket-key', 'iDA5KxziwFqKlGYaO3EXSg=='
'content-length', '0'
'x-forwarded-for', '10.244.232.2'
'x-forwarded-proto', 'https'
'x-envoy-internal', 'true'
'x-request-id', 'eb3ed4d3-32b8-42b2-a2f7-1b45b8948833'
'x-envoy-decorator-operation', 'uas-test.default.svc.cluster.local:443/wss.*'
, dynamicMetadata:
[Envoy (Epoch 0)] [2023-09-13 09:56:59.848][27][debug][rbac] no engine, allowed by default
[Envoy (Epoch 0)] [2023-09-13 09:56:59.848][27][debug][router] [C2379825][S18308753407744783148] cluster 'outbound|443||uas-test.default.svc.cluster.local' match for URL '/wss'
[Envoy (Epoch 0)] [2023-09-13 09:56:59.849][27][debug][router] [C2379825][S18308753407744783148] router decoding headers:
':authority', 'uas-test.dev2.com'
':path', '/'
':method', 'GET'
':scheme', 'https'
'user-agent', 'curl/7.29.0'
'accept', '*/*'
'connection', 'Upgrade'
'upgrade', 'websocket'
'sec-websocket-protocol', 'sip'
'sec-websocket-key', 'iDA5KxziwFqKlGYaO3EXSg=='
'content-length', '0'
'x-forwarded-for', '10.244.232.2'
'x-forwarded-proto', 'https'
'x-envoy-internal', 'true'
'x-request-id', 'eb3ed4d3-32b8-42b2-a2f7-1b45b8948833'
'x-envoy-decorator-operation', 'uas-test.default.svc.cluster.local:443/wss.*'
'x-envoy-attempt-count', '1'
'x-b3-traceid', '4ccec7f13a0b9dacfc93b5e07eda28ec'
'x-b3-spanid', 'fc93b5e07eda28ec'
'x-b3-sampled', '0'
'req-start-time', '1694599019847'
'original-host', 'uas-test.dev2.com'
'x-envoy-original-path', '/wss'

[Envoy (Epoch 0)] [2023-09-13 09:56:59.849][27][debug][pool] queueing stream due to no available connections
[Envoy (Epoch 0)] [2023-09-13 09:56:59.849][27][debug][pool] trying to create new connection
[Envoy (Epoch 0)] [2023-09-13 09:56:59.849][27][debug][pool] creating a new connection
[Envoy (Epoch 0)] [2023-09-13 09:56:59.859][27][debug][client] [C2379826] connecting
[Envoy (Epoch 0)] [2023-09-13 09:56:59.859][27][debug][connection] [C2379826] connecting to 10.244.232.19:7443
[Envoy (Epoch 0)] [2023-09-13 09:56:59.859][27][debug][connection] [C2379826] connection in progress
[Envoy (Epoch 0)] [2023-09-13 09:56:59.867][27][debug][connection] [C2379826] connected
[Envoy (Epoch 0)] [2023-09-13 09:56:59.870][27][debug][connection] [C2379826] TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO
[Envoy (Epoch 0)] [2023-09-13 09:56:59.870][27][debug][connection] [C2379826] closing socket: 0
[Envoy (Epoch 0)] [2023-09-13 09:56:59.870][27][debug][connection] [C2379826] TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO
[Envoy (Epoch 0)] [2023-09-13 09:56:59.871][27][debug][client] [C2379826] disconnect. resetting 0 pending requests
[Envoy (Epoch 0)] [2023-09-13 09:56:59.871][27][warning][client] [C2379826] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 09:56:59.871][27][debug][pool] [C2379826] client disconnected, failure reason: TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO
[Envoy (Epoch 0)] [2023-09-13 09:56:59.871][27][debug][router] [C2379825][S18308753407744783148] upstream reset: reset reason: connection failure, transport failure reason: TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO
[Envoy (Epoch 0)] [2023-09-13 09:56:59.871][27][debug][pool] invoking idle callbacks - is_draining_for_deletion_=false
[Envoy (Epoch 0)] [2023-09-13 09:56:59.883][27][debug][router] [C2379825][S18308753407744783148] performing retry
[Envoy (Epoch 0)] [2023-09-13 09:56:59.883][27][debug][pool] queueing stream due to no available connections
[Envoy (Epoch 0)] [2023-09-13 09:56:59.883][27][debug][pool] trying to create new connection
[Envoy (Epoch 0)] [2023-09-13 09:56:59.884][27][debug][pool] creating a new connection
[Envoy (Epoch 0)] [2023-09-13 09:56:59.884][27][debug][client] [C2379827] connecting
[Envoy (Epoch 0)] [2023-09-13 09:56:59.884][27][debug][connection] [C2379827] connecting to 10.244.232.19:7443
[Envoy (Epoch 0)] [2023-09-13 09:56:59.884][27][debug][connection] [C2379827] connection in progress
[Envoy (Epoch 0)] [2023-09-13 09:56:59.885][27][debug][connection] [C2379827] connected
[Envoy (Epoch 0)] [2023-09-13 09:56:59.888][27][debug][connection] [C2379827] TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO
[Envoy (Epoch 0)] [2023-09-13 09:56:59.888][27][debug][connection] [C2379827] closing socket: 0
[Envoy (Epoch 0)] [2023-09-13 09:56:59.889][27][debug][connection] [C2379827] TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO
[Envoy (Epoch 0)] [2023-09-13 09:56:59.889][27][debug][client] [C2379827] disconnect. resetting 0 pending requests
[Envoy (Epoch 0)] [2023-09-13 09:56:59.889][27][warning][client] [C2379827] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 09:56:59.889][27][debug][pool] [C2379827] client disconnected, failure reason: TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO
[Envoy (Epoch 0)] [2023-09-13 09:56:59.889][27][debug][router] [C2379825][S18308753407744783148] upstream reset: reset reason: connection failure, transport failure reason: TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO
[Envoy (Epoch 0)] [2023-09-13 09:56:59.889][27][debug][pool] invoking idle callbacks - is_draining_for_deletion_=false
[Envoy (Epoch 0)] [2023-09-13 09:56:59.892][27][debug][router] [C2379825][S18308753407744783148] performing retry
[Envoy (Epoch 0)] [2023-09-13 09:56:59.892][27][debug][pool] queueing stream due to no available connections
[Envoy (Epoch 0)] [2023-09-13 09:56:59.892][27][debug][pool] trying to create new connection
[Envoy (Epoch 0)] [2023-09-13 09:56:59.892][27][debug][pool] creating a new connection
[Envoy (Epoch 0)] [2023-09-13 09:56:59.892][27][debug][client] [C2379828] connecting
[Envoy (Epoch 0)] [2023-09-13 09:56:59.892][27][debug][connection] [C2379828] connecting to 10.244.232.19:7443
[Envoy (Epoch 0)] [2023-09-13 09:56:59.892][27][debug][connection] [C2379828] connection in progress
[Envoy (Epoch 0)] [2023-09-13 09:56:59.894][27][debug][connection] [C2379828] connected
[Envoy (Epoch 0)] [2023-09-13 09:56:59.897][27][debug][connection] [C2379828] TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO
[Envoy (Epoch 0)] [2023-09-13 09:56:59.898][27][debug][connection] [C2379828] closing socket: 0
[Envoy (Epoch 0)] [2023-09-13 09:56:59.898][27][debug][connection] [C2379828] TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO
[Envoy (Epoch 0)] [2023-09-13 09:56:59.898][27][debug][client] [C2379828] disconnect. resetting 0 pending requests
[Envoy (Epoch 0)] [2023-09-13 09:56:59.898][27][warning][client] [C2379828] Connection is closed by peer during connecting.
[Envoy (Epoch 0)] [2023-09-13 09:56:59.898][27][debug][pool] [C2379828] client disconnected, failure reason: TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO
[Envoy (Epoch 0)] [2023-09-13 09:56:59.898][27][debug][router] [C2379825][S18308753407744783148] upstream reset: reset reason: connection failure, transport failure reason: TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO
[Envoy (Epoch 0)] [2023-09-13 09:56:59.917][27][debug][http] [C2379825][S18308753407744783148] Sending local reply with details upstream_reset_before_response_started{connection failure,TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO}
[Envoy (Epoch 0)] [2023-09-13 09:56:59.917][27][debug][http] [C2379825][S18308753407744783148] encoding headers via codec (end_stream=false):
':status', '503'
'content-length', '273'
'content-type', 'text/plain'
'date', 'Wed, 13 Sep 2023 09:56:59 GMT'
'server', 'istio-envoy'
'connection', 'close'

[Envoy (Epoch 0)] [2023-09-13 09:56:59.917][27][debug][http] [C2379825][S18308753407744783148] doEndStream() resetting stream
[Envoy (Epoch 0)] [2023-09-13 09:56:59.917][27][debug][http] [C2379825][S18308753407744783148] stream reset
[Envoy (Epoch 0)] [2023-09-13 09:56:59.918][27][debug][connection] [C2379825] closing data_to_write=433 type=2
[Envoy (Epoch 0)] [2023-09-13 09:56:59.918][27][debug][connection] [C2379825] setting delayed close timer with timeout 1000 ms
[Envoy (Epoch 0)] [2023-09-13 09:56:59.918][27][debug][pool] invoking idle callbacks - is_draining_for_deletion_=false
[Envoy (Epoch 0)] [2023-09-13 09:56:59.919][27][debug][connection] [C2379825] write flush complete
[Envoy (Epoch 0)] [2023-09-13 09:56:59.922][27][debug][connection] [C2379825] remote early close
[Envoy (Epoch 0)] [2023-09-13 09:56:59.922][27][debug][connection] [C2379825] closing socket: 0
[Envoy (Epoch 0)] [2023-09-13 09:56:59.922][27][debug][connection] [C2379825] SSL shutdown: rc=0
[Envoy (Epoch 0)] [2023-09-13 09:56:59.923][27][debug][conn_handler] [C2379825] adding to cleanup list
{"authority":"uas-test.dev2.com","bytes_received":"0","bytes_sent":"273","downstream_local_address":"10.244.149.73:443","downstream_remote_address":"10.244.232.2:55332","duration":"69","istio_policy_status":"-","method":"GET","path":"/wss","protocol":"HTTP/1.1","request_id":"eb3ed4d3-32b8-42b2-a2f7-1b45b8948833","requested_server_name":"uas-test.dev2.com","response_code":"503","response_flags":"UF,URX","route_name":"default/uas-test","start_time":"2023-09-13T09:56:59.847Z","trace_id":"4ccec7f13a0b9dacfc93b5e07eda28ec","upstream_cluster":"outbound|443||uas-test.default.svc.cluster.local","upstream_host":"10.244.232.19:7443","upstream_local_address":"-","upstream_service_time":"-","upstream_transport_failure_reason":"TLS error: 268436496:SSL routines:OPENSSL_internal:SSLV3_ALERT_HANDSHAKE_FAILURE 268435610:SSL routines:OPENSSL_internal:HANDSHAKE_FAILURE_ON_CLIENT_HELLO","user_agent":"curl/7.29.0","x_forwarded_for":"10.244.232.2"}
[Envoy (Epoch 0)] [2023-09-13 09:57:00.006][27][debug][conn_handler] [C322423] new connection from 10.20.0.101:51076
[Envoy (Epoch 0)] [2023-09-13 09:57:00.006][27][debug][http] [C322423] new stream
[Envoy (Epoch 0)] [2023-09-13 09:57:00.007][27][debug][http] [C322423][S13101125433380773850] request headers complete (end_stream=true):
':authority', '10.244.23.205:15021'
':path', '/healthz/ready'
':method', 'GET'
'user-agent', 'kube-probe/1.24'
'accept', '*/*'
'connection', 'close'

[Envoy (Epoch 0)] [2023-09-13 09:57:00.007][27][debug][http] [C322423][S13101125433380773850] request end stream
[Envoy (Epoch 0)] [2023-09-13 09:57:00.008][27][debug][router] [C322423][S13101125433380773850] cluster 'agent' match for URL '/healthz/ready'
[Envoy (Epoch 0)] [2023-09-13 09:57:00.008][27][debug][router] [C322423][S13101125433380773850] router decoding headers:
':authority', '10.244.23.205:15021'
':path', '/healthz/ready'
':method', 'GET'
':scheme', 'http'
'user-agent', 'kube-probe/1.24'
'accept', '*/*'
'x-forwarded-proto', 'http'
'x-request-id', 'ca0e30af-5e99-453a-b1ae-175b4fd81c92'
'x-envoy-expected-rq-timeout-ms', '15000'
'req-start-time', '1694599020006'
'original-host', '10.244.23.205:15021'

[Envoy (Epoch 0)] [2023-09-13 09:57:00.008][27][debug][pool] [C8] using existing connection
[Envoy (Epoch 0)] [2023-09-13 09:57:00.008][27][debug][pool] [C8] creating stream
[Envoy (Epoch 0)] [2023-09-13 09:57:00.008][27][debug][router] [C322423][S13101125433380773850] pool ready
[Envoy (Epoch 0)] [2023-09-13 09:57:00.010][27][debug][client] [C8] response complete
[Envoy (Epoch 0)] [2023-09-13 09:57:00.010][27][debug][router] [C322423][S13101125433380773850] upstream headers complete: end_stream=true
[Envoy (Epoch 0)] [2023-09-13 09:57:00.010][27][debug][http] [C322423][S13101125433380773850] closing connection due to connection close header
[Envoy (Epoch 0)] [2023-09-13 09:57:00.010][27][debug][http] [C322423][S13101125433380773850] encoding headers via codec (end_stream=true):
':status', '200'
'date', 'Wed, 13 Sep 2023 09:57:00 GMT'
'content-length', '0'
'req-cost-time', '3'
'req-arrive-time', '1694599020006'
'resp-start-time', '1694599020010'
'x-envoy-upstream-service-time', '1'
'server', 'envoy'
'connection', 'close'

[Envoy (Epoch 0)] [2023-09-13 09:57:00.010][27][debug][connection] [C322423] closing data_to_write=225 type=0
[Envoy (Epoch 0)] [2023-09-13 09:57:00.010][27][debug][connection] [C322423] setting delayed close timer with timeout 1000 ms
[Envoy (Epoch 0)] [2023-09-13 09:57:00.010][27][debug][pool] [C8] response complete
[Envoy (Epoch 0)] [2023-09-13 09:57:00.010][27][debug][pool] [C8] destroying stream: 0 remaining
[Envoy (Epoch 0)] [2023-09-13 09:57:00.011][27][debug][connection] [C322423] write flush complete
[Envoy (Epoch 0)] [2023-09-13 09:57:00.011][27][debug][connection] [C322423] closing socket: 1
[Envoy (Epoch 0)] [2023-09-13 09:57:00.011][27][debug][conn_handler] [C322423] adding to cleanup list
[Envoy (Epoch 0)] [2023-09-13 09:57:00.743][19][debug][main] flushing stats

johnlanni commented 7 months ago

我复现一下再看看

alibaba / higress