search

argoproj / argo-rollouts

Progressive Delivery for Kubernetes
https://argo-rollouts.readthedocs.io/
Apache License 2.0
2.75k stars 866 forks source link

BlueGreen: Old RS not scaled down #1621

Closed dpiraud closed 2 years ago

dpiraud commented 2 years ago

Summary

What happened/what you expected to happen?

Summary

Having a blue/green demo app, old RS in not scaled down after rollout success.

Diagnostics

Version:

1.1.0

Configuration

apiVersion: argoproj.io/v1alpha1  
kind: Rollout  
metadata:  
  name: blue-green-demo-api  
  namespace: staging-exploitation  
  replicas: 5  
  strategy:  
    blueGreen:  
      activeService: blue-green-demo-api  
      autoPromotionEnabled: true  
      scaleDownDelaySeconds: 10  
  selector:  
    matchLabels:  
      app:  blue-green-demo-api  
  template:  
    ...

Rollout view

Name:            blue-green-demo-api
Namespace:       staging-exploitation
Status:          ✔ Healthy
Strategy:        BlueGreen
Images:          xxx/canary-demo-api:blue
                 xxx/canary-demo-api:green (stable, active)
Replicas:
  Desired:       5
  Current:       10
  Updated:       5
  Ready:         5
  Available:     5

NAME                                             KIND        STATUS     AGE    INFO
⟳ blue-green-demo-api                            Rollout     ✔ Healthy  3h13m
├──# revision:2
│  └──⧉ blue-green-demo-api-6765df48f4           ReplicaSet  ✔ Healthy  42m    stable,active
│     ├──□ blue-green-demo-api-6765df48f4-hzjbx  Pod         ✔ Running  42m    ready:2/2
│     ├──□ blue-green-demo-api-6765df48f4-jq582  Pod         ✔ Running  42m    ready:2/2
│     ├──□ blue-green-demo-api-6765df48f4-zb6l4  Pod         ✔ Running  42m    ready:2/2
│     ├──□ blue-green-demo-api-6765df48f4-jj5jj  Pod         ✔ Running  42m    ready:2/2
│     └──□ blue-green-demo-api-6765df48f4-rwpwv  Pod         ✔ Running  42m    ready:2/2
└──# revision:1
   └──⧉ blue-green-demo-api-6695fbf66b           ReplicaSet  ✔ Healthy  3h13m
      ├──□ blue-green-demo-api-6695fbf66b-vqjln  Pod         ✔ Running  3h13m  ready:2/2
      ├──□ blue-green-demo-api-6695fbf66b-9frx9  Pod         ✔ Running  3h13m  ready:2/2
      ├──□ blue-green-demo-api-6695fbf66b-jbdp6  Pod         ✔ Running  3h13m  ready:2/2
      ├──□ blue-green-demo-api-6695fbf66b-5jjvm  Pod         ✔ Running  3h13m  ready:2/2
      └──□ blue-green-demo-api-6695fbf66b-5rz6f  Pod         ✔ Running  3h13m  ready:2/2

Logs

