Repository: kubernetes
Issue: During a rolling update, replica start gets caught in exponential backoff, causing unnecessary delay of up to 16 minutes.
Labels: kind/bug,sig/apps,lifecycle/stale,needs-triage

<!-- Please use this template while reporting a bug and provide as much info as possible. Not doing so may result in your bug not being addressed in a timely manner. Thanks!

If the matter is security related, please disclose it privately via https://kubernetes.io/security/
-->

**TL;DR**

Rolling update gets stuck in an exponential backoff when the app being deployed uses quotas and has a significant termination grace period.

**What happened**:

Define a deployment with the following parameters:

Strategy: RollingUpdate
replicas: 2
maxSurge: 0
maxUnavailable: 1
terminationGracePeriodSeconds: 90
the liveness and readiness probes should both have initialDelaySeconds: 0
each replica consists of just one lightweight container that traps SIGTERM

Define a ResourceQuota sufficient for exactly 3 concurrent replicas.

Apply the deployment and resource quota, then make a no-op change to the deployment and apply it again to force a rolling update.

The following behavior in the rollout is observed  (OLD1 and OLD2 are the two original replicas; NEW1 and NEW2 are the replicas that are rolled out in the new deployment):


| Time    |   OLD1              |   OLD2                 | NEW1                 | NEW2                |      Notes        |
|---------|---------------------|------------------------|----------------------|---------------------|--------------------|
| T0      |   RUNNING/AVAILABLE |   RUNNING/AVAILABLE    | ---                  | ---                 | |
| T1  (1s)    |   TERMINATING       |   RUNNING/AVAILABLE    | RUNNING/UNAVAILABLE  | ---                 | |
| T2   (13s)   |   TERMINATING       |   TERMINATING          | RUNNING/AVAILABLE    | ---                 |  NEW2 blocked by quota; begins exponential backoff |
| T3   (93s)   |   [TERMINATED]      |   TERMINATING          | RUNNING/AVAILABLE    | --- |  NEW2 could start now, but is caught in exponential backoff |
| T4  (105s)     |   [TERMINATED]      |   [TERMINATED]          | RUNNING/AVAILABLE    |  ---  | NEW2 still caught in exponential backoff |
| T5   (168s)   |   [TERMINATED]      |   [TERMINATED]         | RUNNING/AVAILABLE    | RUNNING/UNAVAILABLE   |  NEW2 finally exits exponential backoff and starts |
| T6   (171s)   |   [TERMINATED]      |   [TERMINATED]         | RUNNING/AVAILABLE    | RUNNING/AVAILABLE   | |

The start of replica NEW2 has been delayed by 75 seconds (168 - 93) in this example.  We can easily increase the amount of time delayed by increasing terminationGracePeriodSeconds: for example, if  terminationGracePeriodSeconds is set to 1400s, we observe a delay of over 800s.  

In production, we have observed delays of up to 1000 seconds (>16 minutes).


**What you expected to happen**:

The rolling update proceeds as follows, with the new replicas starting as soon as quota allows:

| Time    |   OLD1              |   OLD2                 | NEW1                 | NEW2                |      Notes        |
|---------|---------------------|------------------------|----------------------|---------------------|--------------------|
| T0      |   RUNNING/AVAILABLE |   RUNNING/AVAILABLE    | ---                  | ---                 | |
| T1      |   TERMINATING       |   RUNNING/AVAILABLE    | RUNNING/UNAVAILABLE  | ---                 | |
| T2      |   TERMINATING       |   TERMINATING          | RUNNING/AVAILABLE    | ---                 | NEW2 blocked by quota |
| T3      |   [TERMINATED]      |   TERMINATING          | RUNNING/AVAILABLE    | RUNNING/UNAVAILABLE |NEW2 no longer blocked by quota; starts immediately |
| T4      |   [TERMINATED]      |   TERMINATING          | RUNNING/AVAILABLE    | RUNNING/AVAILABLE   | |
| T5      |   [TERMINATED]      |   [TERMINATED]         | RUNNING/AVAILABLE    | RUNNING/AVAILABLE   | |

