High CPU and memory usage with frequent k8s state changes

Hi, this is a duplicate of https://github.com/linkerd/linkerd/issues/1585

Testing linkerd in my perf environment I noticed that namerd cpu and memory spike when my pods frequently cycle their readiness state. When I moved my dtabs into linkerd I got the same result there. This being a perf setup the pods report that they’re not ready when they’re at maximum capacity, so they flip back and forth unusually quickly. Note that in this case I’m not even using linkerd/namerd for anything: they’re freshly installed and nothing has it set as it’s proxy.

I was able to reproduce this issue with a minimal install which I will attach. In what I’ve found is it will behave for a few minutes until eventually spiking cpu to 100%, and memory climbing until the pod runs out of memory and restarts.

l5d.yaml:

---
apiVersion: v1
kind: ConfigMap
metadata:
  name: l5d-config
data:
  config.yaml: |-
    admin:
      port: 9990

    namers:
    - kind: io.l5d.k8s
      experimental: true
      host: localhost
      port: 8001

    telemetry:
    - kind: io.l5d.prometheus
    - kind: io.l5d.recentRequests
      sampleRate: 0.25

    usage:
      orgId: linkerd-examples-daemonset

    routers:
    - protocol: http
      label: outgoing
      dtab: |
        /srv        => /#/io.l5d.k8s/default/http;
        /svc        => /srv;
      interpreter:
        kind: default
        transformers:
        - kind: io.l5d.k8s.daemonset
          namespace: default
          port: incoming
          service: l5d
      servers:
      - port: 4140
        ip: 0.0.0.0
      service:
        responseClassifier:
          kind: io.l5d.http.retryableRead5XX

    - protocol: http
      label: incoming
      dtab: |
        /srv        => /#/io.l5d.k8s/default/http;
        /host       => /srv;
        /svc        => /host;
      interpreter:
        kind: default
        transformers:
        - kind: io.l5d.k8s.localnode
      servers:
      - port: 4141
        ip: 0.0.0.0
---
apiVersion: extensions/v1beta1
kind: DaemonSet
metadata:
  labels:
    app: l5d
  name: l5d
spec:
  updateStrategy:
    type: RollingUpdate
    rollingUpdate:
      maxUnavailable: 10%
  template:
    metadata:
      labels:
        app: l5d
    spec:
      volumes:
      - name: l5d-config
        configMap:
          name: "l5d-config"
      containers:
      - name: l5d
        image: buoyantio/linkerd:1.1.3
        env:
        - name: POD_IP
          valueFrom:
            fieldRef:
              fieldPath: status.podIP
        args:
        - -log.level=DEBUG
        - -com.twitter.finagle.tracing.debugTrace=true
        - /io.buoyant/linkerd/config/config.yaml
        ports:
        - name: outgoing
          containerPort: 4140
          hostPort: 4140
        - name: incoming
          containerPort: 4141
        - name: admin
          containerPort: 9990
        volumeMounts:
        - name: "l5d-config"
          mountPath: "/io.buoyant/linkerd/config"
          readOnly: true

      - name: kubectl
        image: buoyantio/kubectl:v1.6.2
        args: ["proxy", "-p", "8001"]
---
apiVersion: v1
kind: Service
metadata:
  name: l5d
spec:
  selector:
    app: l5d
  type: LoadBalancer
  ports:
  - name: outgoing
    port: 4140
  - name: incoming
    port: 4141
  - name: admin
    port: 9990

ready.yaml:

---
apiVersion: v1
kind: ConfigMap
metadata:
  name: ready-config
data:
  server.js: |-
    const http = require('http');
    const port = 8080;

    let flipper = Math.floor(Math.random() * 1000);

    const requestHandler = (request, response) => {
      console.log(request.url, ++flipper);
      if (Math.floor(flipper / 3) % 2 === 0) {
        response.statusCode = 500;
        response.end('Nope!');
      }
      else {
        response.end('Hello Node.js Server!');
      }
    }

    const server = http.createServer(requestHandler);

    server.listen(port, (err) => {
      if (err) {
        return console.log('something bad happened', err);
      }

      console.log(`server is listening on ${port}`);
    });
---
apiVersion: extensions/v1beta1
kind: Deployment
metadata:
  name: ready-deployment
spec:
  replicas: 50
  minReadySeconds: 10
  template:
    metadata:
      labels:
        app: ready
    spec:
      volumes:
      - name: ready-config
        configMap:
          name: "ready-config"
      containers:
      - name: ready
        image: node
        livenessProbe:
          tcpSocket:
            port: 8080
          initialDelaySeconds: 6
          timeoutSeconds: 3
        readinessProbe:
          httpGet:
            path: /health
            port: 8080
            scheme: HTTP
          initialDelaySeconds: 5
          timeoutSeconds: 5
        ports:
        - containerPort: 8080
        volumeMounts:
        - name: "ready-config"
          mountPath: "/ready"
          readOnly: true
        args: ["node", "/ready/server.js"]
