Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

AnalysisRun gets stuck in Running state for dryrun + successful job metric #2151

Closed
2 tasks done
chrisplim opened this issue Jul 19, 2022 · 9 comments
Closed
2 tasks done

AnalysisRun gets stuck in Running state for dryrun + successful job metric #2151

chrisplim opened this issue Jul 19, 2022 · 9 comments
Assignees
@agrawroh
Labels
bug Something isn't working
Milestone
v1.4

Comments

@chrisplim
Copy link

Checklist:

  • I've included steps to reproduce the bug.
  • I've inclued the version of argo rollouts.

Describe the bug

AnalysisRun gets stuck in Running state if the metric is listed as a dryrun and is a Job that completes Successfully with exit code 0.

To Reproduce

  1. Apply this manifests file: https://gist.github.com/chrisplim/c864a22a5ea7ba788a6a86ca13e54807 
    kubectl apply -f dryrun-manifests.yaml
  2. Get/watch the rollout status 
    kubectl argo rollouts get rollout dryrun-rollout --watch
  3. In a separate terminal, update the rollout's pod's image to cause a rollout 
    kubectl argo rollouts set image dryrun-rollout helloworld=hashicorp/http-echo:0.2.3
  4. Notice the AnalysisRun's Job completes successfully with exit code 0, but the AnalysisRun never transitions from the Running state to Successful

Expected behavior

The AnalysisRun should transition to the Successful state after a Job completes successfully with exit code 0, even though the metric was listed as a dryRun.

Note: We can verify that the dryrun with a failed job works as expected, which is to transition the AnalysisRun to be Successful, despite the Job failing.
steps:

  1. Use the same dryrun-manifests.yaml file, except editing the rollout's spec.strategy.blueGreen.prePromotionAnalysis.templates[0].templateName to be dryrun-analysis-failure
  2. kubectl apply -f dryrun-manifests.yaml
  3. Change the rollout image to force a rollout 
    kubectl argo rollouts set image dryrun-rollout helloworld=hashicorp/http-echo:0.2.3
  4. Notice that a failed job + dryrun metric works as intended.

Screen Shot 2022-07-19 at 12 44 07 PM

Screenshots

Screenshot showing the job completed successfully, but AnalysisRun gets stuck in Running state
(the output of kubectl argo rollouts get rollout dryrun-rollout --watch)
Screen Shot 2022-07-19 at 12 22 52 PM

Screenshot showing output of kubectl get pods
Screen Shot 2022-07-19 at 12 23 19 PM
08f-ee71755d698d.png">

Screenshot showing output of kubectl describe pod 25d8853f-6d87-4358-83a7-44d8bf6238f6.test.1-vvqng
Screen Shot 2022-07-19 at 12 23 49 PM

Version

kubectl argo rollouts version
kubectl-argo-rollouts: v1.2.0+08cf10e
  BuildDate: 2022-03-22T00:27:37Z
  GitCommit: 08cf10e554fe99c24c8a37ad07fadd9318e4c8a1
  GitTreeState: clean
  GoVersion: go1.17.6
  Compiler: gc
  Platform: darwin/amd64

Logs

# Logs for dryrun-rollout
kubectl logs -n argo-rollouts deployment/argo-rollouts | grep rollout=dryrun-rollout