The ability to customize the exponential backoff (currently appears to be initial=5ms; max=1000sec; factor=2) would be an acceptable workaround.


**How to reproduce it (as minimally and precisely as possible)**:

* Create a file `app.json` from the text below
* Run `kubectl apply -f app.json`
* Make an insignificant edit to `app.json` (e.g. change "Sleeping" to "Sleeeping") to force a redeploy
* Run `kubectl apply -f app.json` again to trigger a rolling update
* Observe the behavior of the rollout by running a command such as `while true; do echo; date; kubectl get pod -n rollout-quotablocked; sleep 1; done`

```
---
{
   "apiVersion": "v1",
   "kind": "Namespace",
   "metadata": {
      "name": "rollout-quotablocked"
   }
}
---
{
   "apiVersion": "v1",
   "kind": "ResourceQuota",
   "metadata": {
      "name": "rollout-quotablocked",
      "namespace": "rollout-quotablocked"
   },
   "spec": {
      "hard": {
         "requests.memory": "150Mi"
      }
   }
}
---
{
   "apiVersion": "apps/v1",
   "kind": "Deployment",
   "metadata": {
      "name": "rollout-quotablocked",
      "namespace": "rollout-quotablocked"
   },
   "spec": {
      "replicas": 2,
      "selector": {
         "matchLabels": {      
            "app": "rollout-quotablocked"
         }
      },
      "strategy": {
         "rollingUpdate": {
            "maxSurge": 0,
            "maxUnavailable": 1
         },
         "type": "RollingUpdate"
      },
      "template": {
         "metadata": {
            "labels": {
               "app": "rollout-quotablocked"
            }
         },
         "spec": {
            "terminationGracePeriodSeconds": 90,
            "containers": [
               {
                  "command": [
                     "/bin/bash",
                     "-c",
                     "trap \"trap - SIGTERM && echo Sleeping && sleep infinity;  \" SIGTERM; { while true; do date > /tmp/healthy; sleep 5; done; } & wait $!"
                  ],
                  "image": "ubuntu:latest",
                  "livenessProbe": {
                     "exec": {
                        "command": ["cat", "/tmp/healthy"]
                     },
                     "initialDelaySeconds": 0,
                     "timeoutSeconds": 2
                  },
                  "readinessProbe": {
                     "exec": {
                        "command": ["cat",  "/tmp/healthy"]
                     },
                     "initialDelaySeconds": 0,
                     "timeoutSeconds": 2
                  },
                  "name": "rollout-quotablocked",
                  "resources": {
                     "limits": {
                        "memory": "50Mi"
                     }
                  }
               }
            ]
         }
      }
   }
}
```

**Anything else we need to know?**:

EDIT:

With larger parameters (replicas=33, maxSurge=4, maxUnavailable=2, quota allows 39 concurrent instances, terminationGracePeriodSeconds=150), we see worse-than-exponential backoff (the delay  jumps to ~16 minutes almost immediately).  

The kube-controller-manager.log shows 58 failed pod creation attempts within 11 seconds, followed by a 15+ minute gap during which nothing appears to be happening:

