Contour: Observed envoy memory while adding|removing ingress

[mattalberts]

Envoy Memory Investigation

Odd container memory observations do not affect the contour container. As seen in the graphs, contour memory changes are dwarfed by envoy memory changes. I wanted to start the question/discussion with the contour project to see if similar observations have been seen.

I found two possibly related issues in the envoy project

1. https://github.com/envoyproxy/envoy/issues/3592
2. https://github.com/envoyproxy/envoy/issues/3508

The likelihood of a relation is low, but I've included links to the issues for the sake of completenes.

I have yet to find the root cause, but it feels like handling around config (either a leak or purposeful check-point while merging changes).

@davecheney

• Any ideas?
• Have you seen anything similar?
• Would you rather I reach out directly to envoy?

Summary

The goal is to observe container memory while adding and removing ingress definitions.

• nothing other than the ingress definitions are changing.
• there is also no traffic to the ingresses.

Spoilers

• memory shows a large (linear) growth while adding TLS ingress definitions
• the same growth is NOT see for non-TLS ingress definitions

Launch Context

To help eliminate possible causes for memory growth, both hot restart and envoy metrics scraping have been disabled.

---
apiVersion: v1
kind: ServiceAccount
metadata:
  labels:
    app: contour-ingress
  name: contour-ingress
  namespace: ingress-system
---
apiVersion: v1
kind: Service
metadata:
  labels:
    app: contour-ingress
    component: debug
  name: contour-ingress-debug
  namespace: ingress-system
spec:
  ports:
    - port: 80
      name: http
      protocol: TCP
      targetPort: 8080
    - port: 443
      name: https
      protocol: TCP
      targetPort: 8443
  selector:
    app: contour-ingress
    component: debug
  type: LoadBalancer
---
apiVersion: extensions/v1beta1
kind: Deployment
metadata:
  labels:
    app: contour-ingress
    component: debug
  name: contour-ingress-debug
  namespace: ingress-system
spec:
  selector:
    matchLabels:
      app: contour-ingress
      component: debug
  replicas: 1
  template:
    metadata:
      labels:
        app: contour-ingress
        component: debug
      annotations:
        prometheus.io/scrape: "false"
        prometheus.io/port: "9001"
        prometheus.io/path: "/stats"
        prometheus.io/format: "prometheus"
    spec:
      dnsPolicy: ClusterFirst
      serviceAccountName: contour-ingress
      terminationGracePeriodSeconds: 30
      initContainers:
        - name: envoy-init
          image: gcr.io/heptio-images/contour:v0.5.0
          imagePullPolicy: IfNotPresent
          command: ["contour"]
          args:
            - bootstrap
            - /config/contour.yaml
            - --admin-address=0.0.0.0
          volumeMounts:
            - name: contour-config
              mountPath: /config
      containers:
        - name: contour
          image: gcr.io/heptio-images/contour:v0.5.0
          imagePullPolicy: IfNotPresent
          command: ["contour"]
          args:
            - serve
            - --incluster
            - --ingress-class-name=contour-debug
        - name: envoy
          image: docker.io/envoyproxy/envoy-alpine-debug:v1.6.0
          imagePullPolicy: IfNotPresent
          ports:
            - containerPort: 8080
              name: http
            - containerPort: 8443
              name: https
          command: ["envoy"]
          args:
            - -c /config/contour.yaml
            - --service-cluster cluster0
            - --service-node node0
            - --disable-hot-restart
            - --v2-config-only
            - --log-level info
          env:
            - name: HEAPCHECK
              value: "strict"
            - name: HEAPPROFILE
              value: "/tmp/envoy.hprof"
          volumeMounts:
            - name: contour-config
              mountPath: /config
      volumes:
        - name: contour-config
          emptyDir:
            medium: "Memory"
            sizeLimit: 8Mi
      affinity:
        podAntiAffinity:
          preferredDuringSchedulingIgnoredDuringExecution:
          - weight: 100
            podAffinityTerm:
              labelSelector:
                matchLabels:
                  app: contour-ingress
                  component: debug
              topologyKey: kubernetes.io/hostname
---

Observation ~ Adding Ingresses

Let's observe container memory while adding ingress definitions.

Though envoy specific metrics are currently unavailable (the scrape is disabled); container memory metrics were mirrored by envoy heap allocation prior to disabling.

>$ kubectl -n ingress-system top pods -l'app=contour-ingress,component=debug'
NAME                                          CPU(cores)   MEMORY(bytes)   
contour-ingress-debug-64d76ff7ff-sv7z9         121m         94Mi            

The tool clone-http-ingress.sh is bash script that adds ingress definitions in blocks

• n - total number of ingress definitions
• b - block size

The ingress definition is generated from this template.

---
apiVersion: extensions/v1beta1
kind: Ingress
metadata:
  name: $META_NAME
  labels:
    ingress: $INGRESS_CLASS
    role: test
  annotations:
    kubernetes.io/ingress.class: $INGRESS_CLASS
spec:
  tls:
  - hosts:
    - $SPEC_HOST
    secretName: httpbin
  rules:
  - host: $SPEC_HOST
    http:
      paths:
      - path: /
        backend:
          serviceName: httpbin
          servicePort: 8000
---

The command below will add a total of 5000 definitions in blocks of 100.

>$ ./clone-http-ingress.sh -b 100 -n 5000
REPORT
total=5000
block_size=100
delay enabled=0 delay=0.000000

BLOCK    MEMORY   DURATION
00000000 91Mi     17.20000000
00000001 91Mi     15.18000000
00000002 91Mi     19.02000000
00000003 1628Mi   21.68000000
00000004 1628Mi   19.76000000
00000005 1628Mi   20.33000000
00000006 3550Mi   19.08000000
00000007 3550Mi   23.22000000
00000008 3550Mi   24.30000000
00000009 6123Mi   25.92000000
00000010 6123Mi   24.22000000
00000011 8075Mi   28.61000000
00000012 8075Mi   24.51000000
00000013 10248Mi  24.16000000
00000014 10248Mi  30.01000000
00000015 12601Mi  27.30000000
00000016 12601Mi  27.13000000
00000017 12601Mi  29.85000000
00000018 14741Mi  31.88000000
00000019 16793Mi  32.22000000
00000020 16793Mi  34.20000000
00000021 18388Mi  34.93000000
00000022 18388Mi  38.84000000
00000023 20918Mi  40.79000000
00000024 22845Mi  41.11000000
00000025 22845Mi  40.71000000
00000026 24758Mi  43.63000000
00000027 27056Mi  45.06000000
00000028 28994Mi  50.16000000
00000029 30965Mi  46.90000000
00000030 30965Mi  47.86000000
00000031 33168Mi  47.39000000
00000032 35386Mi  48.52000000
00000033 37886Mi  51.76000000
00000034 39765Mi  58.24000000
00000035 42228Mi  56.12000000
00000036 44600Mi  51.11000000
00000037 46879Mi  54.84000000
00000038 46879Mi  53.24000000
00000039 49202Mi  51.93000000
00000040 51236Mi  55.18000000
00000041 53300Mi  53.77000000
00000042 54895Mi  55.32000000
00000043 56731Mi  57.56000000
00000044 58954Mi  58.81000000
00000045 60353Mi  61.28000000
00000046 62116Mi  57.53000000
00000047 63968Mi  61.20000000
00000048 65922Mi  61.22000000
00000049 67487Mi  61.11000000

• envoy admin page is unresponsive ("/" or any "/command")
• when enabled, scraping fails (admin /stats page is also unresponsive)
• memory climbs linearly during addition
• memory never decreases, stuck at ~64Gi

>$ POD_NAME=$(kubectl get pods -n ingress-system -l "app=contour-ingress,component=debug" -o jsonpath="{.items[0].metadata.name}"); echo $POD_NAME
>$ kubectl -n ingress-system delete pod $POD_NAME

>$ kubectl -n ingress-system top pods -l'app=contour-ingress,component=debug'
NAME                                    CPU(cores)   MEMORY(bytes)   
contour-ingress-debug-64d76ff7ff-kt5hk   284m         1391Mi 

• memory after reboot is <2Gi
• all 5000 ingress definitions still exist

Observation ~ Deleting Ingresses

Continuing from the conditions above, let's observe memory while cleaning up the cluster.

>$ kubectl -n ingress-system top pods -l'app=contour-ingress,component=debug'
NAME                                    CPU(cores)   MEMORY(bytes)   
contour-ingress-debug-64d76ff7ff-kt5hk   259m         1228Mi  

• all 5000 ingress definitions still exist

>$ kubectl delete ing --all
ingress.extensions "httpbin-contour-0" deleted
ingress.extensions "httpbin-contour-1" deleted
...

• the command takes a while, but eventually completes
• memory climbs linearly during deletion (~1Gi to ~8Gi)

>$ kubectl -n ingress-system top pods -l'app=contour-ingress,component=debug'
NAME                                    CPU(cores)   MEMORY(bytes)   
contour-ingress-debug-64d76ff7ff-kt5hk   272m         7853Mi   

• memory never decrease, stuck at ~8Gi

Heap Trace

Selecting a heap trace from during the middle of insertion, there does appear to be a fairly large leak. I've included the top set of leaks (not all), to avoid a huge copy-paste.

Welcome to pprof!  For help, type 'help'.
(pprof) top
Total: 5321.2 MB
Leak of 366498538 bytes in 436607 objects allocated from:
    @ 0090f485 unknown
    @ 00000000008df612 BUF_memdup ?
    @ 000000000091b217 CRYPTO_BUFFER_new ?
    @ 00000000008ba473 _ZN4bssl8internal11DeleterImplI7x509_stvE4FreeEPS2_ ?
    @ 00000000008baa39 _ZN4bssl8internal11DeleterImplI7x509_stvE4FreeEPS2_ ?
    @ 0000000000688f0c _ZN5Envoy3Ssl11ContextImplC2ERNS0_18ContextManagerImplERNS_5Stats5ScopeERKNS0_13ContextConfigE ?
    @ 0000000000689e06 _ZN5Envoy3Ssl17ServerContextImplC1ERNS0_18ContextManagerImplERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS9_SaIS9_EERNS_5Stats5ScopeERKNS0_19ServerContextConfigEbRNS_7Runtime6LoaderE ?
    @ 000000000068c6af _ZN5Envoy3Ssl18ContextManagerImpl22createSslServerContextERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS7_SaIS7_EERNS_5Stats5ScopeERKNS0_19ServerContextConfigEb ?
    @ 000000000056e9bc _ZN5Envoy3Ssl22ServerSslSocketFactoryC2ERKNS0_19ServerContextConfigERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorISA_SaISA_EEbRNS0_14ContextManagerERNS_5Stats5ScopeE ?
    @ 000000000051f83c _ZN5Envoy6Server13Configuration26DownstreamSslSocketFactory28createTransportSocketFactoryERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS8_SaIS8_EEbRKN6google8protobuf7MessageERNS1_29TransportSocketFactoryContextE ?
    @ 000000000055a02c _ZN5Envoy6Server12ListenerImplC2ERKN5envoy3api2v28ListenerERNS0_19ListenerManagerImplERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEbbm ?
    @ 000000000055b575 _ZN5Envoy6Server19ListenerManagerImpl19addOrUpdateListenerERKN5envoy3api2v28ListenerEb ?
    @ 000000000076b0dd _ZN5Envoy6Server6LdsApi14onConfigUpdateERKN6google8protobuf16RepeatedPtrFieldIN5envoy3api2v28ListenerEEE ?
    @ 000000000076cce0 _ZN5Envoy6Config23GrpcMuxSubscriptionImplIN5envoy3api2v28ListenerEE14onConfigUpdateERKN6google8protobuf16RepeatedPtrFieldINS8_3AnyEEERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE ?
    @ 00000000007722b3 _ZN5Envoy6Config11GrpcMuxImpl16onReceiveMessageEOSt10unique_ptrIN5envoy3api2v217DiscoveryResponseESt14default_deleteIS6_EE ?
    @ 000000000076f622 _ZN5Envoy4Grpc25TypedAsyncStreamCallbacksIN5envoy3api2v217DiscoveryResponseEE23onReceiveMessageUntypedEOSt10unique_ptrIN6google8protobuf7MessageESt14default_deleteISA_EE ?
    @ 0000000000788c65 _ZN5Envoy4Grpc15AsyncStreamImpl6onDataERNS_6Buffer8InstanceEb ?
    @ 000000000078d93b _ZN5Envoy4Http15AsyncStreamImpl10encodeDataERNS_6Buffer8InstanceEb ?
    @ 00000000006b2a93 _ZN5Envoy4Http5Http214ConnectionImpl15onFrameReceivedEPK13nghttp2_frame ?
    @ 00000000006b58b6 nghttp2_session_del ?
    @ 00000000006b94e1 nghttp2_session_mem_recv ?
    @ 00000000006b1aee _ZN5Envoy4Http5Http214ConnectionImpl8dispatchERNS_6Buffer8InstanceE ?
    @ 000000000066634e _ZN5Envoy4Http11CodecClient6onDataERNS_6Buffer8InstanceE ?
    @ 00000000006664cc _ZN5Envoy4Http11CodecClient15CodecReadFilter6onDataERNS_6Buffer8InstanceEb ?
    @ 000000000056dc66 _ZN5Envoy7Network17FilterManagerImpl17onContinueReadingEPNS1_16ActiveReadFilterE ?
    @ 000000000056c5ce _ZN5Envoy7Network14ConnectionImpl11onReadReadyEv ?
    @ 000000000056cded _ZN5Envoy7Network14ConnectionImpl11onFileEventEj ?
    @ 0000000000566307 _ZN5Envoy5Event13FileEventImpl8activateEj ?
    @ 00000000008a1d11 event_add_nolock_ ?
    @ 00000000008a246e event_base_loop ?
    @ 000000000054dcdd _ZN5Envoy6Server12InstanceImpl3runEv ?
    @ 0000000000464850 _ZN5Envoy14MainCommonBase3runEv ?
Leak of 261964200 bytes in 436607 objects allocated from:
    @ 0090f485 unknown
    @ 00000000008ae16c SSL_CTX_new ?
    @ 00000000006888ae _ZN5Envoy3Ssl11ContextImplC2ERNS0_18ContextManagerImplERNS_5Stats5ScopeERKNS0_13ContextConfigE ?
    @ 0000000000689e06 _ZN5Envoy3Ssl17ServerContextImplC1ERNS0_18ContextManagerImplERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS9_SaIS9_EERNS_5Stats5ScopeERKNS0_19ServerContextConfigEbRNS_7Runtime6LoaderE ?
    @ 000000000068c6af _ZN5Envoy3Ssl18ContextManagerImpl22createSslServerContextERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS7_SaIS7_EERNS_5Stats5ScopeERKNS0_19ServerContextConfigEb ?
    @ 000000000056e9bc _ZN5Envoy3Ssl22ServerSslSocketFactoryC2ERKNS0_19ServerContextConfigERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorISA_SaISA_EEbRNS0_14ContextManagerERNS_5Stats5ScopeE ?
    @ 000000000051f83c _ZN5Envoy6Server13Configuration26DownstreamSslSocketFactory28createTransportSocketFactoryERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS8_SaIS8_EEbRKN6google8protobuf7MessageERNS1_29TransportSocketFactoryContextE ?
    @ 000000000055a02c _ZN5Envoy6Server12ListenerImplC2ERKN5envoy3api2v28ListenerERNS0_19ListenerManagerImplERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEbbm ?
    @ 000000000055b575 _ZN5Envoy6Server19ListenerManagerImpl19addOrUpdateListenerERKN5envoy3api2v28ListenerEb ?
    @ 000000000076b0dd _ZN5Envoy6Server6LdsApi14onConfigUpdateERKN6google8protobuf16RepeatedPtrFieldIN5envoy3api2v28ListenerEEE ?
    @ 000000000076cce0 _ZN5Envoy6Config23GrpcMuxSubscriptionImplIN5envoy3api2v28ListenerEE14onConfigUpdateERKN6google8protobuf16RepeatedPtrFieldINS8_3AnyEEERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE ?
    @ 00000000007722b3 _ZN5Envoy6Config11GrpcMuxImpl16onReceiveMessageEOSt10unique_ptrIN5envoy3api2v217DiscoveryResponseESt14default_deleteIS6_EE ?
    @ 000000000076f622 _ZN5Envoy4Grpc25TypedAsyncStreamCallbacksIN5envoy3api2v217DiscoveryResponseEE23onReceiveMessageUntypedEOSt10unique_ptrIN6google8protobuf7MessageESt14default_deleteISA_EE ?
    @ 0000000000788c65 _ZN5Envoy4Grpc15AsyncStreamImpl6onDataERNS_6Buffer8InstanceEb ?
    @ 000000000078d93b _ZN5Envoy4Http15AsyncStreamImpl10encodeDataERNS_6Buffer8InstanceEb ?
    @ 00000000006b2a93 _ZN5Envoy4Http5Http214ConnectionImpl15onFrameReceivedEPK13nghttp2_frame ?
    @ 00000000006b58b6 nghttp2_session_del ?
    @ 00000000006b94e1 nghttp2_session_mem_recv ?
    @ 00000000006b1aee _ZN5Envoy4Http5Http214ConnectionImpl8dispatchERNS_6Buffer8InstanceE ?
    @ 000000000066634e _ZN5Envoy4Http11CodecClient6onDataERNS_6Buffer8InstanceE ?
    @ 00000000006664cc _ZN5Envoy4Http11CodecClient15CodecReadFilter6onDataERNS_6Buffer8InstanceEb ?
    @ 000000000056dc66 _ZN5Envoy7Network17FilterManagerImpl17onContinueReadingEPNS1_16ActiveReadFilterE ?
    @ 000000000056c5ce _ZN5Envoy7Network14ConnectionImpl11onReadReadyEv ?
    @ 000000000056cded _ZN5Envoy7Network14ConnectionImpl11onFileEventEj ?
    @ 0000000000566307 _ZN5Envoy5Event13FileEventImpl8activateEj ?
    @ 00000000008a1d11 event_add_nolock_ ?
    @ 00000000008a246e event_base_loop ?
    @ 000000000054dcdd _ZN5Envoy6Server12InstanceImpl3runEv ?
    @ 0000000000464850 _ZN5Envoy14MainCommonBase3runEv ?
    @ 00000000004156c8 main ?
    @ 00007f609ebcdb8d unknown
Leak of 244248578 bytes in 436607 objects allocated from:
    @ 0090f485 unknown
    @ 00000000008d7047 asn1_enc_save ?
    @ 00000000008d4ebd ASN1_item_ex_d2i ?
    @ 00000000008d519c ASN1_item_d2i ?
    @ 00000000008d53db ASN1_item_d2i ?
    @ 00000000008d4c3b ASN1_item_ex_d2i ?
    @ 00000000008d4f6a ASN1_item_d2i ?
    @ 000000000090f3c8 d2i_X509_AUX ?
    @ 0000000000913487 PEM_ASN1_read_bio ?
    @ 0000000000688edc _ZN5Envoy3Ssl11ContextImplC2ERNS0_18ContextManagerImplERNS_5Stats5ScopeERKNS0_13ContextConfigE ?
    @ 0000000000689e06 _ZN5Envoy3Ssl17ServerContextImplC1ERNS0_18ContextManagerImplERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS9_SaIS9_EERNS_5Stats5ScopeERKNS0_19ServerContextConfigEbRNS_7Runtime6LoaderE ?
    @ 000000000068c6af _ZN5Envoy3Ssl18ContextManagerImpl22createSslServerContextERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS7_SaIS7_EERNS_5Stats5ScopeERKNS0_19ServerContextConfigEb ?
    @ 000000000056e9bc _ZN5Envoy3Ssl22ServerSslSocketFactoryC2ERKNS0_19ServerContextConfigERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorISA_SaISA_EEbRNS0_14ContextManagerERNS_5Stats5ScopeE ?
    @ 000000000051f83c _ZN5Envoy6Server13Configuration26DownstreamSslSocketFactory28createTransportSocketFactoryERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS8_SaIS8_EEbRKN6google8protobuf7MessageERNS1_29TransportSocketFactoryContextE ?
    @ 000000000055a02c _ZN5Envoy6Server12ListenerImplC2ERKN5envoy3api2v28ListenerERNS0_19ListenerManagerImplERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEbbm ?
    @ 000000000055b575 _ZN5Envoy6Server19ListenerManagerImpl19addOrUpdateListenerERKN5envoy3api2v28ListenerEb ?
    @ 000000000076b0dd _ZN5Envoy6Server6LdsApi14onConfigUpdateERKN6google8protobuf16RepeatedPtrFieldIN5envoy3api2v28ListenerEEE ?
    @ 000000000076cce0 _ZN5Envoy6Config23GrpcMuxSubscriptionImplIN5envoy3api2v28ListenerEE14onConfigUpdateERKN6google8protobuf16RepeatedPtrFieldINS8_3AnyEEERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE ?
    @ 00000000007722b3 _ZN5Envoy6Config11GrpcMuxImpl16onReceiveMessageEOSt10unique_ptrIN5envoy3api2v217DiscoveryResponseESt14default_deleteIS6_EE ?
    @ 000000000076f622 _ZN5Envoy4Grpc25TypedAsyncStreamCallbacksIN5envoy3api2v217DiscoveryResponseEE23onReceiveMessageUntypedEOSt10unique_ptrIN6google8protobuf7MessageESt14default_deleteISA_EE ?
    @ 0000000000788c65 _ZN5Envoy4Grpc15AsyncStreamImpl6onDataERNS_6Buffer8InstanceEb ?
    @ 000000000078d93b _ZN5Envoy4Http15AsyncStreamImpl10encodeDataERNS_6Buffer8InstanceEb ?
    @ 00000000006b2a93 _ZN5Envoy4Http5Http214ConnectionImpl15onFrameReceivedEPK13nghttp2_frame ?
    @ 00000000006b58b6 nghttp2_session_del ?
    @ 00000000006b94e1 nghttp2_session_mem_recv ?
    @ 00000000006b1aee _ZN5Envoy4Http5Http214ConnectionImpl8dispatchERNS_6Buffer8InstanceE ?
    @ 000000000066634e _ZN5Envoy4Http11CodecClient6onDataERNS_6Buffer8InstanceE ?
    @ 00000000006664cc _ZN5Envoy4Http11CodecClient15CodecReadFilter6onDataERNS_6Buffer8InstanceEb ?
    @ 000000000056dc66 _ZN5Envoy7Network17FilterManagerImpl17onContinueReadingEPNS1_16ActiveReadFilterE ?
    @ 000000000056c5ce _ZN5Envoy7Network14ConnectionImpl11onReadReadyEv ?
    @ 000000000056cded _ZN5Envoy7Network14ConnectionImpl11onFileEventEj ?
    @ 0000000000566307 _ZN5Envoy5Event13FileEventImpl8activateEj ?
Leak of 185121368 bytes in 436607 objects allocated from:
    @ 0068c684 unknown
    @ 000000000056e9bc _ZN5Envoy3Ssl22ServerSslSocketFactoryC2ERKNS0_19ServerContextConfigERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorISA_SaISA_EEbRNS0_14ContextManagerERNS_5Stats5ScopeE ?
    @ 000000000051f83c _ZN5Envoy6Server13Configuration26DownstreamSslSocketFactory28createTransportSocketFactoryERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS8_SaIS8_EEbRKN6google8protobuf7MessageERNS1_29TransportSocketFactoryContextE ?
    @ 000000000055a02c _ZN5Envoy6Server12ListenerImplC2ERKN5envoy3api2v28ListenerERNS0_19ListenerManagerImplERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEbbm ?
    @ 000000000055b575 _ZN5Envoy6Server19ListenerManagerImpl19addOrUpdateListenerERKN5envoy3api2v28ListenerEb ?
    @ 000000000076b0dd _ZN5Envoy6Server6LdsApi14onConfigUpdateERKN6google8protobuf16RepeatedPtrFieldIN5envoy3api2v28ListenerEEE ?
    @ 000000000076cce0 _ZN5Envoy6Config23GrpcMuxSubscriptionImplIN5envoy3api2v28ListenerEE14onConfigUpdateERKN6google8protobuf16RepeatedPtrFieldINS8_3AnyEEERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE ?
    @ 00000000007722b3 _ZN5Envoy6Config11GrpcMuxImpl16onReceiveMessageEOSt10unique_ptrIN5envoy3api2v217DiscoveryResponseESt14default_deleteIS6_EE ?
    @ 000000000076f622 _ZN5Envoy4Grpc25TypedAsyncStreamCallbacksIN5envoy3api2v217DiscoveryResponseEE23onReceiveMessageUntypedEOSt10unique_ptrIN6google8protobuf7MessageESt14default_deleteISA_EE ?
    @ 0000000000788c65 _ZN5Envoy4Grpc15AsyncStreamImpl6onDataERNS_6Buffer8InstanceEb ?
    @ 000000000078d93b _ZN5Envoy4Http15AsyncStreamImpl10encodeDataERNS_6Buffer8InstanceEb ?
    @ 00000000006b2a93 _ZN5Envoy4Http5Http214ConnectionImpl15onFrameReceivedEPK13nghttp2_frame ?
    @ 00000000006b58b6 nghttp2_session_del ?
    @ 00000000006b94e1 nghttp2_session_mem_recv ?
    @ 00000000006b1aee _ZN5Envoy4Http5Http214ConnectionImpl8dispatchERNS_6Buffer8InstanceE ?
    @ 000000000066634e _ZN5Envoy4Http11CodecClient6onDataERNS_6Buffer8InstanceE ?
    @ 00000000006664cc _ZN5Envoy4Http11CodecClient15CodecReadFilter6onDataERNS_6Buffer8InstanceEb ?
    @ 000000000056dc66 _ZN5Envoy7Network17FilterManagerImpl17onContinueReadingEPNS1_16ActiveReadFilterE ?
    @ 000000000056c5ce _ZN5Envoy7Network14ConnectionImpl11onReadReadyEv ?
    @ 000000000056cded _ZN5Envoy7Network14ConnectionImpl11onFileEventEj ?
    @ 0000000000566307 _ZN5Envoy5Event13FileEventImpl8activateEj ?
    @ 00000000008a1d11 event_add_nolock_ ?
    @ 00000000008a246e event_base_loop ?
    @ 000000000054dcdd _ZN5Envoy6Server12InstanceImpl3runEv ?
    @ 0000000000464850 _ZN5Envoy14MainCommonBase3runEv ?
    @ 00000000004156c8 main ?
    @ 00007f609ebcdb8d unknown