---
apiVersion: v1
kind: Service
metadata:
  name: ready
spec:
  selector:
    app: ready
  clusterIP: None
  ports:
  - name: http
    port: 8080

default pprof

from curl "localhost:9990/admin/pprof/profile?seconds=30" > linkerd.pprof:

$ pprof --text linkerd.pprof
Using local file linkerd.pprof.
Using local file linkerd.pprof.
Total: 64 samples
       5   7.8%   7.8%        5   7.8% sun.misc.Unsafe.unpark
       4   6.2%  14.1%        4   6.2% com.twitter.util.Promise.forwardInterruptsTo
       4   6.2%  20.3%        4   6.2% java.lang.Thread.sleep
       3   4.7%  25.0%       35  54.7% com.twitter.concurrent.Scheduler$.submit
       2   3.1%  28.1%        2   3.1% java.io.FileOutputStream.writeBytes
       2   3.1%  31.2%        2   3.1% java.lang.Object.getClass
       2   3.1%  34.4%        2   3.1% java.lang.Thread.currentThread
       2   3.1%  37.5%        2   3.1% scala.collection.immutable.HashMap$HashTrieMap.updated0
       2   3.1%  40.6%        2   3.1% sun.reflect.GeneratedConstructorAccessor9.newInstance
       1   1.6%  42.2%        1   1.6% com.fasterxml.jackson.core.json.UTF8StreamJsonParser.
       1   1.6%  43.8%        1   1.6% com.twitter.concurrent.AsyncStream$Cons$.unapply
       1   1.6%  45.3%        7  10.9% com.twitter.concurrent.AsyncStream.map
       1   1.6%  46.9%        1   1.6% com.twitter.jvm.Hotspot.$anonfun$getGc$10
       1   1.6%  48.4%        3   4.7% com.twitter.util.ConstFuture$$anon$8.run
       1   1.6%  50.0%        2   3.1% com.twitter.util.ConstFuture.respond
       1   1.6%  51.6%       22  34.4% com.twitter.util.Future.$anonfun$map$2
       1   1.6%  53.1%        1   1.6% com.twitter.util.Monitor$.get

pprof hz=500

from curl "localhost:9990/admin/pprof/profile?seconds=30&hz=500" > linkerd_500.pprof:

$ pprof --text linkerd_500.pprof
Using local file linkerd_500.pprof.
Using local file linkerd_500.pprof.
Total: 182 samples
      25  13.7%  13.7%      163  89.6% com.twitter.concurrent.Scheduler$.submit
      24  13.2%  26.9%       24  13.2% com.twitter.util.Promise.forwardInterruptsTo
      19  10.4%  37.4%       19  10.4% sun.misc.Unsafe.unpark
      12   6.6%  44.0%      122  67.0% com.twitter.util.Promise$Transformer.apply
      11   6.0%  50.0%       20  11.0% com.twitter.util.ConstFuture$$anon$8.run
      10   5.5%  55.5%       40  22.0% com.twitter.util.Promise$Responder.transform
       4   2.2%  57.7%      163  89.6% com.twitter.concurrent.LocalScheduler$Activation.run
       4   2.2%  59.9%        4   2.2% java.lang.Throwable.getStackTraceElement
       4   2.2%  62.1%        4   2.2% scala.runtime.OrderedProxy.compare$
       3   1.6%  63.7%        3   1.6% com.fasterxml.jackson.core.json.UTF8StreamJsonParser.getText
       3   1.6%  65.4%        3   1.6% com.twitter.concurrent.AsyncStream$$Lambda$1083/644352423.get$Lambda
       2   1.1%  66.5%        2   1.1% com.twitter.concurrent.LocalScheduler$Activation.next
       2   1.1%  67.6%        2   1.1% com.twitter.finagle.context.Context.contains$
       2   1.1%  68.7%        2   1.1% com.twitter.util.Future$$Lambda$256/229997158.get$Lambda
       2   1.1%  69.8%       89  48.9% com.twitter.util.Future.$anonfun$map$2
       2   1.1%  70.9%        7   3.8% com.twitter.util.Promise.continue
       2   1.1%  72.0%      163  89.6% com.twitter.util.Promise.runq
       2   1.1%  73.1%        2   1.1% java.io.FileOutputStream.writeBytes

We’re currently in the process of doing a major refactor to the k8s watch code that we hope will significantly improve performance in cases like this. You can follow that work here: https://github.com/linkerd/linkerd/issues/1534