Proxy sidecar exits with non-zero exit code on SIGTERM

[agniveshadhikari]

I am trying to use Linkerd within an argo workflow. I am aware of the issues that are to be expected when trying to use sidecars with jobs.

Argo somehow seems to send a SIGTERM to the linkerd sidecar, but it exits with non-zero exit code. I believe it should have exited with 0 code, and that could have made my workflow succeed. Can you help me understand what is going on here a little better?

As you can see here, the argo workflow fails:

Here is the message (from the above image. Copy-pasted here for better readability)

sidecar 'linkerd-proxy' time="2020-10-05T07:16:24Z" level=info msg="running version edge-20.9.3" [ 0.8921656s] INFO ThreadId(01) linkerd2_proxy: Admin interface on 0.0.0.0:4191 [ 0.8938158s] INFO ThreadId(01) linkerd2_proxy: Inbound interface on 0.0.0.0:4143 [ 0.8941758s] INFO ThreadId(01) linkerd2_proxy: Outbound interface on 127.0.0.1:4140 [ 0.8945058s] INFO ThreadId(01) linkerd2_proxy: Tap interface on 0.0.0.0:4190 [ 0.8947558s] INFO ThreadId(01) linkerd2_proxy: Local identity is default.argo.serviceaccount.identity.linkerd.cluster.local [ 0.8953258s] INFO ThreadId(01) linkerd2_proxy: Identity verified via linkerd-identity-headless.linkerd.svc.cluster.local:8080 (linkerd-identity.linkerd.serviceaccount.identity.linkerd.cluster.local) [ 0.8956559s] INFO ThreadId(01) linkerd2_proxy: Destinations resolved via linkerd-dst-headless.linkerd.svc.cluster.local:8086 (linkerd-destination.linkerd.serviceaccount.identity.linkerd.cluster.local) [ 0.9331082s] INFO ThreadId(02) inbound: linkerd2_app_inbound: Serving addr=0.0.0.0:4143 [ 0.9410887s] INFO ThreadId(03) outbound: linkerd2_app_outbound: Serving addr=127.0.0.1:4140 [ 0.945191456s] INFO ThreadId(04) daemon:identity: linkerd2_app: Certified identity: default.argo.serviceaccount.identity.linkerd.cluster.local [ 1.231961143s] INFO ThreadId(01) linkerd2_proxy::signal: received SIGTERM, starting shutdown

Here is a part of the describe on the pod:

Name:         awesome-python
Namespace:    argo
Priority:     0
Node:         aks-agentpool-34477928-vmss000000/10.240.0.4
Start Time:   Mon, 05 Oct 2020 12:46:21 +0530
Labels:       linkerd.io/control-plane-ns=linkerd
              linkerd.io/workload-ns=argo
              workflows.argoproj.io/completed=true
              workflows.argoproj.io/workflow=awesome-python