```
2021-02-08T17:58:15.174295319Z stderr F I0208 17:58:15.174110       1 event.go:221] Event(v1.ObjectReference{Kind:"Deployment", Namespace:"hello-www-dwake-dev", Name:"hello-www-dwake", UID:"1d66a96e-6a37-11eb-8878-0242ac120003", APIVersion:"apps/v1", ResourceVersion:"2265", FieldPath:""}): type: 'Normal' reason: 'ScalingReplicaSet' Scaled up replica set hello-www-dwake-7c659fcc8c to 7
2021-02-08T17:58:15.186141811Z stderr F I0208 17:58:15.185754       1 event.go:221] Event(v1.ObjectReference{Kind:"ReplicaSet", Namespace:"hello-www-dwake-dev", Name:"hello-www-dwake-7c659fcc8c", UID:"34f4020a-6a37-11eb-8878-0242ac120003", APIVersion:"apps/v1", ResourceVersion:"2310", FieldPath:""}): type: 'Warning' reason: 'FailedCreate' Error creating: pods "hello-www-dwake-7c659fcc8c-vrbvh" is forbidden: exceeded quota: hello-www-dwake, requested: requests.memory=50Mi, used: requests.memory=1950Mi, limited: requests.memory=1950Mi
2021-02-08T17:58:15.194095728Z stderr F E0208 17:58:15.193859       1 replica_set.go:450] Sync "hello-www-dwake-dev/hello-www-dwake-7c659fcc8c" failed with pods "hello-www-dwake-7c659fcc8c-vrbvh" is forbidden: exceeded quota: hello-www-dwake, requested: requests.memory=50Mi, used: requests.memory=1950Mi, limited: requests.memory=1950Mi
[56 failed pod creation attempts similar to the preceding and following entries omitted]
2021-02-08T17:58:26.078871725Z stderr F E0208 17:58:26.078003       1 replica_set.go:450] Sync "hello-www-dwake-dev/hello-www-dwake-7c659fcc8c" failed with pods "hello-www-dwake-7c659fcc8c-rc8q4" is forbidden: exceeded quota: hello-www-dwake, requested: requests.memory=50Mi, used: requests.memory=1950Mi, limited: requests.memory=1950Mi
2021-02-08T17:58:26.078897958Z stderr F I0208 17:58:26.078307       1 event.go:221] Event(v1.ObjectReference{Kind:"ReplicaSet", Namespace:"hello-www-dwake-dev", Name:"hello-www-dwake-7c659fcc8c", UID:"34f4020a-6a37-11eb-8878-0242ac120003", APIVersion:"apps/v1", ResourceVersion:"2409", FieldPath:""}): type: 'Warning' reason: 'FailedCreate' Error creating: pods "hello-www-dwake-7c659fcc8c-rc8q4" is forbidden: exceeded quota: hello-www-dwake, requested: requests.memory=50Mi, used: requests.memory=1950Mi, limited: requests.memory=1950Mi
2021-02-08T18:14:33.490777675Z stderr F W0208 18:14:33.486527       1 reflector.go:256] k8s.io/client-go/informers/factory.go:132: watch of *v1beta1.Event ended with: The resourceVersion for the provided watch is too old.
2021-02-08T18:15:06.223838023Z stderr F I0208 18:15:06.216009       1 event.go:221] Event(v1.ObjectReference{Kind:"ReplicaSet", Namespace:"hello-www-dwake-dev", Name:"hello-www-dwake-7c659fcc8c", UID:"34f4020a-6a37-11eb-8878-0242ac120003", APIVersion:"apps/v1", ResourceVersion:"2409", FieldPath:""}): type: 'Normal' reason: 'SuccessfulCreate' Created pod: hello-www-dwake-7c659fcc8c-498c6
```

**Environment**:
- Kubernetes version (use `kubectl version`):  Client Version: version.Info{Major:"1", Minor:"13", GitVersion:"v1.13.12", GitCommit:"a8b52209ee172232b6db7a6e0ce2adc77458829f", GitTreeState:"clean", BuildDate:"2019-10-15T12:12:15Z", GoVersion:"go1.11.13", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"19", GitVersion:"v1.19.2", GitCommit:"f5743093fd1c663cb0cbc89748f730662345d44d", GitTreeState:"clean", BuildDate:"2020-09-16T13:32:58Z", GoVersion:"go1.15", Compiler:"gc", Platform:"linux/amd64"}
- Cloud provider or hardware configuration: Kubernetes cluster on dedicated hardware.
- OS (e.g: `cat /etc/os-release`): Red Hat Enterprise Linux Server release 7.9 (Maipo)
- Kernel (e.g. `uname -a`): Linux  3.10.0-1160.el7.x86_64 #1 SMP Tue Aug 18 14:50:17 EDT 2020 x86_64 x86_64 x86_64 GNU/Linux
- Install tools:
- Network plugin and version (if this is a network-related bug):
- Others: