search

openservicemesh / osm

Open Service Mesh (OSM) is a lightweight, extensible, cloud native service mesh that allows users to uniformly manage, secure, and get out-of-the-box observability features for highly dynamic microservice environments.
https://openservicemesh.io/
Apache License 2.0
2.58k stars 277 forks source link

rbac_access_denied_matched_policy[none] by using AuthenticatedPrincipal #5042

Closed thorker closed 2 years ago

thorker commented 2 years ago

Bug description: Currently, we are testing AKS 1.24 & OSM 1.2.0 and as soon as we added the AuthenticatedPrincipal to our IngressBackend, the connectivity breaks. In the envoy logs we see the responsecodedetails rbac_access_denied_matched_policy[none].

We are using the configuration from the guide at another setup with AKS 1.23.8 and OSM 1.1.1 and it's working fine.

Do we missed some configurations to work with version 1.2.0?

Affected area (please mark with X where applicable):

How was OSM installed?: AKS-AddOn

Environment:

shashankram commented 2 years ago

@thorker could you share the following configurations (please redact sensitive/PII data):

  1. Backend k8s service yaml
  2. IngressBackend service yaml
  3. MeshConfig yaml: kubectl get meshconfig osm-mesh-config -n -o yaml

Additionally, could you confirm if HTTP ingress and HTTPS ingress with one-way TLS (skipClientCertValidation: true) works?

thorker commented 2 years ago

HTTP Ingress & HTTPS ingress (skipClientCertValidation: true) works.

Configurations are the same in both AKS, but in the new version it doesn't work anymore. We only adapted the guide to your services.

spec:
  certificate:
    certKeyBitSize: 2048
    ingressGateway:
      secret:
        name: osm-nginx-client-cert
        namespace: kube-system
      subjectAltNames:
        - ingress-nginx.ingress-nginx.cluster.local
      validityDuration: 24h
    serviceCertValidityDuration: 24h
  featureFlags:
    enableAsyncProxyServiceMapping: false
    enableEgressPolicy: true
    enableEnvoyActiveHealthChecks: false
    enableIngressBackendPolicy: true
    enableRetryPolicy: false
    enableSnapshotCacheMode: false
    enableWASMStats: true
  observability:
    enableDebugServer: true
    osmLogLevel: error
    tracing:
      enable: false
  sidecar:
    configResyncInterval: 0s
    enablePrivilegedInitContainer: false
    localProxyMode: Localhost
    logLevel: error
    resources:
      limits:
        memory: 1Gi
      requests:
        cpu: 50m
        memory: 1Gi
    tlsMaxProtocolVersion: TLSv1_3
    tlsMinProtocolVersion: TLSv1_2
  traffic:
    enableEgress: true
    enablePermissiveTrafficPolicyMode: true
    inboundExternalAuthorization:
      enable: false
      failureModeAllow: false
      statPrefix: inboundExtAuthz
      timeout: 1s
spec:
  backends:
    - name: acc000-def-example
      port:
        number: 8080
        protocol: https
      tls:
        skipClientCertValidation: false
  sources:
    - kind: Service
      name: ingress-nginx-controller
      namespace: ingress-nginx
    - kind: AuthenticatedPrincipal
      name: ingress-nginx.ingress-nginx.cluster.local
apiVersion: v1
kind: Service
metadata:
  name: acc000-def-example
  namespace: acc000-example-box-def
spec:
  type: ClusterIP
  ports:
    - name: http
      protocol: TCP
      port: 80
      targetPort: 8080
shashankram commented 2 years ago

Could you also share the following:

  1. Envoy logs during the time the request fails: kubectl logs -n -c envoy -f --tail=50
  2. Backend sidecar's config dump (redact values for all inline_bytes and certificate fields): osm proxy get config_dump -n