time="2021-11-02T13:50:11Z" level=info msg="syncing service" namespace=staging-exploitation rollout=blue-green-demo-api service=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Started syncing rollout" generation=2 namespace=staging-exploitation resourceVersion=492204584 rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6695fbf66b'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="No status changes. Skipping patch" generation=2 namespace=staging-exploitation resourceVersion=492204584 rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Reconciliation completed" generation=2 namespace=staging-exploitation resourceVersion=492204584 rollout=blue-green-demo-api time_ms=3.918436
time="2021-11-02T13:50:11Z" level=info msg="Start processing" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:50:11Z" level=error msg="Failed to process: secret \"argo-rollouts-notification-secret\" not found" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Started syncing rollout" generation=3 namespace=staging-exploitation resourceVersion=492301350 rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Updating replica set 'blue-green-demo-api-6765df48f4' revision from 0 to 2" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Enqueueing parent of staging-exploitation/blue-green-demo-api-6765df48f4: Rollout staging-exploitation/blue-green-demo-api"
time="2021-11-02T13:50:11Z" level=info msg="Created ReplicaSet blue-green-demo-api-6765df48f4" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Enqueueing parent of staging-exploitation/blue-green-demo-api-6765df48f4: Rollout staging-exploitation/blue-green-demo-api"
time="2021-11-02T13:50:11Z" level=info msg="Rollout updated to revision 2" event_reason=RolloutUpdated namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Created ReplicaSet blue-green-demo-api-6765df48f4 (revision 2)" event_reason=NewReplicaSetCreated namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Event(v1.ObjectReference{Kind:\"Rollout\", Namespace:\"staging-exploitation\", Name:\"blue-green-demo-api\", UID:\"b1323fcb-1792-45a6-834c-83d995c115ba\", APIVersion:\"argoproj.io/v1alpha1\", ResourceVersion:\"492301353\", FieldPath:\"\"}): type: 'Normal' reason: 'RolloutUpdated' Rollout updated to revision 2"
time="2021-11-02T13:50:11Z" level=info msg="Event(v1.ObjectReference{Kind:\"Rollout\", Namespace:\"staging-exploitation\", Name:\"blue-green-demo-api\", UID:\"b1323fcb-1792-45a6-834c-83d995c115ba\", APIVersion:\"argoproj.io/v1alpha1\", ResourceVersion:\"492301353\", FieldPath:\"\"}): type: 'Normal' reason: 'NewReplicaSetCreated' Created ReplicaSet blue-green-demo-api-6765df48f4 (revision 2)"
time="2021-11-02T13:50:11Z" level=info msg="Start processing" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:50:11Z" level=error msg="Failed to process: secret \"argo-rollouts-notification-secret\" not found" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Set rollout condition: &RolloutCondition{Type:Progressing,Status:True,LastUpdateTime:2021-11-02 13:50:11.184889504 +0000 UTC m=+968060.080636223,LastTransitionTime:2021-11-02 13:50:11.184889627 +0000 UTC m=+968060.080636335,Reason:NewReplicaSetCreated,Message:Created new replica set \"blue-green-demo-api-6765df48f4\",}" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Pod template change detected (new: 6765df48f4, old: 6695fbf66b)" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Start processing" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:50:11Z" level=error msg="Failed to process: secret \"argo-rollouts-notification-secret\" not found" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Pod template change detected (new: 6765df48f4, old: 6695fbf66b)" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Patched: {\"status\":{\"conditions\":[{\"lastTransitionTime\":\"2021-11-02T11:20:17Z\",\"lastUpdateTime\":\"2021-11-02T11:20:17Z\",\"message\":\"Rollout has minimum availability\",\"reason\":\"AvailableReason\",\"status\":\"True\",\"type\":\"Available\"},{\"lastTransitionTime\":\"2021-11-02T13:50:11Z\",\"lastUpdateTime\":\"2021-11-02T13:50:11Z\",\"message\":\"RolloutCompleted\",\"reason\":\"RolloutCompleted\",\"status\":\"False\",\"type\":\"Completed\"},{\"lastTransitionTime\":\"2021-11-02T11:19:21Z\",\"lastUpdateTime\":\"2021-11-02T13:50:11Z\",\"message\":\"ReplicaSet \\\"blue-green-demo-api-6765df48f4\\\" is progressing.\",\"reason\":\"ReplicaSetUpdated\",\"status\":\"True\",\"type\":\"Progressing\"}],\"currentPodHash\":\"6765df48f4\",\"message\":\"more replicas need to be updated\",\"observedGeneration\":\"4\",\"phase\":\"Progressing\",\"updatedReplicas\":null}}" generation=4 namespace=staging-exploitation resourceVersion=492301355 rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="persisted to informer" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Reconciliation completed" generation=3 namespace=staging-exploitation resourceVersion=492301350 rollout=blue-green-demo-api time_ms=118.29517
time="2021-11-02T13:50:11Z" level=info msg="Start processing" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:50:11Z" level=error msg="Failed to process: secret \"argo-rollouts-notification-secret\" not found" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6695fbf66b'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Scaled up ReplicaSet blue-green-demo-api-6765df48f4 (revision 2) from 0 to 5" event_reason=ScalingReplicaSet namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="New RS 'blue-green-demo-api-6765df48f4' is not ready to pause" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="skipping active service switch: New RS 'blue-green-demo-api-6765df48f4' is not fully saturated" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Event(v1.ObjectReference{Kind:\"Rollout\", Namespace:\"staging-exploitation\", Name:\"blue-green-demo-api\", UID:\"b1323fcb-1792-45a6-834c-83d995c115ba\", APIVersion:\"argoproj.io/v1alpha1\", ResourceVersion:\"492301357\", FieldPath:\"\"}): type: 'Normal' reason: 'ScalingReplicaSet' Scaled up ReplicaSet blue-green-demo-api-6765df48f4 (revision 2) from 0 to 5"
time="2021-11-02T13:50:11Z" level=info msg="Enqueueing parent of staging-exploitation/blue-green-demo-api-6765df48f4: Rollout staging-exploitation/blue-green-demo-api"
time="2021-11-02T13:50:11Z" level=info msg="Timed out (false) [last progress check: 2021-11-02 13:50:11 +0000 UTC - now: 2021-11-02 13:50:11.276115874 +0000 UTC m=+968060.171862592]" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Queueing up rollout for a progress after 599s" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api time_ms=18.462289
time="2021-11-02T13:50:11Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6695fbf66b'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="New RS 'blue-green-demo-api-6765df48f4' is not ready to pause" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="skipping active service switch: New RS 'blue-green-demo-api-6765df48f4' is not fully saturated" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Timed out (false) [last progress check: 2021-11-02 13:50:11 +0000 UTC - now: 2021-11-02 13:50:11.280035121 +0000 UTC m=+968060.175781820]" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Queueing up rollout for a progress after 599s" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api time_ms=3.437971
time="2021-11-02T13:50:11Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6695fbf66b'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="New RS 'blue-green-demo-api-6765df48f4' is not ready to pause" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="skipping active service switch: New RS 'blue-green-demo-api-6765df48f4' is not fully saturated" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Timed out (false) [last progress check: 2021-11-02 13:50:11 +0000 UTC - now: 2021-11-02 13:50:11.282502845 +0000 UTC m=+968060.178249540]" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Queueing up rollout for a progress after 599s" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:11Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api time_ms=2.483135
time="2021-11-02T13:50:15Z" level=info msg="Enqueueing parent of staging-exploitation/blue-green-demo-api-6765df48f4: Rollout staging-exploitation/blue-green-demo-api"
time="2021-11-02T13:50:15Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6695fbf66b'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="New RS 'blue-green-demo-api-6765df48f4' is not ready to pause" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="skipping active service switch: New RS 'blue-green-demo-api-6765df48f4' is not fully saturated" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="Timed out (false) [last progress check: 2021-11-02 13:50:11 +0000 UTC - now: 2021-11-02 13:50:15.719544546 +0000 UTC m=+968064.615291243]" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="Queueing up rollout for a progress after 595s" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api time_ms=4.873148
time="2021-11-02T13:50:15Z" level=info msg="Enqueueing parent of staging-exploitation/blue-green-demo-api-6765df48f4: Rollout staging-exploitation/blue-green-demo-api"
time="2021-11-02T13:50:15Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6695fbf66b'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="New RS 'blue-green-demo-api-6765df48f4' is not ready to pause" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="skipping active service switch: New RS 'blue-green-demo-api-6765df48f4' is not fully saturated" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="Patched: {\"status\":{\"conditions\":[{\"lastTransitionTime\":\"2021-11-02T11:20:17Z\",\"lastUpdateTime\":\"2021-11-02T11:20:17Z\",\"message\":\"Rollout has minimum availability\",\"reason\":\"AvailableReason\",\"status\":\"True\",\"type\":\"Available\"},{\"lastTransitionTime\":\"2021-11-02T13:50:11Z\",\"lastUpdateTime\":\"2021-11-02T13:50:11Z\",\"message\":\"RolloutCompleted\",\"reason\":\"RolloutCompleted\",\"status\":\"False\",\"type\":\"Completed\"},{\"lastTransitionTime\":\"2021-11-02T11:19:21Z\",\"lastUpdateTime\":\"2021-11-02T13:50:15Z\",\"message\":\"ReplicaSet \\\"blue-green-demo-api-6765df48f4\\\" is progressing.\",\"reason\":\"ReplicaSetUpdated\",\"status\":\"True\",\"type\":\"Progressing\"}],\"message\":\"active service cutover pending\",\"replicas\":10,\"updatedReplicas\":5}}" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="persisted to informer" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301357 rollout=blue-green-demo-api time_ms=51.573373
time="2021-11-02T13:50:15Z" level=info msg="Start processing" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:50:15Z" level=error msg="Failed to process: secret \"argo-rollouts-notification-secret\" not found" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6695fbf66b'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="New RS 'blue-green-demo-api-6765df48f4' is not ready to pause" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="skipping active service switch: New RS 'blue-green-demo-api-6765df48f4' is not fully saturated" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="Timed out (false) [last progress check: 2021-11-02 13:50:15 +0000 UTC - now: 2021-11-02 13:50:15.844988559 +0000 UTC m=+968064.740735260]" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="Queueing up rollout for a progress after 599s" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:15Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api time_ms=4.600495
time="2021-11-02T13:50:43Z" level=info msg="Enqueueing parent of staging-exploitation/blue-green-demo-api-6765df48f4: Rollout staging-exploitation/blue-green-demo-api"
time="2021-11-02T13:50:43Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:43Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6695fbf66b'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:43Z" level=info msg="New RS 'blue-green-demo-api-6765df48f4' is not ready to pause" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:43Z" level=info msg="skipping active service switch: New RS 'blue-green-demo-api-6765df48f4' is not fully saturated" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:43Z" level=info msg="Timed out (false) [last progress check: 2021-11-02 13:50:15 +0000 UTC - now: 2021-11-02 13:50:43.779369378 +0000 UTC m=+968092.675116073]" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:43Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:43Z" level=info msg="Queueing up rollout for a progress after 571s" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:43Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api time_ms=2.797286
time="2021-11-02T13:50:44Z" level=info msg="Enqueueing parent of staging-exploitation/blue-green-demo-api-6765df48f4: Rollout staging-exploitation/blue-green-demo-api"
time="2021-11-02T13:50:44Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:44Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6695fbf66b'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:44Z" level=info msg="New RS 'blue-green-demo-api-6765df48f4' is not ready to pause" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:44Z" level=info msg="skipping active service switch: New RS 'blue-green-demo-api-6765df48f4' is not fully saturated" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:44Z" level=info msg="Timed out (false) [last progress check: 2021-11-02 13:50:15 +0000 UTC - now: 2021-11-02 13:50:44.641066271 +0000 UTC m=+968093.536812979]" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:44Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:44Z" level=info msg="Queueing up rollout for a progress after 570s" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:44Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api time_ms=4.078376
time="2021-11-02T13:50:47Z" level=info msg="Enqueueing parent of staging-exploitation/blue-green-demo-api-6765df48f4: Rollout staging-exploitation/blue-green-demo-api"
time="2021-11-02T13:50:47Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:47Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6695fbf66b'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:47Z" level=info msg="New RS 'blue-green-demo-api-6765df48f4' is not ready to pause" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:47Z" level=info msg="skipping active service switch: New RS 'blue-green-demo-api-6765df48f4' is not fully saturated" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:47Z" level=info msg="Timed out (false) [last progress check: 2021-11-02 13:50:15 +0000 UTC - now: 2021-11-02 13:50:47.200333866 +0000 UTC m=+968096.096080563]" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:47Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:47Z" level=info msg="Queueing up rollout for a progress after 567s" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:47Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api time_ms=2.847608
time="2021-11-02T13:50:48Z" level=info msg="Enqueueing parent of staging-exploitation/blue-green-demo-api-6765df48f4: Rollout staging-exploitation/blue-green-demo-api"
time="2021-11-02T13:50:48Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:48Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6695fbf66b'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:48Z" level=info msg="New RS 'blue-green-demo-api-6765df48f4' is not ready to pause" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:48Z" level=info msg="skipping active service switch: New RS 'blue-green-demo-api-6765df48f4' is not fully saturated" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:48Z" level=info msg="Timed out (false) [last progress check: 2021-11-02 13:50:15 +0000 UTC - now: 2021-11-02 13:50:48.484470083 +0000 UTC m=+968097.380216780]" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:48Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:48Z" level=info msg="Queueing up rollout for a progress after 566s" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:48Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api time_ms=2.932105
time="2021-11-02T13:50:53Z" level=info msg="Enqueueing parent of staging-exploitation/blue-green-demo-api-6765df48f4: Rollout staging-exploitation/blue-green-demo-api"
time="2021-11-02T13:50:53Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6695fbf66b'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Switched selector for service 'blue-green-demo-api' from '6695fbf66b' to '6765df48f4'" event_reason=SwitchService namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Event(v1.ObjectReference{Kind:\"Rollout\", Namespace:\"staging-exploitation\", Name:\"blue-green-demo-api\", UID:\"b1323fcb-1792-45a6-834c-83d995c115ba\", APIVersion:\"argoproj.io/v1alpha1\", ResourceVersion:\"492301458\", FieldPath:\"\"}): type: 'Normal' reason: 'SwitchService' Switched selector for service 'blue-green-demo-api' from '6695fbf66b' to '6765df48f4'"
time="2021-11-02T13:50:53Z" level=info msg="Updating active selector (6695fbf66b -> 6765df48f4)" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Rollout completed update to revision 2 (6765df48f4): Completed blue-green update" event_reason=RolloutCompleted namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Event(v1.ObjectReference{Kind:\"Rollout\", Namespace:\"staging-exploitation\", Name:\"blue-green-demo-api\", UID:\"b1323fcb-1792-45a6-834c-83d995c115ba\", APIVersion:\"argoproj.io/v1alpha1\", ResourceVersion:\"492301458\", FieldPath:\"\"}): type: 'Normal' reason: 'RolloutCompleted' Rollout completed update to revision 2 (6765df48f4): Completed blue-green update"
time="2021-11-02T13:50:53Z" level=info msg="syncing service" namespace=staging-exploitation rollout=blue-green-demo-api service=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Patched: {\"status\":{\"blueGreen\":{\"activeSelector\":\"6765df48f4\"},\"conditions\":[{\"lastTransitionTime\":\"2021-11-02T11:20:17Z\",\"lastUpdateTime\":\"2021-11-02T11:20:17Z\",\"message\":\"Rollout has minimum availability\",\"reason\":\"AvailableReason\",\"status\":\"True\",\"type\":\"Available\"},{\"lastTransitionTime\":\"2021-11-02T13:50:53Z\",\"lastUpdateTime\":\"2021-11-02T13:50:53Z\",\"message\":\"RolloutCompleted\",\"reason\":\"RolloutCompleted\",\"status\":\"True\",\"type\":\"Completed\"},{\"lastTransitionTime\":\"2021-11-02T11:19:21Z\",\"lastUpdateTime\":\"2021-11-02T13:50:53Z\",\"message\":\"ReplicaSet \\\"blue-green-demo-api-6765df48f4\\\" has successfully progressed.\",\"reason\":\"NewReplicaSetAvailable\",\"status\":\"True\",\"type\":\"Progressing\"}],\"message\":null,\"phase\":\"Healthy\",\"selector\":\"app=blue-green-demo-api,rollouts-pod-template-hash=6765df48f4\",\"stableRS\":\"6765df48f4\"}}" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="persisted to informer" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301458 rollout=blue-green-demo-api time_ms=64.94183600000001
time="2021-11-02T13:50:53Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6765df48f4'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Reconciling 1 old ReplicaSets (total pods: 5)" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Start processing" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:50:53Z" level=error msg="Failed to process: secret \"argo-rollouts-notification-secret\" not found" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api time_ms=5.382385
time="2021-11-02T13:50:53Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6765df48f4'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Reconciling 1 old ReplicaSets (total pods: 5)" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api
time="2021-11-02T13:50:53Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api time_ms=6.767347
time="2021-11-02T13:51:45Z" level=info msg="Start processing" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:51:45Z" level=error msg="Failed to process: secret \"argo-rollouts-notification-secret\" not found" resource=staging-exploitation/blue-green-demo-api
time="2021-11-02T13:51:45Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api
time="2021-11-02T13:51:45Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6765df48f4'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:51:45Z" level=info msg="Reconciling 1 old ReplicaSets (total pods: 5)" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:51:45Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api
time="2021-11-02T13:51:45Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api time_ms=8.489472
time="2021-11-02T13:52:30Z" level=info msg="syncing service" namespace=staging-exploitation rollout=blue-green-demo-api service=blue-green-demo-api
time="2021-11-02T13:52:30Z" level=info msg="Started syncing rollout" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api
time="2021-11-02T13:52:30Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6765df48f4'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:52:30Z" level=info msg="Reconciling 1 old ReplicaSets (total pods: 5)" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:52:30Z" level=info msg="No status changes. Skipping patch" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api
time="2021-11-02T13:52:30Z" level=info msg="Reconciliation completed" generation=4 namespace=staging-exploitation resourceVersion=492301991 rollout=blue-green-demo-api time_ms=9.712696999999999

Message from the maintainers:

Impacted by this bug? Give it a 👍. We prioritize the issues with the most 👍.

harikrongali commented 2 years ago

am unable to reproduce the scenario. From the logs, I dont see scale down delay set to the old replicaSet. is the service switch happening correctly and traffic is going to the new stack?

harikrongali commented 2 years ago

can you also describe old replicaSet as well?

huikang commented 2 years ago

The following lines appear repeatedly and look suspicious

time="2021-11-02T13:52:30Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6765df48f4'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:52:30Z" level=info msg="Reconciling 1 old ReplicaSets (total pods: 5)" namespace=staging-exploitation rollout=blue-green-demo-api

if the rollout still exists, could you paste the output of kubectl get rollout <rollout name> -o yaml and the kubectl get replicaset <old replicaset> -o yaml. Would like to see if the replicaset has any abnormal status. Thanks.

dpiraud commented 2 years ago

am unable to reproduce the scenario. From the logs, I dont see scale down delay set to the old replicaSet. is the service switch happening correctly and traffic is going to the new stack?

yes, traffic to new version is OK

image

The following lines appear repeatedly and look suspicious

time="2021-11-02T13:52:30Z" level=info msg="Reconciling stable ReplicaSet 'blue-green-demo-api-6765df48f4'" namespace=staging-exploitation rollout=blue-green-demo-api
time="2021-11-02T13:52:30Z" level=info msg="Reconciling 1 old ReplicaSets (total pods: 5)" namespace=staging-exploitation rollout=blue-green-demo-api

if the rollout still exists, could you paste the output of kubectl get rollout <rollout name> -o yaml and the kubectl get replicaset <old replicaset> -o yaml. Would like to see if the replicaset has any abnormal status. Thanks.

I have to replay it this mornnig, here are the describe without "private" part, logs looks similar

Rollout

kubectl argo rollouts get rollout blue-green-demo-api -w

Name:            blue-green-demo-api
Namespace:       staging-exploitation
Status:          ✔ Healthy
Strategy:        BlueGreen
Images:          xxx/canary-demo-api:blue
                 xxx/canary-demo-api:green (stable, active)
Replicas:
  Desired:       5
  Current:       10
  Updated:       5
  Ready:         5
  Available:     5

NAME                                             KIND        STATUS     AGE  INFO
⟳ blue-green-demo-api                            Rollout     ✔ Healthy  26m
├──# revision:2
│  └──⧉ blue-green-demo-api-6765df48f4           ReplicaSet  ✔ Healthy  21m  stable,active
│     ├──□ blue-green-demo-api-6765df48f4-hp9cf  Pod         ✔ Running  21m  ready:2/2
│     ├──□ blue-green-demo-api-6765df48f4-2qxsc  Pod         ✔ Running  21m  ready:2/2
│     ├──□ blue-green-demo-api-6765df48f4-67bqb  Pod         ✔ Running  21m  ready:2/2
│     ├──□ blue-green-demo-api-6765df48f4-5xj5j  Pod         ✔ Running  21m  ready:2/2
│     └──□ blue-green-demo-api-6765df48f4-dnrb6  Pod         ✔ Running  21m  ready:2/2
└──# revision:1
   └──⧉ blue-green-demo-api-6695fbf66b           ReplicaSet  ✔ Healthy  26m
      ├──□ blue-green-demo-api-6695fbf66b-tjrsm  Pod         ✔ Running  26m  ready:2/2
      ├──□ blue-green-demo-api-6695fbf66b-wlrkq  Pod         ✔ Running  26m  ready:2/2
      ├──□ blue-green-demo-api-6695fbf66b-7j9pn  Pod         ✔ Running  26m  ready:2/2
      ├──□ blue-green-demo-api-6695fbf66b-tfwdq  Pod         ✔ Running  26m  ready:2/2
      └──□ blue-green-demo-api-6695fbf66b-9jsbk  Pod         ✔ Running  26m  ready:2/2
kubectl get rollout blue-green-demo-api -o yaml

apiVersion: argoproj.io/v1alpha1
kind: Rollout
metadata:
  annotations:
    kubectl.kubernetes.io/last-applied-configuration: ...
    rollout.argoproj.io/revision: "2"
  creationTimestamp: "2021-11-03T08:25:31Z"
  generation: 4
  name: blue-green-demo-api
  namespace: staging-exploitation
  resourceVersion: "493003247"
  uid: 208364ff-0004-49fe-b8b6-13934713fbd5
spec:
  replicas: 5
  selector:
    matchLabels:
      app: blue-green-demo-api
  strategy:
    blueGreen:
      activeService: blue-green-demo-api
      autoPromotionEnabled: true
      scaleDownDelaySeconds: 10
  template:
    ...
status:
  HPAReplicas: 5
  availableReplicas: 5
  blueGreen:
    activeSelector: 6765df48f4
  canary: {}
  conditions:
  - lastTransitionTime: "2021-11-03T08:26:17Z"
    lastUpdateTime: "2021-11-03T08:26:17Z"
    message: Rollout has minimum availability
    reason: AvailableReason
    status: "True"
    type: Available
  - lastTransitionTime: "2021-11-03T08:31:22Z"
    lastUpdateTime: "2021-11-03T08:31:22Z"
    message: RolloutCompleted
    reason: RolloutCompleted
    status: "True"
    type: Completed
  - lastTransitionTime: "2021-11-03T08:25:31Z"
    lastUpdateTime: "2021-11-03T08:31:22Z"
    message: ReplicaSet "blue-green-demo-api-6765df48f4" has successfully progressed.
    reason: NewReplicaSetAvailable
    status: "True"
    type: Progressing
  currentPodHash: 6765df48f4
  observedGeneration: "4"
  phase: Healthy
  readyReplicas: 5
  replicas: 10
  selector: app=blue-green-demo-api,rollouts-pod-template-hash=6765df48f4
  stableRS: 6765df48f4
  updatedReplicas: 5

Old RS

kubectl get replicaset blue-green-demo-api-6695fbf66b -o yaml

apiVersion: apps/v1
kind: ReplicaSet
metadata:
  annotations:
    rollout.argoproj.io/desired-replicas: "5"
    rollout.argoproj.io/revision: "1"
  creationTimestamp: "2021-11-03T08:25:31Z"
  generation: 2
  labels:
    rollouts-pod-template-hash: 6695fbf66b
  name: blue-green-demo-api-6695fbf66b
  namespace: staging-exploitation
  ownerReferences:
  - apiVersion: argoproj.io/v1alpha1
    blockOwnerDeletion: true
    controller: true
    kind: Rollout
    name: blue-green-demo-api
    uid: 208364ff-0004-49fe-b8b6-13934713fbd5
  resourceVersion: "492999801"
  uid: 7483d383-fa3e-491b-beb7-072f74908468
spec:
  replicas: 5
  selector:
    matchLabels:
      app: blue-green-demo-api
      rollouts-pod-template-hash: 6695fbf66b
  template:
    ...
status:
  availableReplicas: 5
  fullyLabeledReplicas: 5
  observedGeneration: 2
  readyReplicas: 5
  replicas: 5

New RS

kubectl get replicaset blue-green-demo-api-6765df48f4 -o yaml

apiVersion: apps/v1
kind: ReplicaSet
metadata:
  annotations:
    rollout.argoproj.io/desired-replicas: "5"
    rollout.argoproj.io/revision: "2"
  creationTimestamp: "2021-11-03T08:30:40Z"
  generation: 2
  labels:
    rollouts-pod-template-hash: 6765df48f4
  name: blue-green-demo-api-6765df48f4
  namespace: staging-exploitation
  ownerReferences:
  - apiVersion: argoproj.io/v1alpha1
    blockOwnerDeletion: true
    controller: true
    kind: Rollout
    name: blue-green-demo-api
    uid: 208364ff-0004-49fe-b8b6-13934713fbd5
  resourceVersion: "493003244"
  uid: aa8645b7-c48e-498b-9cb0-8fa20cb0a661
spec:
  replicas: 5
  selector:
    matchLabels:
      app: blue-green-demo-api
      rollouts-pod-template-hash: 6765df48f4
  template:
    ...
status:
  availableReplicas: 5
  fullyLabeledReplicas: 5
  observedGeneration: 2
  readyReplicas: 5
  replicas: 5

EDIT I just add the log to this comment. Looking closely in it, i found lines like

...
time="2021-11-03T08:12:59Z" level=error msg="rollout syncHandler error: Operation cannot be fulfilled on replicasets.apps \"blue-green-demo-api-6695fbf66b\": the object has been modified; please apply your changes to the latest version and try again" namespace=staging-exploitation rollout=blue-green-demo-api
...
E1103 08:12:59.297637       1 controller.go:174] Operation cannot be fulfilled on replicasets.apps "blue-green-demo-api-6695fbf66b": the object has been modified; please apply your changes to the latest version and try again
...

Could it be the problem?

log.txt

huikang commented 2 years ago

@dpiraud , those logs definitely provide some clue about this issue, which indicates the controller can't add the scaledown annotation to the old RS due to some interruption. Since this problem seems reproducible in your setup, I am wondering if you could try a simple b/g rollout like in https://argoproj.github.io/argo-rollouts/features/bluegreen/.

BTW, I really like your traffic monitoring dashboard (https://user-images.githubusercontent.com/19174502/140032466-3e80b331-569b-44b5-aeee-93b524f7c372.png). Could you let me know how you generate the data? Thanks.

dpiraud commented 2 years ago

hi @huikang

I can't run this example "out of the box" on our platform but i think my demo is very very close to this example. I'll dig around this log with our k8s provider and keep you inform if I found the problem

Thx for the dashboard, simple => My API log each call with the "color" of the version. Log goes in elastic search with a grafana on top of it. I use "vegeta" to generate traffic

dpiraud commented 2 years ago

Hi all

After diging with our k8s provider, we found that the argo rollout user was not allowed to patch/delete replicaset.

The error above (Operation cannot be fulfilled...) wasn't part of out problem as it remains after fixing the authorizations.

Could-it be a good idea to catch and log this error on missing authorizations ?

No bug => I close this issue

BR