Leak of 121306021 bytes in 436607 objects allocated from:
    @ 0090f485 unknown
    @ 000000000091d8cd c2i_ASN1_BIT_STRING ?
    @ 00000000008d3cf6 asn1_ex_c2i ?
    @ 00000000008d414b asn1_ex_c2i ?
    @ 00000000008d4e0a ASN1_item_ex_d2i ?
    @ 00000000008d519c ASN1_item_d2i ?
    @ 00000000008d53db ASN1_item_d2i ?
    @ 00000000008d4c3b ASN1_item_ex_d2i ?
    @ 00000000008d519c ASN1_item_d2i ?
    @ 00000000008d53db ASN1_item_d2i ?
    @ 00000000008d4c3b ASN1_item_ex_d2i ?
    @ 00000000008d519c ASN1_item_d2i ?
    @ 00000000008d53db ASN1_item_d2i ?
    @ 00000000008d4c3b ASN1_item_ex_d2i ?
    @ 00000000008d4f6a ASN1_item_d2i ?
    @ 000000000090f3c8 d2i_X509_AUX ?
    @ 0000000000913487 PEM_ASN1_read_bio ?
    @ 0000000000688edc _ZN5Envoy3Ssl11ContextImplC2ERNS0_18ContextManagerImplERNS_5Stats5ScopeERKNS0_13ContextConfigE ?
    @ 0000000000689e06 _ZN5Envoy3Ssl17ServerContextImplC1ERNS0_18ContextManagerImplERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS9_SaIS9_EERNS_5Stats5ScopeERKNS0_19ServerContextConfigEbRNS_7Runtime6LoaderE ?
    @ 000000000068c6af _ZN5Envoy3Ssl18ContextManagerImpl22createSslServerContextERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS7_SaIS7_EERNS_5Stats5ScopeERKNS0_19ServerContextConfigEb ?
    @ 000000000056e9bc _ZN5Envoy3Ssl22ServerSslSocketFactoryC2ERKNS0_19ServerContextConfigERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorISA_SaISA_EEbRNS0_14ContextManagerERNS_5Stats5ScopeE ?
    @ 000000000051f83c _ZN5Envoy6Server13Configuration26DownstreamSslSocketFactory28createTransportSocketFactoryERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEERKSt6vectorIS8_SaIS8_EEbRKN6google8protobuf7MessageERNS1_29TransportSocketFactoryContextE ?
    @ 000000000055a02c _ZN5Envoy6Server12ListenerImplC2ERKN5envoy3api2v28ListenerERNS0_19ListenerManagerImplERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEEbbm ?
    @ 000000000055b575 _ZN5Envoy6Server19ListenerManagerImpl19addOrUpdateListenerERKN5envoy3api2v28ListenerEb ?
    @ 000000000076b0dd _ZN5Envoy6Server6LdsApi14onConfigUpdateERKN6google8protobuf16RepeatedPtrFieldIN5envoy3api2v28ListenerEEE ?
    @ 000000000076cce0 _ZN5Envoy6Config23GrpcMuxSubscriptionImplIN5envoy3api2v28ListenerEE14onConfigUpdateERKN6google8protobuf16RepeatedPtrFieldINS8_3AnyEEERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE ?
    @ 00000000007722b3 _ZN5Envoy6Config11GrpcMuxImpl16onReceiveMessageEOSt10unique_ptrIN5envoy3api2v217DiscoveryResponseESt14default_deleteIS6_EE ?
    @ 000000000076f622 _ZN5Envoy4Grpc25TypedAsyncStreamCallbacksIN5envoy3api2v217DiscoveryResponseEE23onReceiveMessageUntypedEOSt10unique_ptrIN6google8protobuf7MessageESt14default_deleteISA_EE ?
    @ 0000000000788c65 _ZN5Envoy4Grpc15AsyncStreamImpl6onDataERNS_6Buffer8InstanceEb ?
    @ 000000000078d93b _ZN5Envoy4Http15AsyncStreamImpl10encodeDataERNS_6Buffer8InstanceEb ?
    @ 00000000006b2a93 _ZN5Envoy4Http5Http214ConnectionImpl15onFrameReceivedEPK13nghttp2_frame ?
    @ 00000000006b58b6 nghttp2_session_del ?

[mattalberts]

envoy.hprof.0180.heap.txt

• head trace output for envoy

[davecheney]

@mattalberts thank you for your detailed bug report. I'm sorry that Contour is behaviour like that, there is no reason for Contour to consume gigabytes of memory, let alone hundreds of megabytes.

Internally at Heptio I've also had a report that matches your symptoms, but from memory it never made it into an issue (/cc @alexbrand, please correct me if I'm wrong).

I see that you're using Contour 0.5.0. The tricky bit about investigating this issue is that over the last two weeks almost all of contours business logic has been rewritten to support the new CRD we're adding in 0.6. The downside of that is any effort spent investigating what is going on with 0.5 is probably wasted effort as the code that may be causing the issue has likely gone to data heaven.

I just landed #504 which marks the rewrite complete with respect to the features of Contour 0.5 -- everything that worked in 0.5 is confirmed to work in master now.

How would you feel about trying to reproduce the problem with gcr.io/heptio-images/contour:master? If you don't feel comfortable chasing :master, we'll be doing a 0.6 beta.1 release very soon, probably early next week.

I'm going to continue to investigate this issue and have tagged it as a blocker for 0.6 final.

[alexbrand]