Annotations:  linkerd.io/created-by: linkerd/proxy-injector edge-20.9.3
              linkerd.io/identity-mode: default
              linkerd.io/inject: enabled
              linkerd.io/proxy-version: edge-20.9.3
              workflows.argoproj.io/node-name: awesome-python
              workflows.argoproj.io/outputs:
                {"artifacts":[{"name":"main-logs","archiveLogs":true,"s3":{"endpoint":"minio:9000","bucket":"my-bucket","insecure":true,"accessKeySecret":...
              workflows.argoproj.io/template:
                {"name":"argosay","arguments":{},"inputs":{"parameters":[{"name":"message","value":"hello argo"}]},"outputs":{},"metadata":{"annotations":...
Status:       Failed
IP:           10.244.1.31
IPs:
  IP:           10.244.1.31
Controlled By:  Workflow/awesome-python
Init Containers:
  linkerd-init:
    Container ID:  docker://c170e1cf72c33c23f7ad4a445724b8fd6a9df5db63eea4eeb12bd6d98e205fae
    Image:         ghcr.io/linkerd/proxy-init:v1.3.6
    Image ID:      docker-pullable://ghcr.io/linkerd/proxy-init@sha256:591d4f578a8c4431fc6343c8f2703338888865440f02f4cb44862a87c5557859
    Port:          <none>
    Host Port:     <none>
    Args:
      --incoming-proxy-port
      4143
      --outgoing-proxy-port
      4140
      --proxy-uid
      2102
      --inbound-ports-to-ignore
      4190,4191
    State:          Terminated
      Reason:       Completed
      Exit Code:    0
      Started:      Mon, 05 Oct 2020 12:46:23 +0530
      Finished:     Mon, 05 Oct 2020 12:46:23 +0530
    Ready:          True
    Restart Count:  0
    Limits:
      cpu:     100m
      memory:  50Mi
    Requests:
      cpu:        10m
      memory:     10Mi
    Environment:  <none>
    Mounts:
      /run from linkerd-proxy-init-xtables-lock (rw)
      /var/run/secrets/kubernetes.io/serviceaccount from default-token-l9w6l (ro)
Containers:
  wait:
    Container ID:  docker://0895146139a0b647394347fc9b3ff63ab49389a6b0bdcddc8dacb7d19917c990
    Image:         argoproj/argoexec:v2.11.1
    Image ID:      docker-pullable://argoproj/argoexec@sha256:574f8eb926820149bc98c4fc6b3c3b48ecdf6046f4f325643024e5684a0653a0
    Port:          <none>
    Host Port:     <none>
    Command:
      argoexec
      wait
    State:          Terminated
      Reason:       Completed
      Exit Code:    0
      Started:      Mon, 05 Oct 2020 12:46:24 +0530
      Finished:     Mon, 05 Oct 2020 12:46:56 +0530
    Ready:          False
    Restart Count:  0
    Environment:
      ARGO_POD_NAME:  awesome-python (v1:metadata.name)
    Mounts:
      /argo/podmetadata from podmetadata (rw)
      /argo/secret/my-minio-cred from my-minio-cred (ro)
      /var/run/docker.sock from docker-sock (ro)
      /var/run/secrets/kubernetes.io/serviceaccount from default-token-l9w6l (ro)
  main:
    Container ID:  docker://95cfca40e66c81526bcb2a9cfec2f4253fccdbb54f0140e39ea551e5df756b49
    Image:         argoproj/argosay:v2
    Image ID:      docker-pullable://argoproj/argosay@sha256:73b91f8b9278fe9317cbaa8ba5cb5a87d84d31126df49acf1823df4c948bc419
    Port:          <none>
    Host Port:     <none>
    Command:
      /argosay
    Args:
      echo
      hello argo
    State:          Terminated
      Reason:       Completed
      Exit Code:    0
      Started:      Mon, 05 Oct 2020 12:46:24 +0530
      Finished:     Mon, 05 Oct 2020 12:46:24 +0530
    Ready:          False
    Restart Count:  0
    Environment:    <none>
    Mounts:
      /var/run/secrets/kubernetes.io/serviceaccount from default-token-l9w6l (ro)
  linkerd-proxy:
    Container ID:  docker://0b5d32dc77d26d3a7c5dbde9ffee3bcb27ced1f9c67df8e0f26f6ac3ed3e2f98
    Image:         ghcr.io/linkerd/proxy:edge-20.9.3
    Image ID:      docker-pullable://ghcr.io/linkerd/proxy@sha256:d372fb1e5029375f194267327e701b36c30c23db631dc583c32cffb4abb38994
    Ports:         4143/TCP, 4191/TCP
    Host Ports:    0/TCP, 0/TCP
    State:         Terminated
      Reason:      Error
      Message:     time="2020-10-05T07:16:24Z" level=info msg="running version edge-20.9.3"
[     0.8921656s]  INFO ThreadId(01) linkerd2_proxy: Admin interface on 0.0.0.0:4191
[     0.8938158s]  INFO ThreadId(01) linkerd2_proxy: Inbound interface on 0.0.0.0:4143
[     0.8941758s]  INFO ThreadId(01) linkerd2_proxy: Outbound interface on 127.0.0.1:4140
[     0.8945058s]  INFO ThreadId(01) linkerd2_proxy: Tap interface on 0.0.0.0:4190
[     0.8947558s]  INFO ThreadId(01) linkerd2_proxy: Local identity is default.argo.serviceaccount.identity.linkerd.cluster.local
[     0.8953258s]  INFO ThreadId(01) linkerd2_proxy: Identity verified via linkerd-identity-headless.linkerd.svc.cluster.local:8080 (linkerd-identity.linkerd.serviceaccount.identity.linkerd.cluster.local)
[     0.8956559s]  INFO ThreadId(01) linkerd2_proxy: Destinations resolved via linkerd-dst-headless.linkerd.svc.cluster.local:8086 (linkerd-destination.linkerd.serviceaccount.identity.linkerd.cluster.local)
[     0.9331082s]  INFO ThreadId(02) inbound: linkerd2_app_inbound: Serving addr=0.0.0.0:4143
[     0.9410887s]  INFO ThreadId(03) outbound: linkerd2_app_outbound: Serving addr=127.0.0.1:4140
[     0.945191456s]  INFO ThreadId(04) daemon:identity: linkerd2_app: Certified identity: default.argo.serviceaccount.identity.linkerd.cluster.local
[     1.231961143s]  INFO ThreadId(01) linkerd2_proxy::signal: received SIGTERM, starting shutdown

      Exit Code:    137
      Started:      Mon, 05 Oct 2020 12:46:24 +0530
      Finished:     Mon, 05 Oct 2020 12:46:55 +0530
    Ready:          False
    Restart Count:  0
    Liveness:       http-get http://:4191/live delay=10s timeout=1s period=10s #success=1 #failure=3
    Readiness:      http-get http://:4191/ready delay=2s timeout=1s period=10s #success=1 #failure=3
    Environment:
      LINKERD2_PROXY_LOG:                           warn,linkerd=info
      LINKERD2_PROXY_LOG_FORMAT:                    plain
      LINKERD2_PROXY_DESTINATION_SVC_ADDR:          linkerd-dst-headless.linkerd.svc.cluster.local:8086
      LINKERD2_PROXY_DESTINATION_GET_NETWORKS:      10.0.0.0/8,172.16.0.0/12,192.168.0.0/16
      LINKERD2_PROXY_DESTINATION_PROFILE_NETWORKS:  10.0.0.0/8,172.16.0.0/12,192.168.0.0/16
      LINKERD2_PROXY_CONTROL_LISTEN_ADDR:           0.0.0.0:4190
      LINKERD2_PROXY_ADMIN_LISTEN_ADDR:             0.0.0.0:4191
      LINKERD2_PROXY_OUTBOUND_LISTEN_ADDR:          127.0.0.1:4140
      LINKERD2_PROXY_INBOUND_LISTEN_ADDR:           0.0.0.0:4143
      LINKERD2_PROXY_DESTINATION_GET_SUFFIXES:      svc.cluster.local.
      LINKERD2_PROXY_DESTINATION_PROFILE_SUFFIXES:  svc.cluster.local.
      LINKERD2_PROXY_INBOUND_ACCEPT_KEEPALIVE:      10000ms
      LINKERD2_PROXY_OUTBOUND_CONNECT_KEEPALIVE:    10000ms
      _pod_ns:                                      argo (v1:metadata.namespace)
      _pod_nodeName:                                 (v1:spec.nodeName)
      LINKERD2_PROXY_DESTINATION_CONTEXT:           {"ns":"$(_pod_ns)", "nodeName":"$(_pod_nodeName)"}

      LINKERD2_PROXY_IDENTITY_DIR:                  /var/run/linkerd/identity/end-entity
      LINKERD2_PROXY_IDENTITY_TRUST_ANCHORS:        -----BEGIN CERTIFICATE-----
                                                    MII [...] kUQ=
                                                    -----END CERTIFICATE-----

      LINKERD2_PROXY_IDENTITY_TOKEN_FILE:           /var/run/secrets/kubernetes.io/serviceaccount/token
      LINKERD2_PROXY_IDENTITY_SVC_ADDR:             linkerd-identity-headless.linkerd.svc.cluster.local:8080
      _pod_sa:                                       (v1:spec.serviceAccountName)
      _l5d_ns:                                      linkerd
      _l5d_trustdomain:                             cluster.local
      LINKERD2_PROXY_IDENTITY_LOCAL_NAME:           $(_pod_sa).$(_pod_ns).serviceaccount.identity.$(_l5d_ns).$(_l5d_trustdomain)
      LINKERD2_PROXY_IDENTITY_SVC_NAME:             linkerd-identity.$(_l5d_ns).serviceaccount.identity.$(_l5d_ns).$(_l5d_trustdomain)
      LINKERD2_PROXY_DESTINATION_SVC_NAME:          linkerd-destination.$(_l5d_ns).serviceaccount.identity.$(_l5d_ns).$(_l5d_trustdomain)
      LINKERD2_PROXY_TAP_SVC_NAME:                  linkerd-tap.$(_l5d_ns).serviceaccount.identity.$(_l5d_ns).$(_l5d_trustdomain)
    Mounts:
      /var/run/linkerd/identity/end-entity from linkerd-identity-end-entity (rw)
      /var/run/secrets/kubernetes.io/serviceaccount from default-token-l9w6l (ro)
Conditions:
  Type              Status
  Initialized       True
  Ready             False
  ContainersReady   False
  PodScheduled      True
Volumes:
  podmetadata:
    Type:  DownwardAPI (a volume populated by information about the pod)
    Items:
      metadata.annotations -> annotations
  docker-sock:
    Type:          HostPath (bare host directory volume)
    Path:          /var/run/docker.sock
    HostPathType:  Socket
  my-minio-cred:
    Type:        Secret (a volume populated by a Secret)
    SecretName:  my-minio-cred
    Optional:    false
  default-token-l9w6l:
    Type:        Secret (a volume populated by a Secret)
    SecretName:  default-token-l9w6l
    Optional:    false
  linkerd-proxy-init-xtables-lock:
    Type:       EmptyDir (a temporary directory that shares a pod's lifetime)
    Medium:
    SizeLimit:  <unset>
  linkerd-identity-end-entity:
    Type:        EmptyDir (a temporary directory that shares a pod's lifetime)
    Medium:      Memory
    SizeLimit:   <unset>
QoS Class:       Burstable
Node-Selectors:  <none>
Tolerations:     node.kubernetes.io/not-ready:NoExecute for 300s
                 node.kubernetes.io/unreachable:NoExecute for 300s
Events:          <none>

[grampelberg]

@cpretzer you've messed around with Argo most recently, any ideas?

[cpretzer]

I didn't get far enough with Argo to see anything like this.

It looks like the proxy is starting up and shutting down very quickly, so I'd start by looking at when and why Argo is sending that SIGTERM. I wonder if the proxy has not fully started when it receives the SIGTERM command.

I'd also set the trace proxy-log-level just to see if there's more detail about what the proxy is doing.