time="2022-07-19T19:12:05Z" level=info msg="Started syncing rollout" generation=1 namespace=default resourceVersion=23640231 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Updating replica set 'dryrun-rollout-5f57fbc894' revision from 0 to 1" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Created ReplicaSet dryrun-rollout-5f57fbc894" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Rollout updated to revision 1" event_reason=RolloutUpdated namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Created ReplicaSet dryrun-rollout-5f57fbc894 (revision 1)" event_reason=NewReplicaSetCreated namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Set rollout condition: &RolloutCondition{Type:Progressing,Status:True,LastUpdateTime:2022-07-19 19:12:05.567367455 +0000 UTC m=+45074.667334877,LastTransitionTime:2022-07-19 19:12:05.567367532 +0000 UTC m=+45074.667334949,Reason:NewReplicaSetCreated,Message:Created new replica set \"dryrun-rollout-5f57fbc894\",}" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Switched selector for service 'dryrun-service-preview' from '' to '5f57fbc894'" event_reason=SwitchService namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="syncing service" namespace=default rollout=dryrun-rollout service=dryrun-service-preview
time="2022-07-19T19:12:05Z" level=info msg="persisted to informer" generation=2 namespace=default resourceVersion=23640237 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=error msg="roCtx.reconcile err Operation cannot be fulfilled on replicasets.apps \"dryrun-rollout-5f57fbc894\": the object has been modified; please apply your changes to the latest version and try again" generation=1 namespace=default resourceVersion=23640231 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Reconciliation completed" generation=1 namespace=default resourceVersion=23640231 rollout=dryrun-rollout time_ms=94.40836599999999
time="2022-07-19T19:12:05Z" level=error msg="rollout syncHandler error: Operation cannot be fulfilled on replicasets.apps \"dryrun-rollout-5f57fbc894\": the object has been modified; please apply your changes to the latest version and try again" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="rollout syncHandler queue retries: 7 : key \"default/dryrun-rollout\"" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Started syncing rollout" generation=2 namespace=default resourceVersion=23640237 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Scaled up ReplicaSet dryrun-rollout-5f57fbc894 (revision 1) from 0 to 1" event_reason=ScalingReplicaSet namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="New RS 'dryrun-rollout-5f57fbc894' is not ready to pause" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="skipping active service switch: New RS 'dryrun-rollout-5f57fbc894' is not fully saturated" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Skipping analysis: isAborted: false, promoteFull: false, rollbackToScaleDownDelay: false, initialDeploy: true" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Updating preview selector ( -> 5f57fbc894)" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Rollout completed update to revision 1 (5f57fbc894): Initial deploy" event_reason=RolloutCompleted namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Patched: {\"status\":{\"blueGreen\":{\"previewSelector\":\"5f57fbc894\"},\"conditions\":[{\"lastTransitionTime\":\"2022-07-19T19:12:05Z\",\"lastUpdateTime\":\"2022-07-19T19:12:05Z\",\"message\":\"ReplicaSet \\\"dryrun-rollout-5f57fbc894\\\" is progressing.\",\"reason\":\"ReplicaSetUpdated\",\"status\":\"True\",\"type\":\"Progressing\"},{\"lastTransitionTime\":\"2022-07-19T19:12:05Z\",\"lastUpdateTime\":\"2022-07-19T19:12:05Z\",\"message\":\"Rollout does not have minimum availability\",\"reason\":\"AvailableReason\",\"status\":\"False\",\"type\":\"Available\"}],\"currentPodHash\":\"5f57fbc894\",\"message\":\"more replicas need to be updated\",\"observedGeneration\":\"2\",\"phase\":\"Progressing\",\"selector\":\"app=dryrun\",\"stableRS\":\"5f57fbc894\"}}" generation=2 namespace=default resourceVersion=23640237 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="persisted to informer" generation=2 namespace=default resourceVersion=23640245 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Reconciliation completed" generation=2 namespace=default resourceVersion=23640237 rollout=dryrun-rollout time_ms=31.423636
time="2022-07-19T19:12:05Z" level=info msg="Started syncing rollout" generation=2 namespace=default resourceVersion=23640245 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="New RS 'dryrun-rollout-5f57fbc894' is not ready to pause" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="skipping active service switch: New RS 'dryrun-rollout-5f57fbc894' is not fully saturated" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:05 +0000 UTC - now: 2022-07-19 19:12:05.643324366 +0000 UTC m=+45074.743291785]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="No status changes. Skipping patch" generation=2 namespace=default resourceVersion=23640245 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Queueing up rollout for a progress after 599s" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Reconciliation completed" generation=2 namespace=default resourceVersion=23640245 rollout=dryrun-rollout time_ms=2.0179310000000004
time="2022-07-19T19:12:05Z" level=info msg="Started syncing rollout" generation=2 namespace=default resourceVersion=23640245 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="New RS 'dryrun-rollout-5f57fbc894' is not ready to pause" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="skipping active service switch: New RS 'dryrun-rollout-5f57fbc894' is not fully saturated" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:05 +0000 UTC - now: 2022-07-19 19:12:05.648858074 +0000 UTC m=+45074.748825499]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="No status changes. Skipping patch" generation=2 namespace=default resourceVersion=23640245 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Queueing up rollout for a progress after 599s" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Reconciliation completed" generation=2 namespace=default resourceVersion=23640245 rollout=dryrun-rollout time_ms=1.301829
time="2022-07-19T19:12:05Z" level=info msg="Started syncing rollout" generation=2 namespace=default resourceVersion=23640245 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="New RS 'dryrun-rollout-5f57fbc894' is not ready to pause" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="skipping active service switch: New RS 'dryrun-rollout-5f57fbc894' is not fully saturated" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Patched: {\"status\":{\"HPAReplicas\":1,\"conditions\":[{\"lastTransitionTime\":\"2022-07-19T19:12:05Z\",\"lastUpdateTime\":\"2022-07-19T19:12:05Z\",\"message\":\"Rollout does not have minimum availability\",\"reason\":\"AvailableReason\",\"status\":\"False\",\"type\":\"Available\"},{\"lastTransitionTime\":\"2022-07-19T19:12:05Z\",\"lastUpdateTime\":\"2022-07-19T19:12:05Z\",\"message\":\"ReplicaSet \\\"dryrun-rollout-5f57fbc894\\\" is progressing.\",\"reason\":\"ReplicaSetUpdated\",\"status\":\"True\",\"type\":\"Progressing\"}],\"message\":\"updated replicas are still becoming available\",\"replicas\":1,\"updatedReplicas\":1}}" generation=2 namespace=default resourceVersion=23640245 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="persisted to informer" generation=2 namespace=default resourceVersion=23640251 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Reconciliation completed" generation=2 namespace=default resourceVersion=23640245 rollout=dryrun-rollout time_ms=26.952251
time="2022-07-19T19:12:05Z" level=info msg="Started syncing rollout" generation=2 namespace=default resourceVersion=23640251 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="New RS 'dryrun-rollout-5f57fbc894' is not ready to pause" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="skipping active service switch: New RS 'dryrun-rollout-5f57fbc894' is not fully saturated" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:05 +0000 UTC - now: 2022-07-19 19:12:05.68195878 +0000 UTC m=+45074.781926206]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="No status changes. Skipping patch" generation=2 namespace=default resourceVersion=23640251 rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Queueing up rollout for a progress after 599s" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:05Z" level=info msg="Reconciliation completed" generation=2 namespace=default resourceVersion=23640251 rollout=dryrun-rollout time_ms=1.1998620000000002
time="2022-07-19T19:12:08Z" level=info msg="Started syncing rollout" generation=2 namespace=default resourceVersion=23640251 rollout=dryrun-rollout
time="2022-07-19T19:12:08Z" level=info msg="Switched selector for service 'dryrun-service' from '' to '5f57fbc894'" event_reason=SwitchService namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:08Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:08Z" level=info msg="syncing service" namespace=default rollout=dryrun-rollout service=dryrun-service
time="2022-07-19T19:12:08Z" level=info msg="Updating active selector ( -> 5f57fbc894)" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:08Z" level=info msg="Patched: {\"status\":{\"availableReplicas\":1,\"blueGreen\":{\"activeSelector\":\"5f57fbc894\"},\"conditions\":[{\"lastTransitionTime\":\"2022-07-19T19:12:08Z\",\"lastUpdateTime\":\"2022-07-19T19:12:08Z\",\"message\":\"RolloutCompleted\",\"reason\":\"RolloutCompleted\",\"status\":\"True\",\"type\":\"Completed\"},{\"lastTransitionTime\":\"2022-07-19T19:12:05Z\",\"lastUpdateTime\":\"2022-07-19T19:12:08Z\",\"message\":\"ReplicaSet \\\"dryrun-rollout-5f57fbc894\\\" has successfully progressed.\",\"reason\":\"NewReplicaSetAvailable\",\"status\":\"True\",\"type\":\"Progressing\"},{\"lastTransitionTime\":\"2022-07-19T19:12:08Z\",\"lastUpdateTime\":\"2022-07-19T19:12:08Z\",\"message\":\"Rollout has minimum availability\",\"reason\":\"AvailableReason\",\"status\":\"True\",\"type\":\"Available\"}],\"message\":null,\"phase\":\"Healthy\",\"readyReplicas\":1,\"selector\":\"app=dryrun,rollouts-pod-template-hash=5f57fbc894\"}}" generation=2 namespace=default resourceVersion=23640251 rollout=dryrun-rollout
time="2022-07-19T19:12:08Z" level=info msg="persisted to informer" generation=2 namespace=default resourceVersion=23640266 rollout=dryrun-rollout
time="2022-07-19T19:12:08Z" level=info msg="Reconciliation completed" generation=2 namespace=default resourceVersion=23640251 rollout=dryrun-rollout time_ms=70.418442
time="2022-07-19T19:12:08Z" level=info msg="Started syncing rollout" generation=2 namespace=default resourceVersion=23640266 rollout=dryrun-rollout
time="2022-07-19T19:12:08Z" level=info msg="Reconciling stable ReplicaSet 'dryrun-rollout-5f57fbc894'" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:08Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:08Z" level=info msg="No status changes. Skipping patch" generation=2 namespace=default resourceVersion=23640266 rollout=dryrun-rollout
time="2022-07-19T19:12:08Z" level=info msg="Reconciliation completed" generation=2 namespace=default resourceVersion=23640266 rollout=dryrun-rollout time_ms=3.740075
time="2022-07-19T19:12:16Z" level=info msg="Started syncing rollout" generation=3 namespace=default resourceVersion=23640273 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Updating replica set 'dryrun-rollout-b9f5d4588' revision from 0 to 2" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Created ReplicaSet dryrun-rollout-b9f5d4588" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Rollout updated to revision 2" event_reason=RolloutUpdated namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Created ReplicaSet dryrun-rollout-b9f5d4588 (revision 2)" event_reason=NewReplicaSetCreated namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Set rollout condition: &RolloutCondition{Type:Progressing,Status:True,LastUpdateTime:2022-07-19 19:12:16.409138404 +0000 UTC m=+45085.509105833,LastTransitionTime:2022-07-19 19:12:16.409138483 +0000 UTC m=+45085.509105907,Reason:NewReplicaSetCreated,Message:Created new replica set \"dryrun-rollout-b9f5d4588\",}" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Switched selector for service 'dryrun-service-preview' from '5f57fbc894' to 'b9f5d4588'" event_reason=SwitchService namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="syncing service" namespace=default rollout=dryrun-rollout service=dryrun-service-preview
time="2022-07-19T19:12:16Z" level=info msg="Pod template change detected (new: b9f5d4588, old: 5f57fbc894)" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Pod template change detected (new: b9f5d4588, old: 5f57fbc894)" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Updating preview selector (5f57fbc894 -> b9f5d4588)" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Patched: {\"status\":{\"blueGreen\":{\"previewSelector\":\"b9f5d4588\"},\"conditions\":[{\"lastTransitionTime\":\"2022-07-19T19:12:08Z\",\"lastUpdateTime\":\"2022-07-19T19:12:08Z\",\"message\":\"Rollout has minimum availability\",\"reason\":\"AvailableReason\",\"status\":\"True\",\"type\":\"Available\"},{\"lastTransitionTime\":\"2022-07-19T19:12:16Z\",\"lastUpdateTime\":\"2022-07-19T19:12:16Z\",\"message\":\"RolloutCompleted\",\"reason\":\"RolloutCompleted\",\"status\":\"False\",\"type\":\"Completed\"},{\"lastTransitionTime\":\"2022-07-19T19:12:05Z\",\"lastUpdateTime\":\"2022-07-19T19:12:16Z\",\"message\":\"ReplicaSet \\\"dryrun-rollout-b9f5d4588\\\" is progressing.\",\"reason\":\"ReplicaSetUpdated\",\"status\":\"True\",\"type\":\"Progressing\"}],\"currentPodHash\":\"b9f5d4588\",\"message\":\"more replicas need to be updated\",\"observedGeneration\":\"3\",\"phase\":\"Progressing\",\"updatedReplicas\":null}}" generation=3 namespace=default resourceVersion=23640279 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="persisted to informer" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciliation completed" generation=3 namespace=default resourceVersion=23640273 rollout=dryrun-rollout time_ms=95.208225
time="2022-07-19T19:12:16Z" level=info msg="Started syncing rollout" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciling stable ReplicaSet 'dryrun-rollout-5f57fbc894'" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Scaled up ReplicaSet dryrun-rollout-b9f5d4588 (revision 2) from 0 to 1" event_reason=ScalingReplicaSet namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="New RS 'dryrun-rollout-b9f5d4588' is not ready to pause" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="skipping active service switch: New RS 'dryrun-rollout-b9f5d4588' is not fully saturated" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:16 +0000 UTC - now: 2022-07-19 19:12:16.474770411 +0000 UTC m=+45085.574737828]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="No status changes. Skipping patch" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Queueing up rollout for a progress after 599s" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciliation completed" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout time_ms=12.333645
time="2022-07-19T19:12:16Z" level=info msg="Started syncing rollout" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciling stable ReplicaSet 'dryrun-rollout-5f57fbc894'" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="New RS 'dryrun-rollout-b9f5d4588' is not ready to pause" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="skipping active service switch: New RS 'dryrun-rollout-b9f5d4588' is not fully saturated" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:16 +0000 UTC - now: 2022-07-19 19:12:16.478164995 +0000 UTC m=+45085.578132412]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="No status changes. Skipping patch" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Queueing up rollout for a progress after 599s" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciliation completed" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout time_ms=3.893173
time="2022-07-19T19:12:16Z" level=info msg="Started syncing rollout" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciling stable ReplicaSet 'dryrun-rollout-5f57fbc894'" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="New RS 'dryrun-rollout-b9f5d4588' is not ready to pause" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="skipping active service switch: New RS 'dryrun-rollout-b9f5d4588' is not fully saturated" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:16 +0000 UTC - now: 2022-07-19 19:12:16.481935119 +0000 UTC m=+45085.581902537]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="No status changes. Skipping patch" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Queueing up rollout for a progress after 599s" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciliation completed" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout time_ms=4.3684270000000005
time="2022-07-19T19:12:16Z" level=info msg="Started syncing rollout" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciling stable ReplicaSet 'dryrun-rollout-5f57fbc894'" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="New RS 'dryrun-rollout-b9f5d4588' is not ready to pause" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="skipping active service switch: New RS 'dryrun-rollout-b9f5d4588' is not fully saturated" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:16 +0000 UTC - now: 2022-07-19 19:12:16.497232458 +0000 UTC m=+45085.597199880]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="No status changes. Skipping patch" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Queueing up rollout for a progress after 599s" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciliation completed" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout time_ms=2.1736400000000002
time="2022-07-19T19:12:16Z" level=info msg="Started syncing rollout" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciling stable ReplicaSet 'dryrun-rollout-5f57fbc894'" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="New RS 'dryrun-rollout-b9f5d4588' is not ready to pause" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="skipping active service switch: New RS 'dryrun-rollout-b9f5d4588' is not fully saturated" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Patched: {\"status\":{\"message\":\"active service cutover pending\",\"replicas\":2,\"updatedReplicas\":1}}" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="persisted to informer" generation=3 namespace=default resourceVersion=23640294 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciliation completed" generation=3 namespace=default resourceVersion=23640284 rollout=dryrun-rollout time_ms=27.02344
time="2022-07-19T19:12:16Z" level=info msg="Started syncing rollout" generation=3 namespace=default resourceVersion=23640294 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciling stable ReplicaSet 'dryrun-rollout-5f57fbc894'" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="New RS 'dryrun-rollout-b9f5d4588' is not ready to pause" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="skipping active service switch: New RS 'dryrun-rollout-b9f5d4588' is not fully saturated" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:16 +0000 UTC - now: 2022-07-19 19:12:16.54173165 +0000 UTC m=+45085.641699071]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="No status changes. Skipping patch" generation=3 namespace=default resourceVersion=23640294 rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Queueing up rollout for a progress after 599s" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:16Z" level=info msg="Reconciliation completed" generation=3 namespace=default resourceVersion=23640294 rollout=dryrun-rollout time_ms=5.536072000000001
time="2022-07-19T19:12:18Z" level=info msg="Started syncing rollout" generation=3 namespace=default resourceVersion=23640294 rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciling stable ReplicaSet 'dryrun-rollout-5f57fbc894'" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Created Pre Promotion AnalysisRun" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:16 +0000 UTC - now: 2022-07-19 19:12:18.24264194 +0000 UTC m=+45087.342609361]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Patched: {\"status\":{\"blueGreen\":{\"prePromotionAnalysisRunStatus\":{\"name\":\"dryrun-rollout-b9f5d4588-2-pre\",\"status\":\"\"}}}}" generation=3 namespace=default resourceVersion=23640294 rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="persisted to informer" generation=3 namespace=default resourceVersion=23640305 rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciliation completed" generation=3 namespace=default resourceVersion=23640294 rollout=dryrun-rollout time_ms=32.181322
time="2022-07-19T19:12:18Z" level=info msg="Started syncing rollout" generation=3 namespace=default resourceVersion=23640305 rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciling stable ReplicaSet 'dryrun-rollout-5f57fbc894'" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:16 +0000 UTC - now: 2022-07-19 19:12:18.264563906 +0000 UTC m=+45087.364531324]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="No status changes. Skipping patch" generation=3 namespace=default resourceVersion=23640305 rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Queueing up rollout for a progress after 597s" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciliation completed" generation=3 namespace=default resourceVersion=23640305 rollout=dryrun-rollout time_ms=1.832558
time="2022-07-19T19:12:18Z" level=info msg="Started syncing rollout" generation=3 namespace=default resourceVersion=23640305 rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciling stable ReplicaSet 'dryrun-rollout-5f57fbc894'" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:16 +0000 UTC - now: 2022-07-19 19:12:18.26666357 +0000 UTC m=+45087.366630988]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="No status changes. Skipping patch" generation=3 namespace=default resourceVersion=23640305 rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Queueing up rollout for a progress after 597s" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciliation completed" generation=3 namespace=default resourceVersion=23640305 rollout=dryrun-rollout time_ms=1.9405270000000001
time="2022-07-19T19:12:18Z" level=info msg="Started syncing rollout" generation=3 namespace=default resourceVersion=23640305 rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciling stable ReplicaSet 'dryrun-rollout-5f57fbc894'" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="PrePromotion Analysis Run 'dryrun-rollout-b9f5d4588-2-pre' Status New: 'Running' Previous: ''" event_reason=AnalysisRunRunning namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:16 +0000 UTC - now: 2022-07-19 19:12:18.295822807 +0000 UTC m=+45087.395790225]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Patched: {\"status\":{\"blueGreen\":{\"prePromotionAnalysisRunStatus\":{\"status\":\"Running\"}}}}" generation=3 namespace=default resourceVersion=23640305 rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="persisted to informer" generation=3 namespace=default resourceVersion=23640314 rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciliation completed" generation=3 namespace=default resourceVersion=23640305 rollout=dryrun-rollout time_ms=22.398578
time="2022-07-19T19:12:18Z" level=info msg="Started syncing rollout" generation=3 namespace=default resourceVersion=23640314 rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciling stable ReplicaSet 'dryrun-rollout-5f57fbc894'" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciling Pre Promotion Analysis" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Timed out (false) [last progress check: 2022-07-19 19:12:16 +0000 UTC - now: 2022-07-19 19:12:18.318326094 +0000 UTC m=+45087.418293516]" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="No status changes. Skipping patch" generation=3 namespace=default resourceVersion=23640314 rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Queueing up rollout for a progress after 597s" namespace=default rollout=dryrun-rollout
time="2022-07-19T19:12:18Z" level=info msg="Reconciliation completed" generation=3 namespace=default resourceVersion=23640314 rollout=dryrun-rollout time_ms=1.703449

Message from the maintainers:

Impacted by this bug? Give it a 👍. We prioritize the issues with the most 👍.
@chrisplim chrisplim added the bug Something isn't working label Jul 19, 2022
@harikrongali
Copy link
Contributor

@agrawroh can you check the above usecase?

@agrawroh
Copy link
Member

agrawroh commented Sep 4, 2022 •
edited
Loading

Sorry for the delayed response. This definitely looks like a bug. I'll try to repro on my end and would open a fix PR.

@chrisplim Could you please share the output of the AnalysisRun? I am curious to see the state of the measurements in this case.

@chrisplim
Copy link
Author

chrisplim commented Sep 5, 2022 •
edited
Loading

@agrawroh
Here's the output of the analysisrun
I ran: kubectl logs -n argo-rollouts deployment/argo-rollouts | grep analysisrun=

AnalysisRun output 
time="2022-09-05T00:51:00Z" level=info msg="Started syncing Analysis at (2022-09-05 00:51:00.337436032 +0000 UTC m=+236440.858005604)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T00:51:00Z" level=info msg="Created Pre Promotion AnalysisRun" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default rollout=dryrun-rollout
time="2022-09-05T00:51:00Z" level=info msg="Running initial measurement" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-09-05T00:51:00Z" level=info msg="Taking 1 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T00:51:00Z" level=info msg="job default/28a63bb7-5451-4a40-88ef-dcd8ea7b1de6.test.1 created" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-09-05T00:51:00Z" level=info msg="Patch status successfully" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T00:51:00Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=48.235609
time="2022-09-05T00:51:00Z" level=info msg="Started syncing Analysis at (2022-09-05 00:51:00.391266402 +0000 UTC m=+236440.911835976)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T00:51:00Z" level=info msg="Resuming in-progress measurement" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-09-05T00:51:00Z" level=info msg="Taking 1 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T00:51:00Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T00:51:00Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=13.012336
time="2022-09-05T00:51:09Z" level=info msg="Started syncing Analysis at (2022-09-05 00:51:09.465326012 +0000 UTC m=+236449.985895586)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T00:51:09Z" level=info msg="Resuming in-progress measurement" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-09-05T00:51:09Z" level=info msg="Taking 1 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T00:51:09Z" level=info msg="job default/28a63bb7-5451-4a40-88ef-dcd8ea7b1de6.test.1 completed: Successful" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-09-05T00:51:09Z" level=info msg="Measurement Completed. Result: Successful" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-09-05T00:51:09Z" level=info msg="Metric 'test' transitioned from Running -> Successful" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-09-05T00:51:09Z" level=info msg="Metric 'test' Completed. Result: Successful" analysisrun=dryrun-rollout-b9f5d4588-2-pre event_reason=MetricSuccessful namespace=default
time="2022-09-05T00:51:09Z" level=info msg="Patch status successfully" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T00:51:09Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=26.983186
time="2022-09-05T00:51:09Z" level=info msg="Started syncing Analysis at (2022-09-05 00:51:09.492820571 +0000 UTC m=+236450.013390148)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T00:51:09Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T00:51:09Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T00:51:09Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=0.972469
time="2022-09-05T01:02:44Z" level=info msg="Started syncing Analysis at (2022-09-05 01:02:44.251526601 +0000 UTC m=+237145.279348315)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T01:02:44Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T01:02:44Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T01:02:44Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=1.3166790000000002
time="2022-09-05T01:03:35Z" level=info msg="Started syncing Analysis at (2022-09-05 01:03:35.584605045 +0000 UTC m=+237196.656628869)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T01:03:35Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T01:03:35Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T01:03:35Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=0.639703
time="2022-09-05T01:03:40Z" level=info msg="Started syncing Analysis at (2022-09-05 01:03:40.653465669 +0000 UTC m=+237201.725489505)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T01:03:40Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T01:03:40Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T01:03:40Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=0.907701
time="2022-09-05T01:04:32Z" level=info msg="Started syncing Analysis at (2022-09-05 01:04:32.676467464 +0000 UTC m=+237253.792444331)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T01:04:32Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T01:04:32Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-09-05T01:04:32Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=2.20075

@agrawroh
Copy link
Member

agrawroh commented Sep 5, 2022

@agrawroh

Here's the output of the analysisrun

I ran: kubectl logs -n argo-rollouts deployment/argo-rollouts | grep analysisrun=

AnalysisRun output 

time="2022-09-05T00:51:00Z" level=info msg="Started syncing Analysis at (2022-09-05 00:51:00.337436032 +0000 UTC m=+236440.858005604)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T00:51:00Z" level=info msg="Created Pre Promotion AnalysisRun" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default rollout=dryrun-rollout

time="2022-09-05T00:51:00Z" level=info msg="Running initial measurement" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default

time="2022-09-05T00:51:00Z" level=info msg="Taking 1 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T00:51:00Z" level=info msg="job default/28a63bb7-5451-4a40-88ef-dcd8ea7b1de6.test.1 created" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default

time="2022-09-05T00:51:00Z" level=info msg="Patch status successfully" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T00:51:00Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=48.235609

time="2022-09-05T00:51:00Z" level=info msg="Started syncing Analysis at (2022-09-05 00:51:00.391266402 +0000 UTC m=+236440.911835976)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T00:51:00Z" level=info msg="Resuming in-progress measurement" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default

time="2022-09-05T00:51:00Z" level=info msg="Taking 1 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T00:51:00Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T00:51:00Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=13.012336

time="2022-09-05T00:51:09Z" level=info msg="Started syncing Analysis at (2022-09-05 00:51:09.465326012 +0000 UTC m=+236449.985895586)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T00:51:09Z" level=info msg="Resuming in-progress measurement" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default

time="2022-09-05T00:51:09Z" level=info msg="Taking 1 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T00:51:09Z" level=info msg="job default/28a63bb7-5451-4a40-88ef-dcd8ea7b1de6.test.1 completed: Successful" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default

time="2022-09-05T00:51:09Z" level=info msg="Measurement Completed. Result: Successful" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default

time="2022-09-05T00:51:09Z" level=info msg="Metric 'test' transitioned from Running -> Successful" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default

time="2022-09-05T00:51:09Z" level=info msg="Metric 'test' Completed. Result: Successful" analysisrun=dryrun-rollout-b9f5d4588-2-pre event_reason=MetricSuccessful namespace=default

time="2022-09-05T00:51:09Z" level=info msg="Patch status successfully" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T00:51:09Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=26.983186

time="2022-09-05T00:51:09Z" level=info msg="Started syncing Analysis at (2022-09-05 00:51:09.492820571 +0000 UTC m=+236450.013390148)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T00:51:09Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T00:51:09Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T00:51:09Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=0.972469

time="2022-09-05T01:02:44Z" level=info msg="Started syncing Analysis at (2022-09-05 01:02:44.251526601 +0000 UTC m=+237145.279348315)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T01:02:44Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T01:02:44Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T01:02:44Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=1.3166790000000002

time="2022-09-05T01:03:35Z" level=info msg="Started syncing Analysis at (2022-09-05 01:03:35.584605045 +0000 UTC m=+237196.656628869)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T01:03:35Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T01:03:35Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T01:03:35Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=0.639703

time="2022-09-05T01:03:40Z" level=info msg="Started syncing Analysis at (2022-09-05 01:03:40.653465669 +0000 UTC m=+237201.725489505)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T01:03:40Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T01:03:40Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T01:03:40Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=0.907701

time="2022-09-05T01:04:32Z" level=info msg="Started syncing Analysis at (2022-09-05 01:04:32.676467464 +0000 UTC m=+237253.792444331)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T01:04:32Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T01:04:32Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default

time="2022-09-05T01:04:32Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=2.20075

Thanks, @chrisplim. Could you please also do "kubectl describe ar " and then paste that screenshot? To see the latest analysis run, you can do "kubectl get ar"

@chrisplim
Copy link
Author

@agrawroh
It was a little big for my screen to do a screenshot, so i'll paste the text if that's ok

kubectl describe ar
Name:         dryrun-rollout-b9f5d4588-2-pre
Namespace:    default
Labels:       rollout-type=PrePromotion
              rollouts-pod-template-hash=b9f5d4588
Annotations:  rollout.argoproj.io/revision: 2
API Version:  argoproj.io/v1alpha1
Kind:         AnalysisRun
Metadata:
  Creation Timestamp:  2022-09-05T00:51:00Z
  Generation:          3
  Managed Fields:
    API Version:  argoproj.io/v1alpha1
    Fields Type:  FieldsV1
    fieldsV1:
      f:metadata:
        f:annotations:
          .:
          f:rollout.argoproj.io/revision:
        f:labels:
          .:
          f:rollout-type:
          f:rollouts-pod-template-hash:
        f:ownerReferences:
          .:
          k:{"uid":"07e44546-4bb5-4486-ae52-b1a349fd43f7"}:
      f:spec:
        .:
        f:dryRun:
        f:metrics:
      f:status:
        .:
        f:dryRunSummary:
          .:
          f:count:
          f:successful:
        f:metricResults:
        f:phase:
        f:runSummary:
        f:startedAt:
    Manager:    Go-http-client
    Operation:  Update
    Time:       2022-09-05T00:51:09Z
  Owner References:
    API Version:           argoproj.io/v1alpha1
    Block Owner Deletion:  true
    Controller:            true
    Kind:                  Rollout
    Name:                  dryrun-rollout
    UID:                   07e44546-4bb5-4486-ae52-b1a349fd43f7
  Resource Version:        568703
  UID:                     28a63bb7-5451-4a40-88ef-dcd8ea7b1de6
Spec:
  Dry Run:
    Metric Name:  test
  Metrics:
    Name:  test
    Provider:
      Job:
        Metadata:
        Spec:
          Backoff Limit:  1
          Template:
            Metadata:
            Spec:
              Containers:
                Command:
                  /bin/sh
                  -c
                  exit 0
                Image:              alpine:latest
                Image Pull Policy:  IfNotPresent
                Name:               success
                Resources:
              Restart Policy:  Never
Status:
  Dry Run Summary:
    Count:       1
    Successful:  1
  Metric Results:
    Count:    1
    Dry Run:  true
    Measurements:
      Finished At:  2022-09-05T00:51:09Z
      Metadata:
        Job - Name:  28a63bb7-5451-4a40-88ef-dcd8ea7b1de6.test.1
      Phase:         Successful
      Started At:    2022-09-05T00:51:00Z
    Name:            test
    Phase:           Successful
    Successful:      1
  Phase:             Running
  Run Summary:
  Started At:  2022-09-05T00:51:00Z
Events:        <none>

@agrawroh agrawroh mentioned this issue Sep 5, 2022
Merged
6 tasks
@agrawroh agrawroh self-assigned this Sep 6, 2022
@chrisplim
Copy link
Author

Hi @agrawroh, I was trying to test the fix on release 1.3.0, but it seems I get the same behavior when I run through the reproducing steps in the PR description.

kubectl argo rollouts version 
kubectl-argo-rollouts: v1.3.0+93ed7a4
  BuildDate: 2022-09-19T02:51:42Z
  GitCommit: 93ed7a497b021051bf6845da90907d67c231e703
  GitTreeState: clean
  GoVersion: go1.18.6
  Compiler: gc
  Platform: darwin/amd64
kubectl describe ar 
Name:         dryrun-rollout-b9f5d4588-2-pre
Namespace:    default
Labels:       rollout-type=PrePromotion
              rollouts-pod-template-hash=b9f5d4588
Annotations:  rollout.argoproj.io/revision: 2
API Version:  argoproj.io/v1alpha1
Kind:         AnalysisRun
Metadata:
  Creation Timestamp:  2022-10-06T16:48:49Z
  Generation:          3
  Managed Fields:
    API Version:  argoproj.io/v1alpha1
    Fields Type:  FieldsV1
    fieldsV1:
      f:metadata:
        f:annotations:
          .:
          f:rollout.argoproj.io/revision:
        f:labels:
          .:
          f:rollout-type:
          f:rollouts-pod-template-hash:
        f:ownerReferences:
          .:
          k:{"uid":"11218e12-b096-4ba8-a2e9-21b74a0e6483"}:
      f:spec:
        .:
        f:dryRun:
        f:metrics:
      f:status:
        .:
        f:dryRunSummary:
          .:
          f:count:
          f:successful:
        f:metricResults:
        f:phase:
        f:runSummary:
        f:startedAt:
    Manager:    rollouts-controller
    Operation:  Update
    Time:       2022-10-06T16:48:53Z
  Owner References:
    API Version:           argoproj.io/v1alpha1
    Block Owner Deletion:  true
    Controller:            true
    Kind:                  Rollout
    Name:                  dryrun-rollout
    UID:                   11218e12-b096-4ba8-a2e9-21b74a0e6483
  Resource Version:        1186856
  UID:                     2436a162-a057-4fd3-a273-e9106a98115a
Spec:
  Dry Run:
    Metric Name:  test
  Metrics:
    Name:  test
    Provider:
      Job:
        Metadata:
        Spec:
          Backoff Limit:  1
          Template:
            Metadata:
            Spec:
              Containers:
                Command:
                  /bin/sh
                  -c
                  exit 0
                Image:              alpine:latest
                Image Pull Policy:  IfNotPresent
                Name:               success
                Resources:
              Restart Policy:  Never
Status:
  Dry Run Summary:
    Count:       1
    Successful:  1
  Metric Results:
    Count:    1
    Dry Run:  true
    Measurements:
      Finished At:  2022-10-06T16:48:53Z
      Metadata:
        Job - Name:  2436a162-a057-4fd3-a273-e9106a98115a.test.1
      Phase:         Successful
      Started At:    2022-10-06T16:48:49Z
    Name:            test
    Phase:           Successful
    Successful:      1
  Phase:             Running
  Run Summary:
  Started At:  2022-10-06T16:48:49Z
Events:
  Type    Reason            Age   From                 Message
  ----    ------            ----  ----                 -------
  Normal  MetricSuccessful  20s   rollouts-controller  Metric 'test' Completed. Result: Successful
kubectl logs -n argo-rollouts deployment/argo-rollouts | grep analysisrun= | grep "2022-10-06" 
time="2022-10-06T16:48:49Z" level=info msg="Started syncing Analysis at (2022-10-06 16:48:49.728913741 +0000 UTC m=+665.696866533)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:48:49Z" level=info msg="Created Pre Promotion AnalysisRun" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default rollout=dryrun-rollout
time="2022-10-06T16:48:49Z" level=info msg="Running initial measurement" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-10-06T16:48:49Z" level=info msg="Taking 1 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:48:49Z" level=info msg="job default/2436a162-a057-4fd3-a273-e9106a98115a.test.1 created" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-10-06T16:48:49Z" level=info msg="Patch status successfully" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:48:49Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=33.434665
time="2022-10-06T16:48:49Z" level=info msg="Started syncing Analysis at (2022-10-06 16:48:49.762668299 +0000 UTC m=+665.730621100)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:48:49Z" level=info msg="Resuming in-progress measurement" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-10-06T16:48:49Z" level=info msg="Taking 1 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:48:49Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:48:49Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=2.351646
time="2022-10-06T16:48:53Z" level=info msg="Started syncing Analysis at (2022-10-06 16:48:53.801878304 +0000 UTC m=+669.769831087)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:48:53Z" level=info msg="Resuming in-progress measurement" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-10-06T16:48:53Z" level=info msg="Taking 1 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:48:53Z" level=info msg="job default/2436a162-a057-4fd3-a273-e9106a98115a.test.1 completed: Successful" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-10-06T16:48:53Z" level=info msg="Measurement Completed. Result: Successful" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-10-06T16:48:53Z" level=info msg="Metric 'test' transitioned from Running -> Successful" analysisrun=dryrun-rollout-b9f5d4588-2-pre metric=test namespace=default
time="2022-10-06T16:48:53Z" level=info msg="Metric 'test' Completed. Result: Successful" analysisrun=dryrun-rollout-b9f5d4588-2-pre event_reason=MetricSuccessful namespace=default
time="2022-10-06T16:48:53Z" level=info msg="Patch status successfully" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:48:53Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=11.344289
time="2022-10-06T16:48:53Z" level=info msg="Started syncing Analysis at (2022-10-06 16:48:53.813911947 +0000 UTC m=+669.781864730)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:48:53Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:48:53Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:48:53Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=0.6678149999999999
time="2022-10-06T16:52:43Z" level=info msg="Started syncing Analysis at (2022-10-06 16:52:43.951149982 +0000 UTC m=+900.090883669)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:52:43Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:52:43Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:52:43Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=0.669043
time="2022-10-06T16:52:43Z" level=info msg="Started syncing Analysis at (2022-10-06 16:52:43.959848683 +0000 UTC m=+900.099582366)" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:52:43Z" level=info msg="Taking 0 Measurement(s)..." analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:52:43Z" level=info msg="No status changes. Skipping patch" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default
time="2022-10-06T16:52:43Z" level=info msg="Reconciliation completed" analysisrun=dryrun-rollout-b9f5d4588-2-pre namespace=default time_ms=0.46269

@chrisplim
Copy link
Author

Following up. It seems that the fix didn't actually get picked up in release 1.3.0 (I misread one of the commits)

@harikrongali
Copy link
Contributor

@chrisplim can you try with 1.3.1 release and confirm if still an issue?

@harikrongali harikrongali added this to the v1.4 milestone Oct 20, 2022
@chrisplim
Copy link
Author

@harikrongali Hello, it seems like the commit made it into the release-1.3 branch, but the Build job failed in the workflow https://github.com/argoproj/argo-rollouts/actions/runs/3199266846

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@agrawroh agrawroh

Labels
bug Something isn't working
Projects
None yet
Milestone
v1.4
Development

No branches or pull requests
3 participants
@chrisplim @agrawroh @harikrongali