We saw a memory consumption issue in the contour process, which I was not able to reproduce in 0.6-alpha.1 (https://github.com/heptio/contour/issues/424#issuecomment-396327057).

It seems to me like this is a leak in Envoy though?

[mattalberts]

@alexbrand @davecheney Hi! Thanks for writing back. Contour actually appears to be the reasonable container (I also really like the project :P); its envoy that appears to be leaky (though I wasn't certain where to origin the issue).

I'm happy to start eval'ing from master! Its pretty easy to stand up a test environment and re-run my scripts :).

[davecheney]

Thanks for confirming. Even though contour's container is well behaved the issue causing Envoy to grow huge might be contour's fault; something with the way we're communicating with Envoy perhaps. I'm going to keep this issue open as a high priority, but also reference #443 which we'll do whenever we start on the 0.7 cycle (probably august)

[mattalberts]

Update ~ contour:master

Based on interested, I've updated to contour:master and re-run tests.

The results are largely the same; though, the slope of the line plotting memory growth is lower (e.g. we still grow into GBs of memory used, but top out at ~32GB rather than ~64GB).

@davecheney
@alexbrand

Observation ~ Adding Ingresses

malbook:ingress-system malberts$ ./tools/clone-http-ingress.sh -n 5000 -b 100
REPORT
total=5000
block_size=100
delay enabled=0 duration=0.000000

BLOCK    MEMORY   DURATION
00000000 38Mi     12.73000000
00000001 38Mi     13.51000000
00000002 38Mi     15.69000000
00000003 727Mi    16.91000000
00000004 727Mi    19.13000000
00000005 727Mi    18.27000000
00000006 1397Mi   19.66000000
00000007 1397Mi   17.98000000
00000008 1397Mi   20.06000000
00000009 2322Mi   20.20000000
00000010 2322Mi   21.42000000
00000011 2322Mi   23.06000000
00000012 3201Mi   26.34000000
00000013 3201Mi   26.48000000
00000014 3962Mi   26.93000000
00000015 3962Mi   31.62000000
00000016 4750Mi   26.29000000
00000017 4750Mi   29.35000000
00000018 5308Mi   31.72000000
00000019 5308Mi   29.80000000
00000020 6104Mi   33.49000000
00000021 6104Mi   33.40000000
00000022 7012Mi   36.17000000
00000023 7745Mi   44.15000000
00000024 8615Mi   48.12000000
00000025 8615Mi   46.05000000
00000026 9419Mi   42.14000000
00000027 10281Mi  41.55000000
00000028 10281Mi  43.36000000
00000029 11109Mi  45.34000000
00000030 11907Mi  47.71000000
00000031 12713Mi  70.68000000
00000032 13480Mi  70.05000000
00000033 15110Mi  76.67000000
00000034 15853Mi  66.57000000
00000035 16718Mi  75.32000000
00000036 17501Mi  77.54000000
00000037 19168Mi  72.29000000
00000038 20075Mi  74.16000000
00000039 20848Mi  82.56000000
00000040 22403Mi  95.71000000
00000041 23176Mi  75.30000000
00000042 23908Mi  76.13000000
00000043 25675Mi  85.38000000
00000044 26451Mi  81.63000000
00000045 27945Mi  83.64000000
00000046 28724Mi  85.74000000
00000047 30249Mi  87.59000000
00000048 31112Mi  90.99000000
00000049 32721Mi  100.62000000

Heap Trace

Again, I've only included a portion of the output to reduce the copy-paste size. At least I was able to get a more legible stack trace (the raw-trace is attached).

(pprof) top
Total: 9982.5 MB
Leak of 697222424 bytes in 831016 objects allocated from:
    @ 0090f485 unknown
    @ 00000000008df612 BUF_memdup ??:0
    @ 000000000091b217 CRYPTO_BUFFER_new ??:0
    @ 00000000008ba473 bssl::x509_to_buffer ssl_x509.cc:0
    @ 00000000008baa39 ssl_use_certificate ssl_x509.cc:0
    @ 0000000000688f0c Envoy::Ssl::ContextImpl::ContextImpl /proc/self/cwd/source/common/ssl/context_impl.cc:144
    @ 0000000000689e06 Envoy::Ssl::ServerContextImpl::ServerContextImpl /proc/self/cwd/source/common/ssl/context_impl.cc:439
    @ 000000000068c6af Envoy::Ssl::ContextManagerImpl::createSslServerContext /proc/self/cwd/source/common/ssl/context_manager_impl.cc:75
    @ 000000000056e9bc Envoy::Ssl::ServerSslSocketFactory::ServerSslSocketFactory /proc/self/cwd/source/common/ssl/ssl_socket.cc:375
    @ 000000000051f83c Envoy::Server::Configuration::DownstreamSslSocketFactory::createTransportSocketFactory /proc/self/cwd/source/server/config/network/ssl_socket.cc:36
    @ 000000000055a02c Envoy::Server::ListenerImpl::ListenerImpl /proc/self/cwd/source/server/listener_manager_impl.cc:203
    @ 000000000055b575 Envoy::Server::ListenerManagerImpl::addOrUpdateListener /proc/self/cwd/source/server/listener_manager_impl.cc:330
    @ 000000000076b0dd Envoy::Server::LdsApi::onConfigUpdate /proc/self/cwd/source/server/lds_api.cc:59
    @ 000000000076cce0 Envoy::Config::GrpcMuxSubscriptionImpl::onConfigUpdate /proc/self/cwd/bazel-out/k8-opt/bin/source/common/config/_virtual_includes/grpc_mux_subscription_lib/common/config/grpc_mux_subscription_impl.h:53
    @ 00000000007722b3 Envoy::Config::GrpcMuxImpl::onReceiveMessage /proc/self/cwd/source/common/config/grpc_mux_impl.cc:174
    @ 000000000076f622 Envoy::Grpc::TypedAsyncStreamCallbacks::onReceiveMessageUntyped /proc/self/cwd/bazel-out/k8-opt/bin/include/envoy/grpc/_virtual_includes/async_client_interface/envoy/grpc/async_client.h:172
    @ 0000000000788c65 Envoy::Grpc::AsyncStreamImpl::onData /proc/self/cwd/source/common/grpc/async_client_impl.cc:131
    @ 000000000078d93b Envoy::Http::AsyncStreamImpl::encodeData /proc/self/cwd/source/common/http/async_client_impl.cc:108
    @ 00000000006b2a93 Envoy::Http::Http2::ConnectionImpl::onFrameReceived /proc/self/cwd/source/common/http/http2/codec_impl.cc:445
    @ 00000000006b58b6 nghttp2_session_on_data_received /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:4881
    @ 00000000006b94e1 nghttp2_session_mem_recv /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:6443
    @ 00000000006b1aee Envoy::Http::Http2::ConnectionImpl::dispatch /proc/self/cwd/source/common/http/http2/codec_impl.cc:302
    @ 000000000066634e Envoy::Http::CodecClient::onData /proc/self/cwd/source/common/http/codec_client.cc:115
    @ 00000000006664cc Envoy::Http::CodecClient::CodecReadFilter::onData /proc/self/cwd/bazel-out/k8-opt/bin/source/common/http/_virtual_includes/codec_client_lib/common/http/codec_client.h:159
    @ 000000000056dc66 Envoy::Network::FilterManagerImpl::onContinueReading /proc/self/cwd/source/common/network/filter_manager_impl.cc:56
    @ 000000000056c5ce Envoy::Network::ConnectionImpl::onReadReady /proc/self/cwd/source/common/network/connection_impl.cc:443
    @ 000000000056cded Envoy::Network::ConnectionImpl::onFileEvent /proc/self/cwd/source/common/network/connection_impl.cc:419
    @ 0000000000566307 _FUN /proc/self/cwd/source/common/event/file_event_impl.cc:61
    @ 00000000008a1d11 event_process_active_single_queue.isra.29 /tmp/libevent.dep.build/libevent-2.1.8-stable/event.c:1639
    @ 00000000008a246e event_base_loop /tmp/libevent.dep.build/libevent-2.1.8-stable/event.c:1961
    @ 000000000054dcdd Envoy::Server::InstanceImpl::run /proc/self/cwd/source/server/server.cc:356
    @ 0000000000464850 Envoy::MainCommonBase::run /proc/self/cwd/source/exe/main_common.cc:83
Leak of 498609600 bytes in 831016 objects allocated from:
    @ 0090f485 unknown
    @ 00000000008ae16c SSL_CTX_new ??:0
    @ 00000000006888ae Envoy::Ssl::ContextImpl::ContextImpl /proc/self/cwd/source/common/ssl/context_impl.cc:34
    @ 0000000000689e06 Envoy::Ssl::ServerContextImpl::ServerContextImpl /proc/self/cwd/source/common/ssl/context_impl.cc:439
    @ 000000000068c6af Envoy::Ssl::ContextManagerImpl::createSslServerContext /proc/self/cwd/source/common/ssl/context_manager_impl.cc:75
    @ 000000000056e9bc Envoy::Ssl::ServerSslSocketFactory::ServerSslSocketFactory /proc/self/cwd/source/common/ssl/ssl_socket.cc:375
    @ 000000000051f83c Envoy::Server::Configuration::DownstreamSslSocketFactory::createTransportSocketFactory /proc/self/cwd/source/server/config/network/ssl_socket.cc:36
    @ 000000000055a02c Envoy::Server::ListenerImpl::ListenerImpl /proc/self/cwd/source/server/listener_manager_impl.cc:203
    @ 000000000055b575 Envoy::Server::ListenerManagerImpl::addOrUpdateListener /proc/self/cwd/source/server/listener_manager_impl.cc:330
    @ 000000000076b0dd Envoy::Server::LdsApi::onConfigUpdate /proc/self/cwd/source/server/lds_api.cc:59
    @ 000000000076cce0 Envoy::Config::GrpcMuxSubscriptionImpl::onConfigUpdate /proc/self/cwd/bazel-out/k8-opt/bin/source/common/config/_virtual_includes/grpc_mux_subscription_lib/common/config/grpc_mux_subscription_impl.h:53
    @ 00000000007722b3 Envoy::Config::GrpcMuxImpl::onReceiveMessage /proc/self/cwd/source/common/config/grpc_mux_impl.cc:174
    @ 000000000076f622 Envoy::Grpc::TypedAsyncStreamCallbacks::onReceiveMessageUntyped /proc/self/cwd/bazel-out/k8-opt/bin/include/envoy/grpc/_virtual_includes/async_client_interface/envoy/grpc/async_client.h:172
    @ 0000000000788c65 Envoy::Grpc::AsyncStreamImpl::onData /proc/self/cwd/source/common/grpc/async_client_impl.cc:131
    @ 000000000078d93b Envoy::Http::AsyncStreamImpl::encodeData /proc/self/cwd/source/common/http/async_client_impl.cc:108
    @ 00000000006b2a93 Envoy::Http::Http2::ConnectionImpl::onFrameReceived /proc/self/cwd/source/common/http/http2/codec_impl.cc:445
    @ 00000000006b58b6 nghttp2_session_on_data_received /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:4881
    @ 00000000006b94e1 nghttp2_session_mem_recv /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:6443
    @ 00000000006b1aee Envoy::Http::Http2::ConnectionImpl::dispatch /proc/self/cwd/source/common/http/http2/codec_impl.cc:302
    @ 000000000066634e Envoy::Http::CodecClient::onData /proc/self/cwd/source/common/http/codec_client.cc:115
    @ 00000000006664cc Envoy::Http::CodecClient::CodecReadFilter::onData /proc/self/cwd/bazel-out/k8-opt/bin/source/common/http/_virtual_includes/codec_client_lib/common/http/codec_client.h:159
    @ 000000000056dc66 Envoy::Network::FilterManagerImpl::onContinueReading /proc/self/cwd/source/common/network/filter_manager_impl.cc:56
    @ 000000000056c5ce Envoy::Network::ConnectionImpl::onReadReady /proc/self/cwd/source/common/network/connection_impl.cc:443
    @ 000000000056cded Envoy::Network::ConnectionImpl::onFileEvent /proc/self/cwd/source/common/network/connection_impl.cc:419
    @ 0000000000566307 _FUN /proc/self/cwd/source/common/event/file_event_impl.cc:61
    @ 00000000008a1d11 event_process_active_single_queue.isra.29 /tmp/libevent.dep.build/libevent-2.1.8-stable/event.c:1639
    @ 00000000008a246e event_base_loop /tmp/libevent.dep.build/libevent-2.1.8-stable/event.c:1961
    @ 000000000054dcdd Envoy::Server::InstanceImpl::run /proc/self/cwd/source/server/server.cc:356
    @ 0000000000464850 Envoy::MainCommonBase::run /proc/self/cwd/source/exe/main_common.cc:83
    @ 00000000004156c8 main /proc/self/cwd/source/exe/main.cc:30
    @ 00007f114a497b8d unknown
Leak of 464537944 bytes in 831016 objects allocated from:
    @ 0090f485 unknown
    @ 00000000008d7047 asn1_enc_save ??:0
    @ 00000000008d4ebd ASN1_item_ex_d2i ??:0
    @ 00000000008d519c asn1_template_noexp_d2i tasn_dec.c:0
    @ 00000000008d53db asn1_template_ex_d2i tasn_dec.c:0
    @ 00000000008d4c3b ASN1_item_ex_d2i ??:0
    @ 00000000008d4f6a ASN1_item_d2i ??:0
    @ 000000000090f3c8 d2i_X509_AUX ??:0
    @ 0000000000913487 PEM_ASN1_read_bio ??:0
    @ 0000000000688edc Envoy::Ssl::ContextImpl::ContextImpl /proc/self/cwd/source/common/ssl/context_impl.cc:143
    @ 0000000000689e06 Envoy::Ssl::ServerContextImpl::ServerContextImpl /proc/self/cwd/source/common/ssl/context_impl.cc:439
    @ 000000000068c6af Envoy::Ssl::ContextManagerImpl::createSslServerContext /proc/self/cwd/source/common/ssl/context_manager_impl.cc:75
    @ 000000000056e9bc Envoy::Ssl::ServerSslSocketFactory::ServerSslSocketFactory /proc/self/cwd/source/common/ssl/ssl_socket.cc:375
    @ 000000000051f83c Envoy::Server::Configuration::DownstreamSslSocketFactory::createTransportSocketFactory /proc/self/cwd/source/server/config/network/ssl_socket.cc:36
    @ 000000000055a02c Envoy::Server::ListenerImpl::ListenerImpl /proc/self/cwd/source/server/listener_manager_impl.cc:203
    @ 000000000055b575 Envoy::Server::ListenerManagerImpl::addOrUpdateListener /proc/self/cwd/source/server/listener_manager_impl.cc:330
    @ 000000000076b0dd Envoy::Server::LdsApi::onConfigUpdate /proc/self/cwd/source/server/lds_api.cc:59
    @ 000000000076cce0 Envoy::Config::GrpcMuxSubscriptionImpl::onConfigUpdate /proc/self/cwd/bazel-out/k8-opt/bin/source/common/config/_virtual_includes/grpc_mux_subscription_lib/common/config/grpc_mux_subscription_impl.h:53
    @ 00000000007722b3 Envoy::Config::GrpcMuxImpl::onReceiveMessage /proc/self/cwd/source/common/config/grpc_mux_impl.cc:174
    @ 000000000076f622 Envoy::Grpc::TypedAsyncStreamCallbacks::onReceiveMessageUntyped /proc/self/cwd/bazel-out/k8-opt/bin/include/envoy/grpc/_virtual_includes/async_client_interface/envoy/grpc/async_client.h:172
    @ 0000000000788c65 Envoy::Grpc::AsyncStreamImpl::onData /proc/self/cwd/source/common/grpc/async_client_impl.cc:131
    @ 000000000078d93b Envoy::Http::AsyncStreamImpl::encodeData /proc/self/cwd/source/common/http/async_client_impl.cc:108
    @ 00000000006b2a93 Envoy::Http::Http2::ConnectionImpl::onFrameReceived /proc/self/cwd/source/common/http/http2/codec_impl.cc:445
    @ 00000000006b58b6 nghttp2_session_on_data_received /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:4881
    @ 00000000006b94e1 nghttp2_session_mem_recv /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:6443
    @ 00000000006b1aee Envoy::Http::Http2::ConnectionImpl::dispatch /proc/self/cwd/source/common/http/http2/codec_impl.cc:302
    @ 000000000066634e Envoy::Http::CodecClient::onData /proc/self/cwd/source/common/http/codec_client.cc:115
    @ 00000000006664cc Envoy::Http::CodecClient::CodecReadFilter::onData /proc/self/cwd/bazel-out/k8-opt/bin/source/common/http/_virtual_includes/codec_client_lib/common/http/codec_client.h:159
    @ 000000000056dc66 Envoy::Network::FilterManagerImpl::onContinueReading /proc/self/cwd/source/common/network/filter_manager_impl.cc:56
    @ 000000000056c5ce Envoy::Network::ConnectionImpl::onReadReady /proc/self/cwd/source/common/network/connection_impl.cc:443
    @ 000000000056cded Envoy::Network::ConnectionImpl::onFileEvent /proc/self/cwd/source/common/network/connection_impl.cc:419
    @ 0000000000566307 _FUN /proc/self/cwd/source/common/event/file_event_impl.cc:61
Leak of 352350784 bytes in 831016 objects allocated from:
    @ 0068c684 unknown
    @ 000000000056e9bc Envoy::Ssl::ServerSslSocketFactory::ServerSslSocketFactory /proc/self/cwd/source/common/ssl/ssl_socket.cc:375
    @ 000000000051f83c Envoy::Server::Configuration::DownstreamSslSocketFactory::createTransportSocketFactory /proc/self/cwd/source/server/config/network/ssl_socket.cc:36
    @ 000000000055a02c Envoy::Server::ListenerImpl::ListenerImpl /proc/self/cwd/source/server/listener_manager_impl.cc:203
    @ 000000000055b575 Envoy::Server::ListenerManagerImpl::addOrUpdateListener /proc/self/cwd/source/server/listener_manager_impl.cc:330
    @ 000000000076b0dd Envoy::Server::LdsApi::onConfigUpdate /proc/self/cwd/source/server/lds_api.cc:59
    @ 000000000076cce0 Envoy::Config::GrpcMuxSubscriptionImpl::onConfigUpdate /proc/self/cwd/bazel-out/k8-opt/bin/source/common/config/_virtual_includes/grpc_mux_subscription_lib/common/config/grpc_mux_subscription_impl.h:53
    @ 00000000007722b3 Envoy::Config::GrpcMuxImpl::onReceiveMessage /proc/self/cwd/source/common/config/grpc_mux_impl.cc:174
    @ 000000000076f622 Envoy::Grpc::TypedAsyncStreamCallbacks::onReceiveMessageUntyped /proc/self/cwd/bazel-out/k8-opt/bin/include/envoy/grpc/_virtual_includes/async_client_interface/envoy/grpc/async_client.h:172
    @ 0000000000788c65 Envoy::Grpc::AsyncStreamImpl::onData /proc/self/cwd/source/common/grpc/async_client_impl.cc:131
    @ 000000000078d93b Envoy::Http::AsyncStreamImpl::encodeData /proc/self/cwd/source/common/http/async_client_impl.cc:108
    @ 00000000006b2a93 Envoy::Http::Http2::ConnectionImpl::onFrameReceived /proc/self/cwd/source/common/http/http2/codec_impl.cc:445
    @ 00000000006b58b6 nghttp2_session_on_data_received /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:4881
    @ 00000000006b94e1 nghttp2_session_mem_recv /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:6443
    @ 00000000006b1aee Envoy::Http::Http2::ConnectionImpl::dispatch /proc/self/cwd/source/common/http/http2/codec_impl.cc:302
    @ 000000000066634e Envoy::Http::CodecClient::onData /proc/self/cwd/source/common/http/codec_client.cc:115
    @ 00000000006664cc Envoy::Http::CodecClient::CodecReadFilter::onData /proc/self/cwd/bazel-out/k8-opt/bin/source/common/http/_virtual_includes/codec_client_lib/common/http/codec_client.h:159
    @ 000000000056dc66 Envoy::Network::FilterManagerImpl::onContinueReading /proc/self/cwd/source/common/network/filter_manager_impl.cc:56
    @ 000000000056c5ce Envoy::Network::ConnectionImpl::onReadReady /proc/self/cwd/source/common/network/connection_impl.cc:443
    @ 000000000056cded Envoy::Network::ConnectionImpl::onFileEvent /proc/self/cwd/source/common/network/connection_impl.cc:419
    @ 0000000000566307 _FUN /proc/self/cwd/source/common/event/file_event_impl.cc:61
    @ 00000000008a1d11 event_process_active_single_queue.isra.29 /tmp/libevent.dep.build/libevent-2.1.8-stable/event.c:1639
    @ 00000000008a246e event_base_loop /tmp/libevent.dep.build/libevent-2.1.8-stable/event.c:1961
    @ 000000000054dcdd Envoy::Server::InstanceImpl::run /proc/self/cwd/source/server/server.cc:356
    @ 0000000000464850 Envoy::MainCommonBase::run /proc/self/cwd/source/exe/main_common.cc:83
    @ 00000000004156c8 main /proc/self/cwd/source/exe/main.cc:30
    @ 00007f114a497b8d unknown

  8605.2  86.2%  86.2%   8605.2  86.2% OPENSSL_malloc
   821.0   8.2%  94.4%    821.0   8.2% OPENSSL_realloc
   336.0   3.4%  97.8%   9843.3  98.6% Envoy::Ssl::ContextManagerImpl::createSslServerContext
    53.5   0.5%  98.3%     53.5   0.5% __gnu_cxx::new_allocator::allocate (inline)
    46.3   0.5%  98.8%     46.3   0.5% std::__cxx11::basic_string::_M_construct
    19.0   0.2%  99.0%     20.0   0.2% std::_List_node::_List_node (inline)
    13.2   0.1%  99.1%     13.2   0.1% std::__cxx11::basic_string::reserve
    12.8   0.1%  99.2%     12.8   0.1% std::__cxx11::basic_string::_M_mutate
    12.7   0.1%  99.4%   9856.9  98.7% std::make_unique (inline)
     9.5   0.1%  99.5%      9.5   0.1% std::__fill_a (inline)

envoy.hprof.0220.heap.txt

[davecheney]

Thanks for the update.

Just to confirm, the large process is envoy, not contour? Is that correct?

Looking at the stack trace you supplied the underlying issue might be due to contour constantly updating lds which introduces new ssl certificates to the https listener. This might be causing, or exposing an underlying issue in envoy.

On 7 Jul 2018, at 07:12, Matthew Alberts [e-mail] wrote:

Update ~ contour:master

Based on interested, I've update to contour:master and re-run tests. The results are largely the same; though, the slope of the slope of the line plotting memory growth is lower.

@davecheney
@alexbrand

Observation ~ Adding Ingresses

malbook:ingress-system malberts$ ./tools/clone-http-ingress.sh -n 5000 -b 100
REPORT
total=5000
block_size=100
delay enabled=0 duration=0.000000

BLOCK MEMORY DURATION
00000000 38Mi 12.73000000
00000001 38Mi 13.51000000
00000002 38Mi 15.69000000
00000003 727Mi 16.91000000
00000004 727Mi 19.13000000
00000005 727Mi 18.27000000
00000006 1397Mi 19.66000000
00000007 1397Mi 17.98000000
00000008 1397Mi 20.06000000
00000009 2322Mi 20.20000000
00000010 2322Mi 21.42000000
00000011 2322Mi 23.06000000
00000012 3201Mi 26.34000000
00000013 3201Mi 26.48000000
00000014 3962Mi 26.93000000
00000015 3962Mi 31.62000000
00000016 4750Mi 26.29000000
00000017 4750Mi 29.35000000
00000018 5308Mi 31.72000000
00000019 5308Mi 29.80000000
00000020 6104Mi 33.49000000
00000021 6104Mi 33.40000000
00000022 7012Mi 36.17000000
00000023 7745Mi 44.15000000
00000024 8615Mi 48.12000000
00000025 8615Mi 46.05000000
00000026 9419Mi 42.14000000
00000027 10281Mi 41.55000000
00000028 10281Mi 43.36000000
00000029 11109Mi 45.34000000
00000030 11907Mi 47.71000000
00000031 12713Mi 70.68000000
00000032 13480Mi 70.05000000
00000033 15110Mi 76.67000000
00000034 15853Mi 66.57000000
00000035 16718Mi 75.32000000
00000036 17501Mi 77.54000000
00000037 19168Mi 72.29000000
00000038 20075Mi 74.16000000
00000039 20848Mi 82.56000000
00000040 22403Mi 95.71000000
00000041 23176Mi 75.30000000
00000042 23908Mi 76.13000000
00000043 25675Mi 85.38000000
00000044 26451Mi 81.63000000
00000045 27945Mi 83.64000000
00000046 28724Mi 85.74000000
00000047 30249Mi 87.59000000
00000048 31112Mi 90.99000000
00000049 32721Mi 100.62000000

Heap Trace

Again, I've only included a portion of the output to reduce the copy-paste size. At least I was able to get a more legible stack trace (the raw-trace is attached).

(pprof) top
Total: 9982.5 MB
Leak of 697222424 bytes in 831016 objects allocated from:
@ 0090f485 unknown
@ 00000000008df612 BUF_memdup ??:0
@ 000000000091b217 CRYPTO_BUFFER_new ??:0
@ 00000000008ba473 bssl::x509_to_buffer ssl_x509.cc:0
@ 00000000008baa39 ssl_use_certificate ssl_x509.cc:0
@ 0000000000688f0c Envoy::Ssl::ContextImpl::ContextImpl /proc/self/cwd/source/common/ssl/context_impl.cc:144
@ 0000000000689e06 Envoy::Ssl::ServerContextImpl::ServerContextImpl /proc/self/cwd/source/common/ssl/context_impl.cc:439
@ 000000000068c6af Envoy::Ssl::ContextManagerImpl::createSslServerContext /proc/self/cwd/source/common/ssl/context_manager_impl.cc:75
@ 000000000056e9bc Envoy::Ssl::ServerSslSocketFactory::ServerSslSocketFactory /proc/self/cwd/source/common/ssl/ssl_socket.cc:375
@ 000000000051f83c Envoy::Server::Configuration::DownstreamSslSocketFactory::createTransportSocketFactory /proc/self/cwd/source/server/config/network/ssl_socket.cc:36
@ 000000000055a02c Envoy::Server::ListenerImpl::ListenerImpl /proc/self/cwd/source/server/listener_manager_impl.cc:203
@ 000000000055b575 Envoy::Server::ListenerManagerImpl::addOrUpdateListener /proc/self/cwd/source/server/listener_manager_impl.cc:330
@ 000000000076b0dd Envoy::Server::LdsApi::onConfigUpdate /proc/self/cwd/source/server/lds_api.cc:59
@ 000000000076cce0 Envoy::Config::GrpcMuxSubscriptionImpl::onConfigUpdate /proc/self/cwd/bazel-out/k8-opt/bin/source/common/config/_virtual_includes/grpc_mux_subscription_lib/common/config/grpc_mux_subscription_impl.h:53
@ 00000000007722b3 Envoy::Config::GrpcMuxImpl::onReceiveMessage /proc/self/cwd/source/common/config/grpc_mux_impl.cc:174
@ 000000000076f622 Envoy::Grpc::TypedAsyncStreamCallbacks::onReceiveMessageUntyped /proc/self/cwd/bazel-out/k8-opt/bin/include/envoy/grpc/_virtual_includes/async_client_interface/envoy/grpc/async_client.h:172
@ 0000000000788c65 Envoy::Grpc::AsyncStreamImpl::onData /proc/self/cwd/source/common/grpc/async_client_impl.cc:131
@ 000000000078d93b Envoy::Http::AsyncStreamImpl::encodeData /proc/self/cwd/source/common/http/async_client_impl.cc:108
@ 00000000006b2a93 Envoy::Http::Http2::ConnectionImpl::onFrameReceived /proc/self/cwd/source/common/http/http2/codec_impl.cc:445
@ 00000000006b58b6 nghttp2_session_on_data_received /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:4881
@ 00000000006b94e1 nghttp2_session_mem_recv /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:6443
@ 00000000006b1aee Envoy::Http::Http2::ConnectionImpl::dispatch /proc/self/cwd/source/common/http/http2/codec_impl.cc:302
@ 000000000066634e Envoy::Http::CodecClient::onData /proc/self/cwd/source/common/http/codec_client.cc:115
@ 00000000006664cc Envoy::Http::CodecClient::CodecReadFilter::onData /proc/self/cwd/bazel-out/k8-opt/bin/source/common/http/_virtual_includes/codec_client_lib/common/http/codec_client.h:159
@ 000000000056dc66 Envoy::Network::FilterManagerImpl::onContinueReading /proc/self/cwd/source/common/network/filter_manager_impl.cc:56
@ 000000000056c5ce Envoy::Network::ConnectionImpl::onReadReady /proc/self/cwd/source/common/network/connection_impl.cc:443
@ 000000000056cded Envoy::Network::ConnectionImpl::onFileEvent /proc/self/cwd/source/common/network/connection_impl.cc:419
@ 0000000000566307 _FUN /proc/self/cwd/source/common/event/file_event_impl.cc:61
@ 00000000008a1d11 event_process_active_single_queue.isra.29 /tmp/libevent.dep.build/libevent-2.1.8-stable/event.c:1639
@ 00000000008a246e event_base_loop /tmp/libevent.dep.build/libevent-2.1.8-stable/event.c:1961
@ 000000000054dcdd Envoy::Server::InstanceImpl::run /proc/self/cwd/source/server/server.cc:356
@ 0000000000464850 Envoy::MainCommonBase::run /proc/self/cwd/source/exe/main_common.cc:83
Leak of 498609600 bytes in 831016 objects allocated from:
@ 0090f485 unknown
@ 00000000008ae16c SSL_CTX_new ??:0
@ 00000000006888ae Envoy::Ssl::ContextImpl::ContextImpl /proc/self/cwd/source/common/ssl/context_impl.cc:34
@ 0000000000689e06 Envoy::Ssl::ServerContextImpl::ServerContextImpl /proc/self/cwd/source/common/ssl/context_impl.cc:439
@ 000000000068c6af Envoy::Ssl::ContextManagerImpl::createSslServerContext /proc/self/cwd/source/common/ssl/context_manager_impl.cc:75
@ 000000000056e9bc Envoy::Ssl::ServerSslSocketFactory::ServerSslSocketFactory /proc/self/cwd/source/common/ssl/ssl_socket.cc:375
@ 000000000051f83c Envoy::Server::Configuration::DownstreamSslSocketFactory::createTransportSocketFactory /proc/self/cwd/source/server/config/network/ssl_socket.cc:36
@ 000000000055a02c Envoy::Server::ListenerImpl::ListenerImpl /proc/self/cwd/source/server/listener_manager_impl.cc:203
@ 000000000055b575 Envoy::Server::ListenerManagerImpl::addOrUpdateListener /proc/self/cwd/source/server/listener_manager_impl.cc:330
@ 000000000076b0dd Envoy::Server::LdsApi::onConfigUpdate /proc/self/cwd/source/server/lds_api.cc:59
@ 000000000076cce0 Envoy::Config::GrpcMuxSubscriptionImpl::onConfigUpdate /proc/self/cwd/bazel-out/k8-opt/bin/source/common/config/_virtual_includes/grpc_mux_subscription_lib/common/config/grpc_mux_subscription_impl.h:53
@ 00000000007722b3 Envoy::Config::GrpcMuxImpl::onReceiveMessage /proc/self/cwd/source/common/config/grpc_mux_impl.cc:174
@ 000000000076f622 Envoy::Grpc::TypedAsyncStreamCallbacks::onReceiveMessageUntyped /proc/self/cwd/bazel-out/k8-opt/bin/include/envoy/grpc/_virtual_includes/async_client_interface/envoy/grpc/async_client.h:172
@ 0000000000788c65 Envoy::Grpc::AsyncStreamImpl::onData /proc/self/cwd/source/common/grpc/async_client_impl.cc:131
@ 000000000078d93b Envoy::Http::AsyncStreamImpl::encodeData /proc/self/cwd/source/common/http/async_client_impl.cc:108
@ 00000000006b2a93 Envoy::Http::Http2::ConnectionImpl::onFrameReceived /proc/self/cwd/source/common/http/http2/codec_impl.cc:445
@ 00000000006b58b6 nghttp2_session_on_data_received /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:4881
@ 00000000006b94e1 nghttp2_session_mem_recv /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:6443
@ 00000000006b1aee Envoy::Http::Http2::ConnectionImpl::dispatch /proc/self/cwd/source/common/http/http2/codec_impl.cc:302
@ 000000000066634e Envoy::Http::CodecClient::onData /proc/self/cwd/source/common/http/codec_client.cc:115
@ 00000000006664cc Envoy::Http::CodecClient::CodecReadFilter::onData /proc/self/cwd/bazel-out/k8-opt/bin/source/common/http/_virtual_includes/codec_client_lib/common/http/codec_client.h:159
@ 000000000056dc66 Envoy::Network::FilterManagerImpl::onContinueReading /proc/self/cwd/source/common/network/filter_manager_impl.cc:56
@ 000000000056c5ce Envoy::Network::ConnectionImpl::onReadReady /proc/self/cwd/source/common/network/connection_impl.cc:443
@ 000000000056cded Envoy::Network::ConnectionImpl::onFileEvent /proc/self/cwd/source/common/network/connection_impl.cc:419
@ 0000000000566307 _FUN /proc/self/cwd/source/common/event/file_event_impl.cc:61
@ 00000000008a1d11 event_process_active_single_queue.isra.29 /tmp/libevent.dep.build/libevent-2.1.8-stable/event.c:1639
@ 00000000008a246e event_base_loop /tmp/libevent.dep.build/libevent-2.1.8-stable/event.c:1961
@ 000000000054dcdd Envoy::Server::InstanceImpl::run /proc/self/cwd/source/server/server.cc:356
@ 0000000000464850 Envoy::MainCommonBase::run /proc/self/cwd/source/exe/main_common.cc:83
@ 00000000004156c8 main /proc/self/cwd/source/exe/main.cc:30
@ 00007f114a497b8d unknown
Leak of 464537944 bytes in 831016 objects allocated from:
@ 0090f485 unknown
@ 00000000008d7047 asn1_enc_save ??:0
@ 00000000008d4ebd ASN1_item_ex_d2i ??:0
@ 00000000008d519c asn1_template_noexp_d2i tasn_dec.c:0
@ 00000000008d53db asn1_template_ex_d2i tasn_dec.c:0
@ 00000000008d4c3b ASN1_item_ex_d2i ??:0
@ 00000000008d4f6a ASN1_item_d2i ??:0
@ 000000000090f3c8 d2i_X509_AUX ??:0
@ 0000000000913487 PEM_ASN1_read_bio ??:0
@ 0000000000688edc Envoy::Ssl::ContextImpl::ContextImpl /proc/self/cwd/source/common/ssl/context_impl.cc:143
@ 0000000000689e06 Envoy::Ssl::ServerContextImpl::ServerContextImpl /proc/self/cwd/source/common/ssl/context_impl.cc:439
@ 000000000068c6af Envoy::Ssl::ContextManagerImpl::createSslServerContext /proc/self/cwd/source/common/ssl/context_manager_impl.cc:75
@ 000000000056e9bc Envoy::Ssl::ServerSslSocketFactory::ServerSslSocketFactory /proc/self/cwd/source/common/ssl/ssl_socket.cc:375
@ 000000000051f83c Envoy::Server::Configuration::DownstreamSslSocketFactory::createTransportSocketFactory /proc/self/cwd/source/server/config/network/ssl_socket.cc:36
@ 000000000055a02c Envoy::Server::ListenerImpl::ListenerImpl /proc/self/cwd/source/server/listener_manager_impl.cc:203
@ 000000000055b575 Envoy::Server::ListenerManagerImpl::addOrUpdateListener /proc/self/cwd/source/server/listener_manager_impl.cc:330
@ 000000000076b0dd Envoy::Server::LdsApi::onConfigUpdate /proc/self/cwd/source/server/lds_api.cc:59
@ 000000000076cce0 Envoy::Config::GrpcMuxSubscriptionImpl::onConfigUpdate /proc/self/cwd/bazel-out/k8-opt/bin/source/common/config/_virtual_includes/grpc_mux_subscription_lib/common/config/grpc_mux_subscription_impl.h:53
@ 00000000007722b3 Envoy::Config::GrpcMuxImpl::onReceiveMessage /proc/self/cwd/source/common/config/grpc_mux_impl.cc:174
@ 000000000076f622 Envoy::Grpc::TypedAsyncStreamCallbacks::onReceiveMessageUntyped /proc/self/cwd/bazel-out/k8-opt/bin/include/envoy/grpc/_virtual_includes/async_client_interface/envoy/grpc/async_client.h:172
@ 0000000000788c65 Envoy::Grpc::AsyncStreamImpl::onData /proc/self/cwd/source/common/grpc/async_client_impl.cc:131
@ 000000000078d93b Envoy::Http::AsyncStreamImpl::encodeData /proc/self/cwd/source/common/http/async_client_impl.cc:108
@ 00000000006b2a93 Envoy::Http::Http2::ConnectionImpl::onFrameReceived /proc/self/cwd/source/common/http/http2/codec_impl.cc:445
@ 00000000006b58b6 nghttp2_session_on_data_received /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:4881
@ 00000000006b94e1 nghttp2_session_mem_recv /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:6443
@ 00000000006b1aee Envoy::Http::Http2::ConnectionImpl::dispatch /proc/self/cwd/source/common/http/http2/codec_impl.cc:302
@ 000000000066634e Envoy::Http::CodecClient::onData /proc/self/cwd/source/common/http/codec_client.cc:115
@ 00000000006664cc Envoy::Http::CodecClient::CodecReadFilter::onData /proc/self/cwd/bazel-out/k8-opt/bin/source/common/http/_virtual_includes/codec_client_lib/common/http/codec_client.h:159
@ 000000000056dc66 Envoy::Network::FilterManagerImpl::onContinueReading /proc/self/cwd/source/common/network/filter_manager_impl.cc:56
@ 000000000056c5ce Envoy::Network::ConnectionImpl::onReadReady /proc/self/cwd/source/common/network/connection_impl.cc:443
@ 000000000056cded Envoy::Network::ConnectionImpl::onFileEvent /proc/self/cwd/source/common/network/connection_impl.cc:419
@ 0000000000566307 _FUN /proc/self/cwd/source/common/event/file_event_impl.cc:61
Leak of 352350784 bytes in 831016 objects allocated from:
@ 0068c684 unknown
@ 000000000056e9bc Envoy::Ssl::ServerSslSocketFactory::ServerSslSocketFactory /proc/self/cwd/source/common/ssl/ssl_socket.cc:375
@ 000000000051f83c Envoy::Server::Configuration::DownstreamSslSocketFactory::createTransportSocketFactory /proc/self/cwd/source/server/config/network/ssl_socket.cc:36
@ 000000000055a02c Envoy::Server::ListenerImpl::ListenerImpl /proc/self/cwd/source/server/listener_manager_impl.cc:203
@ 000000000055b575 Envoy::Server::ListenerManagerImpl::addOrUpdateListener /proc/self/cwd/source/server/listener_manager_impl.cc:330
@ 000000000076b0dd Envoy::Server::LdsApi::onConfigUpdate /proc/self/cwd/source/server/lds_api.cc:59
@ 000000000076cce0 Envoy::Config::GrpcMuxSubscriptionImpl::onConfigUpdate /proc/self/cwd/bazel-out/k8-opt/bin/source/common/config/_virtual_includes/grpc_mux_subscription_lib/common/config/grpc_mux_subscription_impl.h:53
@ 00000000007722b3 Envoy::Config::GrpcMuxImpl::onReceiveMessage /proc/self/cwd/source/common/config/grpc_mux_impl.cc:174
@ 000000000076f622 Envoy::Grpc::TypedAsyncStreamCallbacks::onReceiveMessageUntyped /proc/self/cwd/bazel-out/k8-opt/bin/include/envoy/grpc/_virtual_includes/async_client_interface/envoy/grpc/async_client.h:172
@ 0000000000788c65 Envoy::Grpc::AsyncStreamImpl::onData /proc/self/cwd/source/common/grpc/async_client_impl.cc:131
@ 000000000078d93b Envoy::Http::AsyncStreamImpl::encodeData /proc/self/cwd/source/common/http/async_client_impl.cc:108
@ 00000000006b2a93 Envoy::Http::Http2::ConnectionImpl::onFrameReceived /proc/self/cwd/source/common/http/http2/codec_impl.cc:445
@ 00000000006b58b6 nghttp2_session_on_data_received /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:4881
@ 00000000006b94e1 nghttp2_session_mem_recv /tmp/nghttp2.dep.build/nghttp2-1.29.0/lib/nghttp2_session.c:6443
@ 00000000006b1aee Envoy::Http::Http2::ConnectionImpl::dispatch /proc/self/cwd/source/common/http/http2/codec_impl.cc:302
@ 000000000066634e Envoy::Http::CodecClient::onData /proc/self/cwd/source/common/http/codec_client.cc:115
@ 00000000006664cc Envoy::Http::CodecClient::CodecReadFilter::onData /proc/self/cwd/bazel-out/k8-opt/bin/source/common/http/_virtual_includes/codec_client_lib/common/http/codec_client.h:159
@ 000000000056dc66 Envoy::Network::FilterManagerImpl::onContinueReading /proc/self/cwd/source/common/network/filter_manager_impl.cc:56
@ 000000000056c5ce Envoy::Network::ConnectionImpl::onReadReady /proc/self/cwd/source/common/network/connection_impl.cc:443
@ 000000000056cded Envoy::Network::ConnectionImpl::onFileEvent /proc/self/cwd/source/common/network/connection_impl.cc:419
@ 0000000000566307 _FUN /proc/self/cwd/source/common/event/file_event_impl.cc:61
@ 00000000008a1d11 event_process_active_single_queue.isra.29 /tmp/libevent.dep.build/libevent-2.1.8-stable/event.c:1639
@ 00000000008a246e event_base_loop /tmp/libevent.dep.build/libevent-2.1.8-stable/event.c:1961
@ 000000000054dcdd Envoy::Server::InstanceImpl::run /proc/self/cwd/source/server/server.cc:356
@ 0000000000464850 Envoy::MainCommonBase::run /proc/self/cwd/source/exe/main_common.cc:83
@ 00000000004156c8 main /proc/self/cwd/source/exe/main.cc:30
@ 00007f114a497b8d unknown

8605.2 86.2% 86.2% 8605.2 86.2% OPENSSL_malloc
821.0 8.2% 94.4% 821.0 8.2% OPENSSL_realloc
336.0 3.4% 97.8% 9843.3 98.6% Envoy::Ssl::ContextManagerImpl::createSslServerContext
53.5 0.5% 98.3% 53.5 0.5% __gnu_cxx::new_allocator::allocate (inline)
46.3 0.5% 98.8% 46.3 0.5% std::__cxx11::basic_string::_M_construct
19.0 0.2% 99.0% 20.0 0.2% std::_List_node::_List_node (inline)
13.2 0.1% 99.1% 13.2 0.1% std::__cxx11::basic_string::reserve
12.8 0.1% 99.2% 12.8 0.1% std::__cxx11::basic_string::_M_mutate
12.7 0.1% 99.4% 9856.9 98.7% std::make_unique (inline)
9.5 0.1% 99.5% 9.5 0.1% std::__fill_a (inline)
envoy.hprof.0220.heap.txt

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.

[mattalberts]

@davecheney
That is an interesting theory! The stack trace does suggest a leak related to certificate creation. I've been attempting to audit the code/classes responsible for the memory alloc/free related to certificates and keys.

Correct. The memory hungry container is envoy. Contour remains within reasonable range across ingress insertion. Here, I've grabbed a screenshot of each container (in isolation) at the same time window. I've annotated the images to separate the different stages

• start - fresh start, no ingresses
• insert - beging insertion (5000 total in blocks of 100)
• stable - insert has finished, containers are idle
• restart - delete the pod and let it recreate to see the difference in memory vs stable

Contour Memory

Envoy Memory

[rosskukulinski]

@mattalberts can you share clone-http-ingress.sh? We've been doing similar perf testing looking at the impact of memory for Envoy and Contour, but with IngressRoute objects, not Ingress (and without TLS)

Do all your Ingress objects share the same TLS key?

FWIW, I also hacked something similar together: https://github.com/rosskukulinski/contour-envoy-memory-batch.

Leaving this in the 0.6.0 milestone for now, but we may also want to see how things change with Envoy 1.7.

[mattalberts]

@rosskukulinski

I sure can! Its a little rough, especially right here.

MEM=$(kubectl -n ingress-system top pods -l'app=contour-ingress,component=debug' | awk 'NR==2{print $3}')

clone-http-ingress.txt

• replace the .txt suffix with .sh

[mattalberts]

@rosskukulinski I have this script too (a derivation of the first script) that i used for log rate testing
(see #556). It adds generates a service, deployment and ingress (might be more helpful)

clone-echo.txt

• replace the .txt suffix with .sh

[davecheney]

Bumping to 0.8.

This issue is important, but can't be p0 this late in the cycle.

[davecheney]

I'm sorry to do this but I'm going to remove the milestone from this issue. The alternative is to keep bumping it every month, which is dishonest for anyone watching it expecting that it will be resolved.

[phylake]

I think the SSL stuff is a red herring based on how it manages memory. That's further backed by the fact we're seeing the same thing on IngressRoutes that don't use tls.

We're seeing this after IngressRoutes are added or modified. Basically if contour isn't touching envoy then it's fine.

Below is the container_memory_rss{container_name="envoy",pod_name=~"contour.*"} prometheus metric. We're not doing a split-pod deployment yet. We see this on contour v0.9 and v0.10. This cluster of 10 instances is running 200 IngressRoute objects which helped highlight the problem in the graphs.

Envoy's leaking ~10MB/minute

[fillmore]

I noticed similar behavior

[davecheney]

Thank you for this information.

I’m sorry nobody has been able to dig into this issue so far.

As a wild guess, the stairstep growth in envoy memory usage would indicate to me that something is preventing envoy from freeing older configurations. In my experience this may be a long running connection, web socket, etc.

I’m sorry, I have not debugged the issue further.

On 29 Mar 2019, at 10:13, Lingfeng Wu [e-mail] wrote:

I noticed similar behavior

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.

[fillmore]

@davecheney, thanks for quick response.

I spent some time studying contour code today. It looks like every time contour finds a change with any resource, the full list of resources will be sent to envoy for update. But in envoy's xds document, it suggests only sending the resources changed.

The management server should only send updates to the Envoy client when the resources in the DiscoveryResponse have changed. Envoy replies to any DiscoveryResponse with a DiscoveryRequest containing the ACK/NACK immediately after it has been either accepted or rejected. If the management server provides the same set of resources rather than waiting for a change to occur, it will cause Envoy and the management server to spin and have a severe performance impact.

Could this be the cause?

[davecheney]

Possibly. But we already restrict our response to the resources requested from envoy.

On 29 Mar 2019, at 12:18, Lingfeng Wu [e-mail] wrote:

@davecheney, thanks for quick response.

I spent some time studying contour code today. It looks like every time contour finds a change with any resource, the full list of resources will be sent to envoy for update. But in envoy's xds document, it suggests only sending the resources changed.

The management server should only send updates to the Envoy client when the resources in the DiscoveryResponse have changed. Envoy replies to any DiscoveryResponse with a DiscoveryRequest containing the ACK/NACK immediately after it has been either accepted or rejected. If the management server provides the same set of resources rather than waiting for a change to occur, it will cause Envoy and the management server to spin and have a severe performance impact.

Could this be the cause?

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.

[davecheney]

Good point. [] means envoy did not set a filter so it will receive everything.

On 29 Mar 2019, at 14:38, Lingfeng Wu [e-mail] wrote:

That may not be the case. In stream of xds.go, since their 2 loops there, only the first request is received and kept, the requested resource is always []. I just check logs from one of my contour instance. Below are some of the lines related to connection 1, you can see it clearly that resource_names="[]" and all the resources were sent to envoy in this case.
time="2019-03-29T00:14:30Z" level=info msg=stream_wait connection=1 context=grpc error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= time="2019-03-29T00:14:30Z" level=info msg=response connection=1 context=grpc count=41 error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= time="2019-03-29T00:14:30Z" level=info msg=stream_wait connection=1 context=grpc error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= time="2019-03-29T00:16:20Z" level=info msg=response connection=1 context=grpc count=41 error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= time="2019-03-29T00:16:20Z" level=info msg=stream_wait connection=1 context=grpc error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= time="2019-03-29T00:16:20Z" level=info msg=response connection=1 context=grpc count=42 error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= time="2019-03-29T00:16:20Z" level=info msg=stream_wait connection=1 context=grpc error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= time="2019-03-29T00:16:33Z" level=info msg=response connection=1 context=grpc count=41 error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= time="2019-03-29T00:16:33Z" level=info msg=stream_wait connection=1 context=grpc error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= ... time="2019-03-29T05:19:55Z" level=info msg=stream_wait connection=1 context=grpc error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= time="2019-03-29T05:25:44Z" level=info msg=response connection=1 context=grpc count=31 error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= time="2019-03-29T05:25:44Z" level=info msg=stream_wait connection=1 context=grpc error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= time="2019-03-29T05:25:44Z" level=info msg=response connection=1 context=grpc count=32 error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info= time="2019-03-29T05:25:44Z" level=info msg=stream_wait connection=1 context=grpc error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info=

https://github.com/heptio/contour/blob/532c4e111d95cfb5d2bd28e04ffcc698827d9000/internal/grpc/xds.go#L80-L134

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.

[phylake]

Any progress on this? It's blocking us.

Good point. [] means envoy did not set a filter so it will receive everything.

Is that the smoking gun? If so can you point me to the source so I can look into fixing it?

[phylake]

According to the xDS protocol the DiscoveryRequest's version and nonce are supposed to be returned in the DiscoveryResponse

PR link below

[mattalberts]

All tests have the xDS update to populate version_info from last.
(PR #1016)

Test 1: Insert 5000 Ingress without TLS in blocks of 100

conditions:

• all ing are generate prior to test start
• all ing point to the same service (echo)
• blocks are inserted using kubectl apply -f block_dir
• insertions are serial without sleep between blocks
• ing are deleted using kubectl delete ing -lrole=debug

goals:

• monitor memory and readiness during resource insertion
• monitor memory and readiness on restart after all resources exist
• monitor memory and readiness during resource deletion

results:

• both pods become ready quickly (~<10s) on restart with resources
• see diagram for memory
• envoy rss and working_set_bytes remains high (expected until overload manager in 1.10.0)

Inspecting either rss or working_set_bytes isn't accurate based on what
envoy appears to be doing with allocation (it appears to pool it). Once an
allocation occurs, the memory is not released to the system. Envoy 1.10.0
added the ability to release memory back to the system as part of the
overload manager. These two metrics are more useful:

• envoy_server_memory_allocated
• envoy_server_memory_heap_size

However, looking for areas where rss and working_set_bytes run away is
an indicator of a problem.

Test 2: Insert 5000 Ingress with TLS in blocks of 100

conditions:

• all ing are generate prior to test start
• all ing point to the same service (echo)
• all ing point to the same secret (echo)
• blocks are inserted using kubectl apply -f block_dir
• insertions are serial without sleep between blocks
• ing are deleted using kubectl delete ing -lrole=debug

goals:

• monitor memory and readiness during resource insertion
• monitor memory and readiness on restart after all resources exist
• monitor memory and readiness during resource deletion

results:

• see diagram for memory
• envoy rss and working_set_bytes appear to continue to grow
• envoy pod never becomes ready after restart
• runway memory allocation for 5000 ingresses, killed pod at ~77Gi
• reducing to 4000, memory allocation climbs to ~60Gi and marks pods ready after ~30m

restart at 5000 ing:

restart at 4000 ing:

Though, I think adding version_info to the response of both stream and fetch makes sense, I'm unsure that the just adding version_info is enough. I'm going to continue to investigate behavior under rapid change, monitoring memory metrics published by envoy.

[davecheney]

Thank you for these detailed statistics.

As I understand it when Envoy is restarted it will receive one, or at least
not a continual series of updates from contour, with the complete
configuration--all 4,000 ingresses. Can you please confirm that with the
contour output for that period.

On Sun, 14 Apr 2019 at 10:42, Matthew Alberts [e-mail]
wrote:

All tests have the xDS update to populate version_info from last.
(PR #1016 https://github.com/heptio/contour/pull/1016)
Test 1: Insert 5000 Ingress without TLS in blocks of 100

conditions:

• all ing are generate prior to test start
• all ing point to the same service (echo)
• blocks are inserted using kubectl apply -f block_dir
• insertions are serial without sleep between blocks
• ing are deleted using kubectl delete ing -lrole=debug

goals:

• monitor memory and readiness during resource insertion
• monitor memory and readiness on restart after all resources exist
• monitor memory and readiness during resource deletion

results:

• both pods become ready quickly (~<10s) on restart with resources
• see diagram for memory
• envoy rss and working_set_bytes remains high (expected until
  overload manager in 1.10.0)

[image: contour-with-version_info-5000-ing-without-tls]
https://user-images.githubusercontent.com/6054865/56086781-9cdb6100-5e23-11e9-90dd-19036054d86b.png

Inspecting either rss or working_set_bytes isn't accurate based on what
envoy appears to be doing with allocation (it appears to pool it). Once an
allocation occurs, the memory is not released to the system. Envoy 1.10.0
added the ability to release memory back to the system as part of the
overload manager. These two metrics are more useful:

• envoy_server_memory_allocated
• envoy_server_memory_heap_size

However, looking for areas where rss and working_set_bytes run away is
an indicator of a problem.
Test 2: Insert 5000 Ingress with TLS in blocks of 100

conditions:

• all ing are generate prior to test start
• all ing point to the same service (echo)
• all ing point to the same secret (echo)
• blocks are inserted using kubectl apply -f block_dir
• insertions are serial without sleep between blocks
• ing are deleted using kubectl delete ing -lrole=debug

goals:

• monitor memory and readiness during resource insertion
• monitor memory and readiness on restart after all resources exist
• monitor memory and readiness during resource deletion

results:

• see diagram for memory
• envoy rss and working_set_bytes appear to continue to grow
• envoy pod never becomes ready after restart
• runway memory allocation for 5000 ingresses, killed pod at ~77Gi
• reducing to 4000, memory allocation climbs to ~60Gi and marks pods
  ready after ~30m

restart at 5000 ing:
[image: contour-with-version_info-5000-ing-with-tls]
https://user-images.githubusercontent.com/6054865/56086783-a4026f00-5e23-11e9-9a1b-4217036b978b.png

restart at 4000 ing:
[image: contour-with-version_info-4000-ing-with-tls]
https://user-images.githubusercontent.com/6054865/56086788-bed4e380-5e23-11e9-88a4-85860e99afd8.png

Though, I think adding version_info to the response of both stream and
fetch makes sense, I'm unsure that the just adding version_info is enough.
I'm going to continue to investigate behavior under rapid change,
monitoring memory metrics published by envoy.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/heptio/contour/issues/499#issuecomment-482907743, or mute
the thread
https://github.com/notifications/unsubscribe-auth/AAAcA9BHZaK0_9vFp2H-e9Tp4D9NrbHWks5vgnmGgaJpZM4U_z8t
.

[davecheney]

Matthew, is it possible for you to send me the yaml representing the relevant parts of the apiserver at the point envoy is restarted?

On 14 Apr 2019, at 10:55, Dave Cheney [e-mail] wrote:

Thank you for these detailed statistics.

As I understand it when Envoy is restarted it will receive one, or at least not a continual series of updates from contour, with the complete configuration--all 4,000 ingresses. Can you please confirm that with the contour output for that period.

On Sun, 14 Apr 2019 at 10:42, Matthew Alberts [e-mail] wrote:
All tests have the xDS update to populate version_info from last.
(PR #1016)

Test 1: Insert 5000 Ingress without TLS in blocks of 100

conditions:

all ing are generate prior to test start
all ing point to the same service (echo)
blocks are inserted using kubectl apply -f block_dir
insertions are serial without sleep between blocks
ing are deleted using kubectl delete ing -lrole=debug
goals:

monitor memory and readiness during resource insertion
monitor memory and readiness on restart after all resources exist
monitor memory and readiness during resource deletion
results:

both pods become ready quickly (~<10s) on restart with resources
see diagram for memory
envoy rss and working_set_bytes remains high (expected until overload manager in 1.10.0)

Inspecting either rss or working_set_bytes isn't accurate based on what
envoy appears to be doing with allocation (it appears to pool it). Once an
allocation occurs, the memory is not released to the system. Envoy 1.10.0
added the ability to release memory back to the system as part of the
overload manager. These two metrics are more useful:

envoy_server_memory_allocated
envoy_server_memory_heap_size
However, looking for areas where rss and working_set_bytes run away is
an indicator of a problem.

Test 2: Insert 5000 Ingress with TLS in blocks of 100

conditions:

all ing are generate prior to test start
all ing point to the same service (echo)
all ing point to the same secret (echo)
blocks are inserted using kubectl apply -f block_dir
insertions are serial without sleep between blocks
ing are deleted using kubectl delete ing -lrole=debug
goals:

monitor memory and readiness during resource insertion
monitor memory and readiness on restart after all resources exist
monitor memory and readiness during resource deletion
results:

see diagram for memory
envoy rss and working_set_bytes appear to continue to grow
envoy pod never becomes ready after restart
runway memory allocation for 5000 ingresses, killed pod at ~77Gi
reducing to 4000, memory allocation climbs to ~60Gi and marks pods ready after ~30m
restart at 5000 ing:

restart at 4000 ing:

Though, I think adding version_info to the response of both stream and fetch makes sense, I'm unsure that the just adding version_info is enough. I'm going to continue to investigate behavior under rapid change, monitoring memory metrics published by envoy.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.

[davecheney]

Hello,

What I'm seeing in my experimentation is envoy is keeping many versions of the ingress_https listener around. These may drain over time, but this may explain the explosive memory use under the condition where the ingress_https configuration is changing rapidly.

I cannot explain why the restart 4000 example where the listener configuration is being changed only once or twice is consuming so much memory.

Thanks

Dave

[davecheney]

The magic value to watch is

% watch ' curl -s http://127.0.0.1:9001/stats | grep total_listeners_draining'

[davecheney]

The next magic value is 600 seconds, that is the time a listener spend in draining state before being removed from envoy. During high update rates this is why hundreds or thousands of listener configurations remain active.

[davecheney]

After a bit of searching I've found where 600s is coming from, its the server hot restart interval.

https://www.envoyproxy.io/docs/envoy/latest/intro/arch_overview/draining.html?highlight=hot%20restart

Hot restart occurs when the set of listeners changes, the amount of time an old listener is kept alive is controlled by the --drain-time-s cli flag. --drain-time-s has a default value of 600s.

As an experiment I set --drain-time-s 5 on my Contour and the number of listeners in draining was observed to be consistent with a 5 second timeout.

The _downside_ of this is any active connection running longer than 5 seconds was killed, so this is an interesting parameter to play with, but not a solution to the problem.

Unfortunately, at the moment the way TLS is implemented in Envoy requires us to modify the ingress_https listener to change the configuration of the envoy.tls.listener filter which gives us SNI. So, if the set of ingresses which are TLS enabled changes, we have to send a new ingress_https listener configuration.

I don't have any more information than that at the moment. I haven't looked at the ridiculous 60gb memory usage with the 4000 ingress + tls case that @mattalberts reported.

I wonder how Istio are working around this?

[mattalberts]

Good find! I'm trying to gather the information you requested. In the process, I did notice two interesting aspects of the holdoff notifier that can trigger more updates that expected. I'll open a PR for each and continue to gather what i can :).

[mattalberts]

While gathering up information related to the startup behavior in the present of a large number of ingress definitions. I noticed something that I though would be relevant to share out-of-band.

Test 3: Insert 1000 IngressRoutes without TLS and 1000 Services

conditions:

• ingressroutes point to a unique service
• insertions are serial without sleep between blocks

In this test, I generate a unique service for every IngressRoute, to more closely mimic how things are deployed in my cluster (and certainly other people's). I didn't grab the memory graphs for this test, but I did capture a segment of the contour info logs.

time="2019-04-15T17:28:00Z" level=info msg=stream_wait connection=951 context=grpc error_detail=nil resource_names="[default/echo-953/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=response connection=992 context=grpc count=1 error_detail=nil resource_names="[default/echo-99/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=stream_wait connection=992 context=grpc error_detail=nil resource_names="[default/echo-99/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=response connection=886 context=grpc count=1 error_detail=nil resource_names="[default/echo-899/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=stream_wait connection=886 context=grpc error_detail=nil resource_names="[default/echo-899/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=response connection=867 context=grpc count=1 error_detail=nil resource_names="[default/echo-878/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=stream_wait connection=867 context=grpc error_detail=nil resource_names="[default/echo-878/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=response connection=923 context=grpc count=1 error_detail=nil resource_names="[default/echo-928/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=stream_wait connection=923 context=grpc error_detail=nil resource_names="[default/echo-928/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=response connection=908 context=grpc count=1 error_detail=nil resource_names="[default/echo-914/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=stream_wait connection=908 context=grpc error_detail=nil resource_names="[default/echo-914/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=response connection=647 context=grpc count=1 error_detail=nil resource_names="[default/echo-68/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=stream_wait connection=647 context=grpc error_detail=nil resource_names="[default/echo-68/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T17:28:00Z" level=info msg=response connection=584 context=grpc count=1 error_detail=nil resource_names="[default/echo-623/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=

What you might notice, each service becomes its own gRPC stream. As a result of the 1000 service definitions, I now have ~1000 gRPC streams (which I'm going to guess also equate to a go routine per stream?).

• Is this the expected/desired behavior?
• Would an aDS variant of the xDS implementation be preferred?
  
  
  
  • Envoy XDS Protocol: ADS
  
  

[davecheney]

Yes, envoy opens one grpc stream per cluster to receive the endpoints for that cluster. This will be one goroutine per stream.

Would ads do better? Unknown.

[mattalberts]

Using contour built from master at revision e905f23 (which includes the xds change 78d0f79, here is the log output from both containers. I'm at ~20Gi currently (last time i tried this I terminated the operation at ~80Gi).

Restart 5000 Ingress with TLS

$ kubectl logs $POD -c contour -f
time="2019-04-15T22:39:47Z" level=info msg="args: [serve --incluster --envoy-service-http-port=80 --envoy-service-https-port=443 --ingress-class-name=contour-xxx]"
time="2019-04-15T22:39:47Z" level=info msg="waiting for cache sync" context=contourinformers
time="2019-04-15T22:39:47Z" level=info msg=started context=contourinformers
time="2019-04-15T22:39:47Z" level=info msg=started address="127.0.0.1:6060" context=debugsvc
time="2019-04-15T22:39:47Z" level=info msg="waiting for cache sync" context=coreinformers
time="2019-04-15T22:39:47Z" level=info msg=started context=grpc
time="2019-04-15T22:39:47Z" level=info msg=started address="0.0.0.0:8000" context=metricsvc
time="2019-04-15T22:39:47Z" level=info msg=started context=coreinformers
time="2019-04-15T22:39:48Z" level=info msg="forcing update" context=HoldoffNotifier last update=2562047h47m16.854775807s
time="2019-04-15T22:39:48Z" level=info msg="performing delayed update" context=HoldoffNotifier last update=131.894946ms
time="2019-04-15T22:39:48Z" level=info msg="performing delayed update" context=HoldoffNotifier last update=231.862123ms
time="2019-04-15T22:39:49Z" level=info msg=stream_wait connection=1 context=grpc error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info=
time="2019-04-15T22:39:49Z" level=info msg=response connection=1 context=grpc count=1 error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info=
time="2019-04-15T22:39:49Z" level=info msg=stream_wait connection=1 context=grpc error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Cluster version_info=
time="2019-04-15T22:39:49Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:39:49Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:39:49Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:39:49Z" level=info msg=stream_wait connection=3 context=grpc error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Listener version_info=
time="2019-04-15T22:39:49Z" level=info msg=response connection=3 context=grpc count=2 error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Listener version_info=
time="2019-04-15T22:39:49Z" level=info msg=stream_wait connection=3 context=grpc error_detail=nil resource_names="[]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.Listener version_info=
time="2019-04-15T22:39:49Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:39:49Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:39:57Z" level=info msg=stream_wait connection=4 context=grpc error_detail=nil resource_names="[ingress_http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.RouteConfiguration version_info=
time="2019-04-15T22:39:57Z" level=info msg=stream_wait connection=5 context=grpc error_detail=nil resource_names="[ingress_https]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.RouteConfiguration version_info=
time="2019-04-15T22:39:57Z" level=info msg=response connection=4 context=grpc count=1 error_detail=nil resource_names="[ingress_http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.RouteConfiguration version_info=
time="2019-04-15T22:39:57Z" level=info msg=stream_wait connection=4 context=grpc error_detail=nil resource_names="[ingress_http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.RouteConfiguration version_info=
time="2019-04-15T22:39:57Z" level=info msg=response connection=5 context=grpc count=1 error_detail=nil resource_names="[ingress_https]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.RouteConfiguration version_info=
time="2019-04-15T22:39:57Z" level=info msg=stream_wait connection=5 context=grpc error_detail=nil resource_names="[ingress_https]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.RouteConfiguration version_info=
time="2019-04-15T22:40:24Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:40:24Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:40:40Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:40:40Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:41:00Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:41:00Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:41:01Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:41:01Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:41:58Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:41:58Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:42:04Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:42:04Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:42:21Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:42:21Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:42:25Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:42:25Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:44:14Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:44:14Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:44:16Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:44:16Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:45:52Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:45:52Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:45:53Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:45:53Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:46:10Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:46:10Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:46:11Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:46:11Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:47:14Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:47:14Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:47:22Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:47:22Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:47:41Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:47:41Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:47:46Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:47:46Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:49:31Z" level=info msg=response connection=2 context=grpc count=1 error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=
time="2019-04-15T22:49:31Z" level=info msg=stream_wait connection=2 context=grpc error_detail=nil resource_names="[default/echo/http]" response_nonce= type_url=type.googleapis.com/envoy.api.v2.ClusterLoadAssignment version_info=

• the logs are fairly quiet, there are 3 OnChange events from HoldoffNotifier
• a response for resource_names="[default/echo/http]" is repeated (the frequency is ~2minutes)

$ kubectl logs $POD -c envoy -f
[2019-04-15 22:39:49.332][000001][info][main] [source/server/server.cc:206] initializing epoch 0 (hot restart version=10.200.16384.127.options=capacity=16384, num_slots=8209 hash=228984379728933363 size=2654312)
[2019-04-15 22:39:49.332][000001][info][main] [source/server/server.cc:208] statically linked extensions:
[2019-04-15 22:39:49.332][000001][info][main] [source/server/server.cc:210]   access_loggers: envoy.file_access_log,envoy.http_grpc_access_log
[2019-04-15 22:39:49.332][000001][info][main] [source/server/server.cc:213]   filters.http: envoy.buffer,envoy.cors,envoy.ext_authz,envoy.fault,envoy.filters.http.header_to_metadata,envoy.filters.http.jwt_authn,envoy.filters.http.rbac,envoy.grpc_http1_bridge,envoy.grpc_json_transcoder,envoy.grpc_web,envoy.gzip,envoy.health_check,envoy.http_dynamo_filter,envoy.ip_tagging,envoy.lua,envoy.rate_limit,envoy.router,envoy.squash
[2019-04-15 22:39:49.332][000001][info][main] [source/server/server.cc:216]   filters.listener: envoy.listener.original_dst,envoy.listener.proxy_protocol,envoy.listener.tls_inspector
[2019-04-15 22:39:49.332][000001][info][main] [source/server/server.cc:219]   filters.network: envoy.client_ssl_auth,envoy.echo,envoy.ext_authz,envoy.filters.network.dubbo_proxy,envoy.filters.network.rbac,envoy.filters.network.sni_cluster,envoy.filters.network.thrift_proxy,envoy.http_connection_manager,envoy.mongo_proxy,envoy.ratelimit,envoy.redis_proxy,envoy.tcp_proxy
[2019-04-15 22:39:49.332][000001][info][main] [source/server/server.cc:221]   stat_sinks: envoy.dog_statsd,envoy.metrics_service,envoy.stat_sinks.hystrix,envoy.statsd
[2019-04-15 22:39:49.332][000001][info][main] [source/server/server.cc:223]   tracers: envoy.dynamic.ot,envoy.lightstep,envoy.tracers.datadog,envoy.zipkin
[2019-04-15 22:39:49.332][000001][info][main] [source/server/server.cc:226]   transport_sockets.downstream: envoy.transport_sockets.alts,envoy.transport_sockets.capture,raw_buffer,tls
[2019-04-15 22:39:49.332][000001][info][main] [source/server/server.cc:229]   transport_sockets.upstream: envoy.transport_sockets.alts,envoy.transport_sockets.capture,raw_buffer,tls
[2019-04-15 22:39:49.335][000001][info][main] [source/server/server.cc:271] admin address: 127.0.0.1:9001
[2019-04-15 22:39:49.336][000001][info][config] [source/server/configuration_impl.cc:50] loading 0 static secret(s)
[2019-04-15 22:39:49.336][000001][info][config] [source/server/configuration_impl.cc:56] loading 2 cluster(s)
[2019-04-15 22:39:49.337][000001][info][upstream] [source/common/upstream/cluster_manager_impl.cc:132] cm init: initializing cds
[2019-04-15 22:39:49.338][000001][info][config] [source/server/configuration_impl.cc:67] loading 1 listener(s)
[2019-04-15 22:39:49.339][000001][info][config] [source/server/configuration_impl.cc:92] loading tracing configuration
[2019-04-15 22:39:49.339][000001][info][config] [source/server/configuration_impl.cc:112] loading stats sink configuration
[2019-04-15 22:39:49.339][000001][info][main] [source/server/server.cc:463] starting main dispatch loop
[2019-04-15 22:39:49.341][000001][info][upstream] [source/common/upstream/cluster_manager_impl.cc:495] add/update cluster default/echo/80/da39a3ee5e during init
[2019-04-15 22:39:49.341][000001][info][upstream] [source/common/upstream/cluster_manager_impl.cc:112] cm init: initializing secondary clusters
[2019-04-15 22:39:49.341][000001][info][upstream] [source/common/upstream/cluster_manager_impl.cc:136] cm init: all clusters initialized
[2019-04-15 22:39:49.341][000001][info][main] [source/server/server.cc:435] all clusters initialized. initializing init manager
[2019-04-15 22:39:49.626][000001][info][upstream] [source/server/lds_api.cc:80] lds: add/update listener 'ingress_http'
[2019-04-15 22:39:57.260][000001][info][upstream] [source/server/lds_api.cc:80] lds: add/update listener 'ingress_https'

[davecheney]

@mattalberts

I'm at ~20Gi currently (last time i tried this I terminated the operation at ~80Gi).

How can I reproduce this on my cluster?

[mattalberts]

@davecheney
The easiest way is to use this echo.txt one of these two scripts to generate ingress or ingressroutes

• echo.txt ~ .txt -> .yaml
• clone-echo-ingress.txt ~ .txt -> .sh
• clone-echo-ingressroute.txt ~ .txt -> .sh

Ex:

• ing with tls: ./tools/clone-echo-ingress.sh -b 1000 -n 5000 -t
• ing with svc: ./tools/clone-echo-ingress.sh -b 1000 -n 5000 -s
• ingressroute: ./tools/clone-echo-ingressroute.sh -n 1000 -b 100
• ingressroute with svc: ./tools/clone-echo-ingressroute.sh -n 1000 -b 100

[davecheney]

@mattalberts thank you for your script, its very well written. I've tried to run it but I cannot reproduce your results.

To remove as many variables as possible can you please take a dump of the namespace you described here, https://github.com/heptio/contour/issues/499#issuecomment-483393145

I need the yaml for ingress, service, secret objects (you can include others if needed). I don't think the speed at which objects are applied to the cluster is an important factor so the rate kubectl apply -f works will be fine.

Bottom line I'm trying to reproduce something like _integration/service500.yaml

[davecheney]

https://github.com/envoyproxy/envoy/issues/4540 is relevant here. This will remove a major reason for changing LDS entries.

[davecheney]

I want to give an update for the observers. With the exception of the ridongculous memory usage (the 60Gb+ that @mattalberts has reported) here is what we've figured out so far.

1. Whenever an LDS update is sent, envoy will replace the current listener with the new version. The old version goes into a "draining" phase for 600 seconds (--drain-time-s). Do this frequently enough and you will have 10's, possibly 100's, of old listener configurations pending cleanup.
   1a. Whenever a listener is replaced, connections owned by the previous versions are terminated at the end of its draining phase. This is bad.
   1b. Therefore we don't just want to limit the number of LDS updates we send to Envoy, for long running connections, we have to basically stop sending LDS updates. This is not possible today.
2. Currently whenever there is a change to the objects that Contour watches; ingress, ingressroute, secret, service (not endpoints, they are handled separately) contour will, after a delay of between 100ms and 500ms, rebuild the DAG. Rebuilding the DAG regenerates all the xDS tables, and will send a fresh copy of the xDS tables to any Envoy watching.
   2a. This means if I change a property of an ingress route, RDS, CDS, and LDS will be pinged. See point 1 and 1a.
   2b. Envoy appears to ignore duplicate updates -- I assume based on the hash of the contents of the update. So, most of the updates that are spuriously sent from Contour are discarded on the Envoy side.
   2c. We're currently not handling the xDS NACK protocol so Envoy might be telling us that we sent a duplicate which it ignored, but we're ignoring that message. Turns out two wrongs don't make a right.
3. Because the Envoy side deduplication is based on hashing the gRPC update _order matters_. There are a bunch of fields in the xDS message which are sets, not lists, so order with respect to the correctness of the message is not important, but when you're deduplicating based on the bit patterns in memory, it sure as heck counts.
   3a. Sorting the ingress_https's FilterChains by the hostname helps.
   3b. However when we're building the listener configuration Contour uses grpc Structs, not typed configuration, an grpc Structs are backed by Go maps which are unordered, so the order in which the fields are serialised to the wire is not stable. This is #876 which is currently blocked by #999.
4. Doing 3a and 3b should reduce the number of suprious listener updates, however the normal action of a cluster adding/changing/removing ingresses, rotating secrets (hello lets-encrypt), modifying services, and so on introduces an amount of unavoidable churn that will affect listeners. It looks like Istio are in the same position and have some structural changes proposed for Envoy which we can take advantage of, but for the moment, listener updates are expensive.
5. I don't believe Envoy is leaking memory, it just hangs on to old listener definitions longer than we expected and this leads to its larger working set.
   5a. I cannot explain why @mattalberts can make his Envoy fleet blow up to 60Gb on an idle cluster. In some ways I hope this is an independent problem.

In summary:

• Contour should not send updates for tables that have not changed.
• If Contour is going to send those updates, they should be bit for bit identical so Envoy can deduplicate them if needed.
• We need to reduce the number of LDS updates we send, ideally to zero, but that is complicated because we need features that are not available in Envoy yet, FDS for example.

[mattalberts]

@davecheney I've emailed manifests to replicate both test cases (5000 ingresses with tls and 1000 ingressroutes with 1000 services). I can attempt to grab more logs output for the later case as well, if it will help.

[davecheney]

Unassigning myself, I am unavailable for the next two weeks.

[davecheney]

Hello,

I am downgrading this issues to p2 as there is no more work that can be done on this before the end of the 0.12 cycle. The cause of some of the memory usage has been identified, see https://github.com/heptio/contour/issues/499#issuecomment-483516063. The resolution is we must reduce the number of LDS updates sent to Envoy. There are two components to this

a. spurious updates

• [ ] Contour should not regenerate the LDS tables when they have not changed in memory.
• [ ] Contour should sort the list of vhosts in the ingress_https listener to permit identical responses to be bit for bit identical on the wire
• [ ] Contour should use types.Any rather than types.Struct when constructing the listener configuration, #876, blocked by #999.

b. Required updates

• [ ] Contour should implement FDS, see #1039

[poidag]

Possibly related.

envoyproxy/envoy#6617

[davecheney]

Fascinating.

I think there are two issues at play in contour, one is high memory consumption if configuration churns frequently, the other is memory consumption due to traffic flow. I think this issue has a handle on the first issue, and staying up to date with the latest envoy releases will give us the best chance of resolving the latter.

On 10 May 2019, at 09:28, Peter Grant [e-mail] wrote:

Possibly related.

envoyproxy/envoy#6617

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.

[davecheney]

Update: for 0.13 we will complete #876 and #1096 which should reduce the number of draining listeners when changes from Contour to Envoy are idempotent. This won't reduce the bloat in draining listeners if the changes are non idempotent -- virtual hosts are being added or removed -- that will have to wait for FDS (#1039) which is not available in a shipping envoy yet.

[davecheney]

We've continued to work on #499 throughout 0.14 by reducing the number of spurious updates sent to Envoy. Moving to 0.15 as work continues.

[davecheney]

Moving to 1.0 beta 1 as #1039 is not yet available. We'll continue to work on this ticket throughout the next few milestones, including #1159.

[davecheney]

In 0.15 we added filtering for unrelated secrets and services. Moving to the next milestone as there is no more work scheduled for this release.

[davecheney]

Moving to the 1.0 release milestone as there is work scheduled for the release candidates.

[davecheney]

Hello,

TL;DR upgrade to Contour 1.2.0 or later and follow the recommendation to use Envoy 1.13.0 or later.

After some investigations on an internally reported issue I am pleased to say this issue can be bought to a close. The root cause of the issue was envoyproxy/envoy#7923 which caused envoy to keep N squared copies of the RDS database in memory for each LDS update. This meant that as the number of vhosts defined across Ingress/IngressRoute/HTTPProxy documents _that used TLS_ grew, this would consume N*N memory on the envoy side for each configuration update. Said another way, the memory consumed by Envoy for each configuration was quadratic, not linear. This issues was resolved upstream in envoyproxy/envoy#9209 and shipped as part of Envoy 1.13.0.

I am marking this issue as complete against the 1.2.0 milestone. The remaining work to reduce the cost of LDS updates is tracked on #1039 which at the time of writing remains blocked on upstream support for FDS.

/cc @michmike @pickledrick

[michmike]

great work team to bring this to a close!

[mattalberts]

Fantastic!

Sent from my iPhone

On Feb 26, 2020, at 9:40 PM, Michael Michael [e-mail] wrote:


great work team to bring this to a close!

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or unsubscribe.