thorker commented 2 years ago 
2022-08-29 05:42:56.024][24][debug][filter] [source/extensions/filters/listener/tls_inspector/tls_inspector.cc:88] tls inspector: new connection accepted
[2022-08-29 05:42:56.024][24][trace][filter] [source/extensions/filters/listener/tls_inspector/tls_inspector.cc:175] tls inspector: recv: 0
[2022-08-29 05:42:56.024][24][trace][filter] [source/extensions/filters/listener/tls_inspector/tls_inspector.cc:175] tls inspector: recv: 194
[2022-08-29 05:42:56.024][24][trace][filter] [source/extensions/filters/listener/tls_inspector/tls_inspector.cc:202] tls inspector: done: true
[2022-08-29 05:42:56.024][24][debug][filter] [source/extensions/filters/listener/original_dst/original_dst.cc:20] original_dst: new connection accepted
[2022-08-29 05:42:56.024][24][trace][filter] [source/extensions/filters/listener/original_dst/original_dst.cc:66] original_dst: set destination to xxx
[2022-08-29 05:42:56.024][24][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x4ac7e0d4900 for 3600000ms, min is 3600000ms
[2022-08-29 05:42:56.024][24][debug][conn_handler] [source/server/active_tcp_listener.cc:142] [C116] new connection from xxx
[2022-08-29 05:42:56.024][24][trace][main] [source/common/event/dispatcher_impl.cc:249] item added to deferred deletion list (size=1)
[2022-08-29 05:42:56.024][24][trace][main] [source/common/event/dispatcher_impl.cc:125] clearing deferred deletion list (size=1)
[2022-08-29 05:42:56.024][24][trace][connection] [source/common/network/connection_impl.cc:563] [C116] socket event: 3
[2022-08-29 05:42:56.024][24][trace][connection] [source/common/network/connection_impl.cc:674] [C116] write ready
[2022-08-29 05:42:56.025][24][trace][connection] [source/extensions/transport_sockets/tls/ssl_handshaker.cc:52] [C116] ssl error occurred while read: WANT_READ
[2022-08-29 05:42:56.025][24][trace][connection] [source/common/network/connection_impl.cc:603] [C116] read ready. dispatch_buffered_data=0
[2022-08-29 05:42:56.025][24][trace][connection] [source/extensions/transport_sockets/tls/ssl_handshaker.cc:52] [C116] ssl error occurred while read: WANT_READ
[2022-08-29 05:42:56.028][24][trace][connection] [source/common/network/connection_impl.cc:563] [C116] socket event: 3
[2022-08-29 05:42:56.028][24][trace][connection] [source/common/network/connection_impl.cc:674] [C116] write ready
[2022-08-29 05:42:56.028][24][trace][connection] [source/common/network/connection_impl.cc:418] [C116] raising connection event 2
[2022-08-29 05:42:56.028][24][trace][conn_handler] [source/server/active_stream_listener_base.cc:111] [C116] connection on event 2
[2022-08-29 05:42:56.028][24][trace][connection] [source/common/network/connection_impl.cc:603] [C116] read ready. dispatch_buffered_data=0
[2022-08-29 05:42:56.028][24][trace][connection] [source/extensions/transport_sockets/tls/ssl_socket.cc:88] [C116] ssl read returns: -1
[2022-08-29 05:42:56.028][24][trace][connection] [source/extensions/transport_sockets/tls/ssl_socket.cc:128] [C116] ssl error occurred while read: WANT_READ
[2022-08-29 05:42:56.028][24][trace][connection] [source/extensions/transport_sockets/tls/ssl_socket.cc:164] [C116] ssl read 0 bytes
[2022-08-29 05:42:56.028][24][trace][connection] [source/common/network/connection_impl.cc:563] [C116] socket event: 3
[2022-08-29 05:42:56.028][24][trace][connection] [source/common/network/connection_impl.cc:674] [C116] write ready
[2022-08-29 05:42:56.028][24][trace][connection] [source/common/network/connection_impl.cc:603] [C116] read ready. dispatch_buffered_data=0
[2022-08-29 05:42:56.028][24][trace][connection] [source/extensions/transport_sockets/tls/ssl_socket.cc:88] [C116] ssl read returns: 718
[2022-08-29 05:42:56.028][24][trace][connection] [source/extensions/transport_sockets/tls/ssl_socket.cc:88] [C116] ssl read returns: -1
[2022-08-29 05:42:56.028][24][trace][connection] [source/extensions/transport_sockets/tls/ssl_socket.cc:128] [C116] ssl error occurred while read: WANT_READ
[2022-08-29 05:42:56.028][24][trace][connection] [source/extensions/transport_sockets/tls/ssl_socket.cc:164] [C116] ssl read 718 bytes
[2022-08-29 05:42:56.028][24][trace][http] [source/common/http/http1/codec_impl.cc:579] [C116] parsing 718 bytes
[2022-08-29 05:42:56.028][24][trace][http] [source/common/http/http1/codec_impl.cc:865] [C116] message begin
[2022-08-29 05:42:56.028][24][debug][http] [source/common/http/conn_manager_impl.cc:299] [C116] new stream
[2022-08-29 05:42:56.028][24][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x4ac7e0d5500 for 300000ms, min is 300000ms
[2022-08-29 05:42:56.028][24][trace][http] [source/common/http/http1/codec_impl.cc:492] [C116] completed header: key=sec-fetch-user value=?1
[2022-08-29 05:42:56.028][24][trace][http] [source/common/http/http1/codec_impl.cc:1053] [C116] Server: onHeadersComplete size=18
[2022-08-29 05:42:56.028][24][trace][http] [source/common/http/http1/codec_impl.cc:843] [C116] message complete
[2022-08-29 05:42:56.028][24][debug][http] [source/common/http/conn_manager_impl.cc:904] [C116]
[2022-08-29 05:42:56.028][24][debug][http] [source/common/http/filter_manager.cc:849] [C116][S9317171363508398323] request end stream
[2022-08-29 05:42:56.028][24][debug][connection] [./source/common/network/connection_impl.h:89] [C116] current connecting state: false
[2022-08-29 05:42:56.029][24][debug][rbac] [source/extensions/filters/http/rbac/rbac_filter.cc:113] enforced denied, matched policy none
[2022-08-29 05:42:56.029][24][debug][http] [source/common/http/filter_manager.cc:960] [C116][S9317171363508398323] Sending local reply with details rbac_access_denied_matched_policy[none]
[2022-08-29 05:42:56.029][24][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x4ac7e0d5500 for 300000ms, min is 300000ms
[2022-08-29 05:42:56.029][24][trace][http] [source/common/http/filter_manager.cc:1130] [C116][S9317171363508398323] encode headers called: filter=0x4ac7ebef110 status=0
[2022-08-29 05:42:56.029][24][debug][http] [source/common/http/conn_manager_impl.cc:1516] [C116][S9317171363508398323] encoding headers via codec (end_stream=false):
':status', '403'
'content-length', '19'
'content-type', 'text/plain'
'date', 'Mon, 29 Aug 2022 05:42:55 GMT'
'server', 'envoy'

[2022-08-29 05:42:56.029][24][trace][connection] [source/common/network/connection_impl.cc:478] [C116] writing 124 bytes, end_stream false
psandytang commented 2 years ago

I am also facing the exact same issue when I upgraded from 1.23.8 to 1.24.3 in AKS. Could this be due to serviceaccounts no longer generate secrets by default?

keithmattix commented 2 years ago

@thorker could you provide the envoy config dump that Shashank requested? osm proxy get config_dump -n acc000-def-example should work

thorker commented 2 years ago

envoy-config.txt

shashankram commented 2 years ago

@thorker, @psandytang, it appears the root cause for the issue has been identified. A patch fix will be available for this bug soon. The fix is provided in https://github.com/openservicemesh/osm/pull/5063.

Thanks

keithmattix commented 2 years ago

Now that #5063 is merged, this issue can likely be considered closed. Do you agree @shashankram?

nshankar13 commented 2 years ago

@keithmattix should we wait until the hotfix is rolled out, including for the add-on?

keithmattix commented 2 years ago

This has been fixed and released in v1.2.1 of upstream, so I'm closing this