This job view page is being replaced by Spyglass soon. Check out the new job view.
PRkarlkfi: feat: replace StatusPoller w/ StatusWatcher
ResultABORTED
Tests 0 failed / 0 succeeded
Started2022-05-04 23:51
Elapsed12m54s
Revisionca25c8a0e1d54fc5e8a8837442ff40e024a4bb36
Refs 572

No Test Failures!


Error lines from build-log.txt

... skipping 594 lines ...
I0504 23:53:50.579635   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Started" }
I0504 23:53:50.579667   17139 apply_task.go:91] apply task starting (name: "apply-0", objects: 1)
I0504 23:53:50.586606   17139 apply_task.go:222] apply task completing (name: "apply-0")
I0504 23:53:50.586655   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Finished" }
I0504 23:53:50.586677   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Started" }
I0504 23:53:50.586697   17139 prune_task.go:55] prune task starting (name: "prune-0", objects: 2)
I0504 23:53:50.586730   17139 context.go:66] Sending event: PruneEvent{ GroupName: "prune-0", Status: "Skipped", Identifier: "e2e-test-23680260_pod2__Pod", Error: "annotation prevents deletion (\"client.lifecycle.config.k8s.io/deletion\": \"detach\")" }
I0504 23:53:50.586841   17139 context.go:66] Sending event: PruneEvent{ GroupName: "prune-0", Status: "Skipped", Identifier: "e2e-test-23680260_pod1__Pod", Error: "annotation prevents deletion (\"cli-utils.sigs.k8s.io/on-remove\": \"keep\")" }
I0504 23:53:50.586897   17139 prune_task.go:74] prune task completing (name: "prune-0")
I0504 23:53:50.586906   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Finished" }
I0504 23:53:50.586928   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-set-0", Action: "Inventory", Type: "Started" }
I0504 23:53:50.586980   17139 inv_set_task.go:59] inventory set task starting (name: "inventory-set-0")
I0504 23:53:50.587049   17139 inv_set_task.go:123] inventory set task completing (name: "inventory-set-0")
I0504 23:53:50.587081   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-set-0", Action: "Inventory", Type: "Finished" }
... skipping 33 lines ...
I0504 23:53:50.636950   17139 task.go:186] wait task progress: 1/1
I0504 23:53:50.636960   17139 task.go:190] all objects reconciled or skipped (name: "wait-0")
I0504 23:53:50.636982   17139 task.go:116] wait task completing (name: "wait-0",): context canceled
I0504 23:53:50.637002   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Finished" }
I0504 23:53:50.637009   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Started" }
I0504 23:53:50.637072   17139 prune_task.go:55] prune task starting (name: "prune-0", objects: 2)
I0504 23:53:50.645775   17139 context.go:66] Sending event: PruneEvent{ GroupName: "prune-0", Status: "Skipped", Identifier: "e2e-test-23680260_pod2__Pod", Error: "annotation prevents deletion (\"client.lifecycle.config.k8s.io/deletion\": \"detach\")" }
I0504 23:53:50.655435   17139 context.go:66] Sending event: PruneEvent{ GroupName: "prune-0", Status: "Skipped", Identifier: "e2e-test-23680260_pod1__Pod", Error: "annotation prevents deletion (\"cli-utils.sigs.k8s.io/on-remove\": \"keep\")" }
I0504 23:53:50.655527   17139 prune_task.go:74] prune task completing (name: "prune-0")
I0504 23:53:50.655542   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Finished" }
I0504 23:53:50.655561   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-1", Action: "Wait", Type: "Started" }
I0504 23:53:50.655573   17139 task.go:94] wait task starting (name: "wait-1", objects: 2)
I0504 23:53:50.655583   17139 task.go:152] wait task progress: 0/2
I0504 23:53:50.655592   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-1", Status: "Skipped", Identifier: "e2e-test-23680260_pod2__Pod" }
... skipping 56 lines ...
I0504 23:53:51.014243   17139 solver.go:243] adding apply task (1 objects)
I0504 23:53:51.014250   17139 solver.go:265] adding wait task
I0504 23:53:51.014259   17139 solver.go:216] adding inventory set task
I0504 23:53:51.018139   17139 watcher_dynamic.go:78] DynamicStatusWatcher starting in namespace-scoped mode (targets: 2)
I0504 23:53:51.018208   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-add-0", Action: "Inventory", Type: "Started" }
I0504 23:53:51.018249   17139 inv_add_task.go:48] inventory add task starting (name: "inventory-add-0")
I0504 23:53:51.018878   17139 watcher_dynamic.go:325] Watch start error (blocking until CRD is added): cli-utils.example.io/Example/namespaces/: no matches for kind "Example" in group "cli-utils.example.io"
I0504 23:53:51.019033   17139 watcher_dynamic.go:452] Watch starting: apiextensions.k8s.io/CustomResourceDefinition/namespaces/
I0504 23:53:51.019107   17139 reflector.go:219] Starting reflector apiextensions.k8s.io/v1, Kind=CustomResourceDefinition (1h0m0s) from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:53:51.019123   17139 reflector.go:255] Listing and watching apiextensions.k8s.io/v1, Kind=CustomResourceDefinition from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:53:51.031371   17139 inv_add_task.go:94] inventory add task completing (name: "inventory-add-0")
I0504 23:53:51.031507   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-add-0", Action: "Inventory", Type: "Finished" }
I0504 23:53:51.031565   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Started" }
... skipping 143 lines ...
I0504 23:53:54.016106   17139 reflector.go:219] Starting reflector apiextensions.k8s.io/v1, Kind=CustomResourceDefinition (1h0m0s) from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:53:54.016184   17139 reflector.go:255] Listing and watching apiextensions.k8s.io/v1, Kind=CustomResourceDefinition from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:53:54.023621   17139 inv_add_task.go:94] inventory add task completing (name: "inventory-add-0")
I0504 23:53:54.023681   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-add-0", Action: "Inventory", Type: "Finished" }
I0504 23:53:54.023728   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Started" }
I0504 23:53:54.023769   17139 apply_task.go:91] apply task starting (name: "apply-0", objects: 2)
I0504 23:53:54.032210   17139 context.go:66] Sending event: ApplyEvent{ GroupName: "apply-0", Status: "Failed", Identifier: "_invalidexamples.cli-utils.example.io_apiextensions.k8s.io_CustomResourceDefinition", Error: "error when creating \"unstructured\": CustomResourceDefinition.apiextensions.k8s.io \"invalidexamples.cli-utils.example.io\" is invalid: [spec.versions: Invalid value: []apiextensions.CustomResourceDefinitionVersion(nil): must have exactly one version marked as storage version, status.storedVersions: Invalid value: []string(nil): must have at least one stored version]" }
I0504 23:53:54.047186   17139 apply_task.go:222] apply task completing (name: "apply-0")
I0504 23:53:54.047360   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Finished" }
I0504 23:53:54.047443   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Started" }
I0504 23:53:54.047514   17139 task.go:94] wait task starting (name: "wait-0", objects: 2)
I0504 23:53:54.047546   17139 task.go:152] wait task progress: 0/2
I0504 23:53:54.047597   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-0", Status: "Skipped", Identifier: "_invalidexamples.cli-utils.example.io_apiextensions.k8s.io_CustomResourceDefinition" }
... skipping 580 lines ...
I0504 23:54:30.117461   17139 reflector.go:219] Starting reflector /v1, Kind=Pod (1h0m0s) from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:54:30.117474   17139 reflector.go:255] Listing and watching /v1, Kind=Pod from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:54:30.127759   17139 inv_add_task.go:94] inventory add task completing (name: "inventory-add-0")
I0504 23:54:30.127812   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-add-0", Action: "Inventory", Type: "Finished" }
I0504 23:54:30.127848   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Started" }
I0504 23:54:30.127886   17139 apply_task.go:91] apply task starting (name: "apply-0", objects: 1)
I0504 23:54:30.131184   17139 context.go:66] Sending event: ApplyEvent{ GroupName: "apply-0", Status: "Skipped", Identifier: "e2e-test-75997220_pod1__Pod", Error: "dependency scheduled for delete: e2e-test-75997220_pod2__Pod" }
I0504 23:54:30.131240   17139 apply_task.go:222] apply task completing (name: "apply-0")
I0504 23:54:30.131250   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Finished" }
I0504 23:54:30.131264   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Started" }
I0504 23:54:30.131270   17139 task.go:94] wait task starting (name: "wait-0", objects: 1)
I0504 23:54:30.131276   17139 task.go:152] wait task progress: 0/1
I0504 23:54:30.131284   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-0", Status: "Skipped", Identifier: "e2e-test-75997220_pod1__Pod" }
I0504 23:54:30.131294   17139 task.go:186] wait task progress: 1/1
I0504 23:54:30.131298   17139 task.go:190] all objects reconciled or skipped (name: "wait-0")
I0504 23:54:30.131315   17139 task.go:116] wait task completing (name: "wait-0",): context canceled
I0504 23:54:30.131334   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Finished" }
I0504 23:54:30.131340   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Started" }
I0504 23:54:30.131390   17139 prune_task.go:55] prune task starting (name: "prune-0", objects: 1)
I0504 23:54:30.131422   17139 context.go:66] Sending event: PruneEvent{ GroupName: "prune-0", Status: "Skipped", Identifier: "e2e-test-75997220_pod2__Pod", Error: "dependent scheduled for apply: e2e-test-75997220_pod1__Pod" }
I0504 23:54:30.131453   17139 prune_task.go:74] prune task completing (name: "prune-0")
I0504 23:54:30.131458   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Finished" }
I0504 23:54:30.131464   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-1", Action: "Wait", Type: "Started" }
I0504 23:54:30.131469   17139 task.go:94] wait task starting (name: "wait-1", objects: 1)
I0504 23:54:30.131473   17139 task.go:152] wait task progress: 0/1
I0504 23:54:30.131478   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-1", Status: "Skipped", Identifier: "e2e-test-75997220_pod2__Pod" }
... skipping 110 lines ...
I0504 23:54:31.126390   17139 reflector.go:219] Starting reflector /v1, Kind=Pod (1h0m0s) from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:54:31.126424   17139 reflector.go:255] Listing and watching /v1, Kind=Pod from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:54:31.140115   17139 inv_add_task.go:94] inventory add task completing (name: "inventory-add-0")
I0504 23:54:31.140168   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-add-0", Action: "Inventory", Type: "Finished" }
I0504 23:54:31.140249   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Started" }
I0504 23:54:31.140307   17139 apply_task.go:91] apply task starting (name: "apply-0", objects: 1)
I0504 23:54:31.144218   17139 context.go:66] Sending event: ApplyEvent{ GroupName: "apply-0", Status: "Skipped", Identifier: "e2e-test-42003637-ns1_pod-b__Pod", Error: "dependency scheduled for delete: _e2e-test-42003637-ns1__Namespace" }
I0504 23:54:31.144340   17139 apply_task.go:222] apply task completing (name: "apply-0")
I0504 23:54:31.144373   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Finished" }
I0504 23:54:31.144401   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Started" }
I0504 23:54:31.144437   17139 task.go:94] wait task starting (name: "wait-0", objects: 1)
I0504 23:54:31.144473   17139 task.go:152] wait task progress: 0/1
I0504 23:54:31.144523   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-0", Status: "Skipped", Identifier: "e2e-test-42003637-ns1_pod-b__Pod" }
I0504 23:54:31.144563   17139 task.go:186] wait task progress: 1/1
I0504 23:54:31.144589   17139 task.go:190] all objects reconciled or skipped (name: "wait-0")
I0504 23:54:31.144651   17139 task.go:116] wait task completing (name: "wait-0",): context canceled
I0504 23:54:31.144685   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Finished" }
I0504 23:54:31.144699   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Started" }
I0504 23:54:31.144723   17139 prune_task.go:55] prune task starting (name: "prune-0", objects: 1)
I0504 23:54:31.144752   17139 context.go:66] Sending event: PruneEvent{ GroupName: "prune-0", Status: "Skipped", Identifier: "_e2e-test-42003637-ns1__Namespace", Error: "namespace still in use: e2e-test-42003637-ns1" }
I0504 23:54:31.144854   17139 prune_task.go:74] prune task completing (name: "prune-0")
I0504 23:54:31.144862   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Finished" }
I0504 23:54:31.144870   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-1", Action: "Wait", Type: "Started" }
I0504 23:54:31.144875   17139 task.go:94] wait task starting (name: "wait-1", objects: 1)
I0504 23:54:31.144880   17139 task.go:152] wait task progress: 0/1
I0504 23:54:31.144885   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-1", Status: "Skipped", Identifier: "_e2e-test-42003637-ns1__Namespace" }
... skipping 197 lines ...
I0504 23:54:40.237558   17139 task.go:94] wait task starting (name: "wait-0", objects: 1)
I0504 23:54:40.237575   17139 task.go:152] wait task progress: 0/1
I0504 23:54:40.237588   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-0", Status: "Pending", Identifier: "e2e-test-31084870_pod1__Pod" }
I0504 23:54:40.237610   17139 task.go:186] wait task progress: 0/1
I0504 23:54:40.237784   17139 task.go:401] wait task progress: 0/1
I0504 23:54:40.242979   17139 task.go:401] wait task progress: 0/1
I0504 23:54:55.247183   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-0", Status: "Failed", Identifier: "e2e-test-31084870_pod1__Pod" }
I0504 23:54:55.247269   17139 task.go:401] wait task progress: 1/1
I0504 23:54:55.247277   17139 task.go:407] all objects reconciled or skipped (name: "wait-0")
I0504 23:54:55.247294   17139 task.go:116] wait task completing (name: "wait-0",): context canceled
I0504 23:54:55.247302   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Finished" }
I0504 23:54:55.247319   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-set-0", Action: "Inventory", Type: "Started" }
I0504 23:54:55.247343   17139 inv_set_task.go:59] inventory set task starting (name: "inventory-set-0")
... skipping 79 lines ...
I0504 23:55:25.421760   17139 depends.go:144] adding vertex: e2e-test-45613933_pod1__Pod
I0504 23:55:25.421809   17139 depends.go:144] adding vertex: e2e-test-45613933_nginx-deployment_apps_Deployment
I0504 23:55:25.421818   17139 depends.go:144] adding vertex: e2e-test-45613933_pod3__Pod
I0504 23:55:25.421825   17139 depends.go:144] adding vertex: e2e-test-45613933_pod-a__Pod
I0504 23:55:25.421832   17139 depends.go:144] adding vertex: e2e-test-45613933_pod-b__Pod
I0504 23:55:25.421858   17139 depends.go:258] adding edge from: e2e-test-45613933_nginx-deployment_apps_Deployment, to: e2e-test-45613933_pod1__Pod
I0504 23:55:25.421881   17139 depends.go:255] failed to add edges: invalid "config.kubernetes.io/depends-on" annotation: external dependency: /namespaces/e2e-test-45613933/Pod/pod3 -> /namespaces/e2e-test-45613933/Pod/pod0
I0504 23:55:25.422168   17139 depends.go:191] adding edge from: e2e-test-45613933_pod-a__Pod, to: e2e-test-45613933_pod-b__Pod
I0504 23:55:25.422348   17139 depends.go:191] adding edge from: e2e-test-45613933_pod-b__Pod, to: e2e-test-45613933_pod-a__Pod
I0504 23:55:25.422373   17139 depends.go:188] failed to add edges: invalid "config.kubernetes.io/apply-time-mutation" annotation: external dependency: /namespaces/e2e-test-45613933/Pod/pod-b -> /Pod/pod-a
I0504 23:55:25.422430   17139 solver.go:159] adding inventory add task (2 objects)
I0504 23:55:25.422447   17139 solver.go:243] adding apply task (1 objects)
I0504 23:55:25.422459   17139 solver.go:265] adding wait task
I0504 23:55:25.422467   17139 solver.go:243] adding apply task (1 objects)
I0504 23:55:25.422475   17139 solver.go:265] adding wait task
I0504 23:55:25.422483   17139 solver.go:216] adding inventory set task
... skipping 60 lines ...
STEP: verify podA not found 05/04/22 23:55:29.63
STEP: verify podB not found 05/04/22 23:55:29.633
STEP: modify deployment1 depends-on annotation to be invalid 05/04/22 23:55:29.637
STEP: destroy valid objects and skip invalid objects 05/04/22 23:55:29.649
I0504 23:55:29.669275   17139 depends.go:144] adding vertex: e2e-test-45613933_nginx-deployment_apps_Deployment
I0504 23:55:29.669332   17139 depends.go:144] adding vertex: e2e-test-45613933_pod1__Pod
I0504 23:55:29.669352   17139 depends.go:217] failed to add edges from: e2e-test-45613933_nginx-deployment_apps_Deployment: invalid "config.kubernetes.io/depends-on" annotation: failed to parse object reference (index: 0): expected 3 or 5 fields, found 1: "invalid"
I0504 23:55:29.669386   17139 solver.go:282] adding prune task (1 objects)
I0504 23:55:29.669405   17139 solver.go:265] adding wait task
I0504 23:55:29.669412   17139 solver.go:226] adding delete inventory task
I0504 23:55:29.669449   17139 watcher_dynamic.go:78] DynamicStatusWatcher starting in namespace-scoped mode (targets: 2)
I0504 23:55:29.669473   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Delete", Type: "Started" }
I0504 23:55:29.669516   17139 prune_task.go:55] prune task starting (name: "prune-0", objects: 1)
... skipping 156 lines ...
I0504 23:55:37.823254   17139 reflector.go:219] Starting reflector apps/v1, Kind=Deployment (1h0m0s) from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:55:37.823279   17139 reflector.go:255] Listing and watching apps/v1, Kind=Deployment from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:55:37.830977   17139 inv_add_task.go:94] inventory add task completing (name: "inventory-add-0")
I0504 23:55:37.831029   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-add-0", Action: "Inventory", Type: "Finished" }
I0504 23:55:37.831046   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Started" }
I0504 23:55:37.831100   17139 apply_task.go:91] apply task starting (name: "apply-0", objects: 1)
I0504 23:55:37.834407   17139 context.go:66] Sending event: ApplyEvent{ GroupName: "apply-0", Status: "Skipped", Identifier: "e2e-test-21026113_nginx-deployment_apps_Deployment", Error: "inventory policy prevented actuation (strategy: Apply, status: NoMatch, policy: MustMatch)" }
I0504 23:55:37.834482   17139 apply_task.go:222] apply task completing (name: "apply-0")
I0504 23:55:37.834495   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Finished" }
I0504 23:55:37.834511   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Started" }
I0504 23:55:37.834518   17139 task.go:94] wait task starting (name: "wait-0", objects: 1)
I0504 23:55:37.834528   17139 task.go:152] wait task progress: 0/1
I0504 23:55:37.834534   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-0", Status: "Skipped", Identifier: "e2e-test-21026113_nginx-deployment_apps_Deployment" }
... skipping 648 lines ...
I0504 23:56:22.560639   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Started" }
I0504 23:56:22.560689   17139 apply_task.go:91] apply task starting (name: "apply-0", objects: 1)
I0504 23:56:22.568400   17139 apply_task.go:222] apply task completing (name: "apply-0")
I0504 23:56:22.568443   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Finished" }
I0504 23:56:22.568476   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Started" }
I0504 23:56:22.568497   17139 prune_task.go:55] prune task starting (name: "prune-0", objects: 2)
I0504 23:56:22.568526   17139 context.go:66] Sending event: PruneEvent{ GroupName: "prune-0", Status: "Skipped", Identifier: "e2e-test-67393793_pod2__Pod", Error: "annotation prevents deletion (\"client.lifecycle.config.k8s.io/deletion\": \"detach\")" }
I0504 23:56:22.568571   17139 context.go:66] Sending event: PruneEvent{ GroupName: "prune-0", Status: "Skipped", Identifier: "e2e-test-67393793_pod1__Pod", Error: "annotation prevents deletion (\"cli-utils.sigs.k8s.io/on-remove\": \"keep\")" }
I0504 23:56:22.568583   17139 prune_task.go:74] prune task completing (name: "prune-0")
I0504 23:56:22.568588   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Finished" }
I0504 23:56:22.568601   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-set-0", Action: "Inventory", Type: "Started" }
I0504 23:56:22.568614   17139 inv_set_task.go:59] inventory set task starting (name: "inventory-set-0")
I0504 23:56:22.568638   17139 inv_set_task.go:123] inventory set task completing (name: "inventory-set-0")
I0504 23:56:22.568643   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-set-0", Action: "Inventory", Type: "Finished" }
... skipping 33 lines ...
I0504 23:56:22.642667   17139 task.go:186] wait task progress: 1/1
I0504 23:56:22.642674   17139 task.go:190] all objects reconciled or skipped (name: "wait-0")
I0504 23:56:22.642700   17139 task.go:116] wait task completing (name: "wait-0",): context canceled
I0504 23:56:22.642719   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Finished" }
I0504 23:56:22.642727   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Started" }
I0504 23:56:22.642755   17139 prune_task.go:55] prune task starting (name: "prune-0", objects: 2)
I0504 23:56:22.652373   17139 context.go:66] Sending event: PruneEvent{ GroupName: "prune-0", Status: "Skipped", Identifier: "e2e-test-67393793_pod2__Pod", Error: "annotation prevents deletion (\"client.lifecycle.config.k8s.io/deletion\": \"detach\")" }
I0504 23:56:22.661324   17139 context.go:66] Sending event: PruneEvent{ GroupName: "prune-0", Status: "Skipped", Identifier: "e2e-test-67393793_pod1__Pod", Error: "annotation prevents deletion (\"cli-utils.sigs.k8s.io/on-remove\": \"keep\")" }
I0504 23:56:22.661416   17139 prune_task.go:74] prune task completing (name: "prune-0")
I0504 23:56:22.661430   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Finished" }
I0504 23:56:22.661448   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-1", Action: "Wait", Type: "Started" }
I0504 23:56:22.661457   17139 task.go:94] wait task starting (name: "wait-1", objects: 2)
I0504 23:56:22.661466   17139 task.go:152] wait task progress: 0/2
I0504 23:56:22.661475   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-1", Status: "Skipped", Identifier: "e2e-test-67393793_pod2__Pod" }
... skipping 56 lines ...
I0504 23:56:23.007185   17139 solver.go:243] adding apply task (1 objects)
I0504 23:56:23.007193   17139 solver.go:265] adding wait task
I0504 23:56:23.007201   17139 solver.go:216] adding inventory set task
I0504 23:56:23.010873   17139 watcher_dynamic.go:78] DynamicStatusWatcher starting in namespace-scoped mode (targets: 2)
I0504 23:56:23.010928   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-add-0", Action: "Inventory", Type: "Started" }
I0504 23:56:23.010975   17139 inv_add_task.go:48] inventory add task starting (name: "inventory-add-0")
I0504 23:56:23.011197   17139 watcher_dynamic.go:325] Watch start error (blocking until CRD is added): cli-utils.example.io/Example/namespaces/: no matches for kind "Example" in group "cli-utils.example.io"
I0504 23:56:23.011221   17139 watcher_dynamic.go:452] Watch starting: apiextensions.k8s.io/CustomResourceDefinition/namespaces/
I0504 23:56:23.011313   17139 reflector.go:219] Starting reflector apiextensions.k8s.io/v1, Kind=CustomResourceDefinition (1h0m0s) from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:56:23.011332   17139 reflector.go:255] Listing and watching apiextensions.k8s.io/v1, Kind=CustomResourceDefinition from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:56:23.034895   17139 inv_add_task.go:94] inventory add task completing (name: "inventory-add-0")
I0504 23:56:23.034956   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-add-0", Action: "Inventory", Type: "Finished" }
I0504 23:56:23.034990   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Started" }
... skipping 141 lines ...
I0504 23:56:26.234252   17139 reflector.go:219] Starting reflector apiextensions.k8s.io/v1, Kind=CustomResourceDefinition (1h0m0s) from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:56:26.234317   17139 reflector.go:255] Listing and watching apiextensions.k8s.io/v1, Kind=CustomResourceDefinition from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:56:26.254039   17139 inv_add_task.go:94] inventory add task completing (name: "inventory-add-0")
I0504 23:56:26.254088   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-add-0", Action: "Inventory", Type: "Finished" }
I0504 23:56:26.254112   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Started" }
I0504 23:56:26.254150   17139 apply_task.go:91] apply task starting (name: "apply-0", objects: 2)
I0504 23:56:26.263022   17139 context.go:66] Sending event: ApplyEvent{ GroupName: "apply-0", Status: "Failed", Identifier: "_invalidexamples.cli-utils.example.io_apiextensions.k8s.io_CustomResourceDefinition", Error: "error when creating \"unstructured\": CustomResourceDefinition.apiextensions.k8s.io \"invalidexamples.cli-utils.example.io\" is invalid: [spec.versions: Invalid value: []apiextensions.CustomResourceDefinitionVersion(nil): must have exactly one version marked as storage version, status.storedVersions: Invalid value: []string(nil): must have at least one stored version]" }
I0504 23:56:26.277262   17139 apply_task.go:222] apply task completing (name: "apply-0")
I0504 23:56:26.277308   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Finished" }
I0504 23:56:26.277490   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Started" }
I0504 23:56:26.277582   17139 task.go:94] wait task starting (name: "wait-0", objects: 2)
I0504 23:56:26.277602   17139 task.go:152] wait task progress: 0/2
I0504 23:56:26.277611   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-0", Status: "Skipped", Identifier: "_invalidexamples.cli-utils.example.io_apiextensions.k8s.io_CustomResourceDefinition" }
... skipping 583 lines ...
I0504 23:57:01.850768   17139 reflector.go:219] Starting reflector /v1, Kind=Pod (1h0m0s) from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:57:01.850799   17139 reflector.go:255] Listing and watching /v1, Kind=Pod from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:57:01.871695   17139 inv_add_task.go:94] inventory add task completing (name: "inventory-add-0")
I0504 23:57:01.871740   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-add-0", Action: "Inventory", Type: "Finished" }
I0504 23:57:01.871758   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Started" }
I0504 23:57:01.871930   17139 apply_task.go:91] apply task starting (name: "apply-0", objects: 1)
I0504 23:57:01.887141   17139 context.go:66] Sending event: ApplyEvent{ GroupName: "apply-0", Status: "Skipped", Identifier: "e2e-test-92986365_pod1__Pod", Error: "dependency scheduled for delete: e2e-test-92986365_pod2__Pod" }
I0504 23:57:01.887248   17139 apply_task.go:222] apply task completing (name: "apply-0")
I0504 23:57:01.887281   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Finished" }
I0504 23:57:01.887357   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Started" }
I0504 23:57:01.887386   17139 task.go:94] wait task starting (name: "wait-0", objects: 1)
I0504 23:57:01.887398   17139 task.go:152] wait task progress: 0/1
I0504 23:57:01.887410   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-0", Status: "Skipped", Identifier: "e2e-test-92986365_pod1__Pod" }
I0504 23:57:01.887424   17139 task.go:186] wait task progress: 1/1
I0504 23:57:01.887431   17139 task.go:190] all objects reconciled or skipped (name: "wait-0")
I0504 23:57:01.887467   17139 task.go:116] wait task completing (name: "wait-0",): context canceled
I0504 23:57:01.887744   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Finished" }
I0504 23:57:01.887978   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Started" }
I0504 23:57:01.888457   17139 prune_task.go:55] prune task starting (name: "prune-0", objects: 1)
I0504 23:57:01.888638   17139 context.go:66] Sending event: PruneEvent{ GroupName: "prune-0", Status: "Skipped", Identifier: "e2e-test-92986365_pod2__Pod", Error: "dependent scheduled for apply: e2e-test-92986365_pod1__Pod" }
I0504 23:57:01.888793   17139 prune_task.go:74] prune task completing (name: "prune-0")
I0504 23:57:01.888821   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Finished" }
I0504 23:57:01.888836   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-1", Action: "Wait", Type: "Started" }
I0504 23:57:01.888845   17139 task.go:94] wait task starting (name: "wait-1", objects: 1)
I0504 23:57:01.888853   17139 task.go:152] wait task progress: 0/1
I0504 23:57:01.888861   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-1", Status: "Skipped", Identifier: "e2e-test-92986365_pod2__Pod" }
... skipping 112 lines ...
I0504 23:57:02.858293   17139 reflector.go:255] Listing and watching /v1, Kind=Pod from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:57:02.858358   17139 reflector.go:255] Listing and watching /v1, Kind=Namespace from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:57:02.912917   17139 inv_add_task.go:94] inventory add task completing (name: "inventory-add-0")
I0504 23:57:02.913310   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-add-0", Action: "Inventory", Type: "Finished" }
I0504 23:57:02.913406   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Started" }
I0504 23:57:02.913458   17139 apply_task.go:91] apply task starting (name: "apply-0", objects: 1)
I0504 23:57:02.923136   17139 context.go:66] Sending event: ApplyEvent{ GroupName: "apply-0", Status: "Skipped", Identifier: "e2e-test-36837532-ns1_pod-b__Pod", Error: "dependency scheduled for delete: _e2e-test-36837532-ns1__Namespace" }
I0504 23:57:02.923205   17139 apply_task.go:222] apply task completing (name: "apply-0")
I0504 23:57:02.923222   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Finished" }
I0504 23:57:02.923281   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Started" }
I0504 23:57:02.923378   17139 task.go:94] wait task starting (name: "wait-0", objects: 1)
I0504 23:57:02.923416   17139 task.go:152] wait task progress: 0/1
I0504 23:57:02.923447   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-0", Status: "Skipped", Identifier: "e2e-test-36837532-ns1_pod-b__Pod" }
I0504 23:57:02.923483   17139 task.go:186] wait task progress: 1/1
I0504 23:57:02.923492   17139 task.go:190] all objects reconciled or skipped (name: "wait-0")
I0504 23:57:02.923528   17139 task.go:116] wait task completing (name: "wait-0",): context canceled
I0504 23:57:02.923549   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Finished" }
I0504 23:57:02.923583   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Started" }
I0504 23:57:02.923621   17139 prune_task.go:55] prune task starting (name: "prune-0", objects: 1)
I0504 23:57:02.923660   17139 context.go:66] Sending event: PruneEvent{ GroupName: "prune-0", Status: "Skipped", Identifier: "_e2e-test-36837532-ns1__Namespace", Error: "namespace still in use: e2e-test-36837532-ns1" }
I0504 23:57:02.923708   17139 prune_task.go:74] prune task completing (name: "prune-0")
I0504 23:57:02.923718   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Prune", Type: "Finished" }
I0504 23:57:02.923747   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-1", Action: "Wait", Type: "Started" }
I0504 23:57:02.923788   17139 task.go:94] wait task starting (name: "wait-1", objects: 1)
I0504 23:57:02.923798   17139 task.go:152] wait task progress: 0/1
I0504 23:57:02.923806   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-1", Status: "Skipped", Identifier: "_e2e-test-36837532-ns1__Namespace" }
... skipping 198 lines ...
I0504 23:57:11.984854   17139 task.go:94] wait task starting (name: "wait-0", objects: 1)
I0504 23:57:11.984895   17139 task.go:152] wait task progress: 0/1
I0504 23:57:11.984916   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-0", Status: "Pending", Identifier: "e2e-test-64174248_pod1__Pod" }
I0504 23:57:11.984957   17139 task.go:186] wait task progress: 0/1
I0504 23:57:11.986324   17139 task.go:401] wait task progress: 0/1
I0504 23:57:11.993298   17139 task.go:401] wait task progress: 0/1
I0504 23:57:26.997354   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-0", Status: "Failed", Identifier: "e2e-test-64174248_pod1__Pod" }
I0504 23:57:26.997440   17139 task.go:401] wait task progress: 1/1
I0504 23:57:26.997449   17139 task.go:407] all objects reconciled or skipped (name: "wait-0")
I0504 23:57:26.997467   17139 task.go:116] wait task completing (name: "wait-0",): context canceled
I0504 23:57:26.997474   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Finished" }
I0504 23:57:26.997493   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-set-0", Action: "Inventory", Type: "Started" }
I0504 23:57:26.997512   17139 inv_set_task.go:59] inventory set task starting (name: "inventory-set-0")
... skipping 78 lines ...
I0504 23:57:57.199746   17139 depends.go:144] adding vertex: e2e-test-03206822_pod1__Pod
I0504 23:57:57.199811   17139 depends.go:144] adding vertex: e2e-test-03206822_nginx-deployment_apps_Deployment
I0504 23:57:57.199825   17139 depends.go:144] adding vertex: e2e-test-03206822_pod3__Pod
I0504 23:57:57.199831   17139 depends.go:144] adding vertex: e2e-test-03206822_pod-a__Pod
I0504 23:57:57.199837   17139 depends.go:144] adding vertex: e2e-test-03206822_pod-b__Pod
I0504 23:57:57.199862   17139 depends.go:258] adding edge from: e2e-test-03206822_nginx-deployment_apps_Deployment, to: e2e-test-03206822_pod1__Pod
I0504 23:57:57.199890   17139 depends.go:255] failed to add edges: invalid "config.kubernetes.io/depends-on" annotation: external dependency: /namespaces/e2e-test-03206822/Pod/pod3 -> /namespaces/e2e-test-03206822/Pod/pod0
I0504 23:57:57.200096   17139 depends.go:191] adding edge from: e2e-test-03206822_pod-a__Pod, to: e2e-test-03206822_pod-b__Pod
I0504 23:57:57.200261   17139 depends.go:191] adding edge from: e2e-test-03206822_pod-b__Pod, to: e2e-test-03206822_pod-a__Pod
I0504 23:57:57.200289   17139 depends.go:188] failed to add edges: invalid "config.kubernetes.io/apply-time-mutation" annotation: external dependency: /namespaces/e2e-test-03206822/Pod/pod-b -> /Pod/pod-a
I0504 23:57:57.200349   17139 solver.go:159] adding inventory add task (2 objects)
I0504 23:57:57.200366   17139 solver.go:243] adding apply task (1 objects)
I0504 23:57:57.200380   17139 solver.go:265] adding wait task
I0504 23:57:57.200402   17139 solver.go:243] adding apply task (1 objects)
I0504 23:57:57.200410   17139 solver.go:265] adding wait task
I0504 23:57:57.200418   17139 solver.go:216] adding inventory set task
... skipping 60 lines ...
STEP: verify podA not found 05/04/22 23:58:01.406
STEP: verify podB not found 05/04/22 23:58:01.408
STEP: modify deployment1 depends-on annotation to be invalid 05/04/22 23:58:01.411
STEP: destroy valid objects and skip invalid objects 05/04/22 23:58:01.421
I0504 23:58:01.438673   17139 depends.go:144] adding vertex: e2e-test-03206822_pod1__Pod
I0504 23:58:01.442887   17139 depends.go:144] adding vertex: e2e-test-03206822_nginx-deployment_apps_Deployment
I0504 23:58:01.442936   17139 depends.go:217] failed to add edges from: e2e-test-03206822_nginx-deployment_apps_Deployment: invalid "config.kubernetes.io/depends-on" annotation: failed to parse object reference (index: 0): expected 3 or 5 fields, found 1: "invalid"
I0504 23:58:01.442980   17139 solver.go:282] adding prune task (1 objects)
I0504 23:58:01.442994   17139 solver.go:265] adding wait task
I0504 23:58:01.443003   17139 solver.go:226] adding delete inventory task
I0504 23:58:01.443062   17139 watcher_dynamic.go:78] DynamicStatusWatcher starting in namespace-scoped mode (targets: 2)
I0504 23:58:01.443100   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "prune-0", Action: "Delete", Type: "Started" }
I0504 23:58:01.443150   17139 prune_task.go:55] prune task starting (name: "prune-0", objects: 1)
... skipping 158 lines ...
I0504 23:58:10.600670   17139 reflector.go:255] Listing and watching apps/v1, Kind=Deployment from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
I0504 23:58:10.615389   17139 inv_add_task.go:94] inventory add task completing (name: "inventory-add-0")
I0504 23:58:10.615450   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-add-0", Action: "Inventory", Type: "Finished" }
I0504 23:58:10.615485   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Started" }
I0504 23:58:10.615523   17139 apply_task.go:91] apply task starting (name: "apply-0", objects: 1)
I0504 23:58:10.616676   17139 context.go:66] Sending event: StatusEvent{ Status: "Current", Generation: 1, Identifier: "e2e-test-59531057_nginx-deployment_apps_Deployment" }
I0504 23:58:10.622316   17139 context.go:66] Sending event: ApplyEvent{ GroupName: "apply-0", Status: "Skipped", Identifier: "e2e-test-59531057_nginx-deployment_apps_Deployment", Error: "inventory policy prevented actuation (strategy: Apply, status: NoMatch, policy: MustMatch)" }
I0504 23:58:10.622378   17139 apply_task.go:222] apply task completing (name: "apply-0")
I0504 23:58:10.622389   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "apply-0", Action: "Apply", Type: "Finished" }
I0504 23:58:10.622411   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "wait-0", Action: "Wait", Type: "Started" }
I0504 23:58:10.622436   17139 task.go:94] wait task starting (name: "wait-0", objects: 1)
I0504 23:58:10.622450   17139 task.go:152] wait task progress: 0/1
I0504 23:58:10.622520   17139 context.go:66] Sending event: WaitEvent{ GroupName: "wait-0", Status: "Skipped", Identifier: "e2e-test-59531057_nginx-deployment_apps_Deployment" }
... skipping 277 lines ...
I0504 23:58:36.989230   17139 inv_set_task.go:123] inventory set task completing (name: "inventory-set-0")
I0504 23:58:36.989278   17139 context.go:66] Sending event: ActionGroupEvent{ GroupName: "inventory-set-0", Action: "Inventory", Type: "Finished" }
I0504 23:58:36.989351   17139 reflector.go:225] Stopping reflector apps/v1, Kind=Deployment (1h0m0s) from pkg/mod/k8s.io/client-go@v0.23.2/tools/cache/reflector.go:167
STEP: Verify inventory 05/04/22 23:58:36.989
I0504 23:58:36.989421   17139 watcher_dynamic.go:454] Watch stopped: apps/Deployment/namespaces/e2e-test-31704090
STEP: Apply second set of resources, using same inventory name but different ID 05/04/22 23:58:36.992
STEP: Verify that we get the correct error 05/04/22 23:58:36.996
------------------------------
• [SLOW TEST] [7.189 seconds]
E2E
/home/prow/go/src/sigs.k8s.io/cli-utils/test/e2e/e2e_test.go:92
  NameStrategy
  /home/prow/go/src/sigs.k8s.io/cli-utils/test/e2e/e2e_test.go:239
    InventoryIDMismatch
    /home/prow/go/src/sigs.k8s.io/cli-utils/test/e2e/e2e_test.go:261

  Begin Captured GinkgoWriter Output >>
    STEP: Apply first set of resources 05/04/22 23:58:29.821
    STEP: Verify inventory 05/04/22 23:58:36.989
    STEP: Apply second set of resources, using same inventory name but different ID 05/04/22 23:58:36.992
    STEP: Verify that we get the correct error 05/04/22 23:58:36.996
  << End Captured GinkgoWriter Output
------------------------------
[AfterSuite] 
/home/prow/go/src/sigs.k8s.io/cli-utils/test/e2e/e2e_test.go:85
------------------------------
[AfterSuite] PASSED [0.007 seconds]
[AfterSuite] 
/home/prow/go/src/sigs.k8s.io/cli-utils/test/e2e/e2e_test.go:85
------------------------------

Ran 39 of 39 Specs in 311.094 seconds
SUCCESS! -- 39 Passed | 0 Failed | 0 Pending | 0 Skipped
PASS

Ginkgo ran 1 suite in 6m4.618836885s
Test Suite Passed
go install github.com/monopole/mdrip@v1.0.2
go: downloading github.com/monopole/mdrip v1.0.2
... skipping 64 lines ...
/kubernetes-sigs/kustomize\
/master/examples/wordpress/mysql\
/{secret,deployment,service}.yaml"

function expectedOutputLine() {
  if ! grep -q "$@" "$OUTPUT/status"; then
    echo -e "${RED}Error: output line not found${NC}"
    echo -e "${RED}Expected: $@${NC}"
    exit 1
  else
    echo -e "${GREEN}Success: output line found${NC}"
  fi
}
... skipping 130 lines ...
I0505 00:00:22.577270   45978 scanner.go:43] stream stdOut: forwarding "reconcile phase finished"
I0505 00:00:22.577311   45978 scanner.go:43] stream stdOut: forwarding "inventory update started"
I0505 00:00:22.577332   45978 subshell.go:78] accum stdOut: [reconcile phase finished]
I0505 00:00:22.577340   45978 subshell.go:78] accum stdOut: [inventory update started]
I0505 00:00:22.599799   45978 scanner.go:43] stream stdOut: forwarding "inventory update finished"
I0505 00:00:22.599884   45978 subshell.go:78] accum stdOut: [inventory update finished]
I0505 00:00:22.601672   45978 scanner.go:43] stream stdOut: forwarding "apply result: 3 attempted, 3 successful, 0 skipped, 0 failed"
I0505 00:00:22.601719   45978 scanner.go:43] stream stdOut: forwarding "reconcile result: 3 attempted, 3 successful, 0 skipped, 0 failed, 0 timed out"
I0505 00:00:22.601745   45978 subshell.go:78] accum stdOut: [apply result: 3 attempted, 3 successful, 0 skipped, 0 failed]
I0505 00:00:22.601755   45978 subshell.go:78] accum stdOut: [reconcile result: 3 attempted, 3 successful, 0 skipped, 0 failed, 0 timed out]
I0505 00:00:22.626970   45978 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:00:22.627042   45978 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:00:22.628811   45978 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:00:22.628882   45978 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:00:22.632571   45978 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:00:22.632641   45978 subshell.go:78] accum stdOut: [Success: output line found]
... skipping 57 lines ...
I0505 00:00:35.625039   45978 scanner.go:43] stream stdOut: forwarding "reconcile phase finished"
I0505 00:00:35.625074   45978 scanner.go:43] stream stdOut: forwarding "inventory update started"
I0505 00:00:35.625103   45978 subshell.go:78] accum stdOut: [reconcile phase finished]
I0505 00:00:35.625109   45978 subshell.go:78] accum stdOut: [inventory update started]
I0505 00:00:35.641535   45978 scanner.go:43] stream stdOut: forwarding "inventory update finished"
I0505 00:00:35.641600   45978 subshell.go:78] accum stdOut: [inventory update finished]
I0505 00:00:35.643013   45978 scanner.go:43] stream stdOut: forwarding "apply result: 2 attempted, 2 successful, 0 skipped, 0 failed"
I0505 00:00:35.643050   45978 scanner.go:43] stream stdOut: forwarding "reconcile result: 2 attempted, 2 successful, 0 skipped, 0 failed, 0 timed out"
I0505 00:00:35.643069   45978 subshell.go:78] accum stdOut: [apply result: 2 attempted, 2 successful, 0 skipped, 0 failed]
I0505 00:00:35.643083   45978 subshell.go:78] accum stdOut: [reconcile result: 2 attempted, 2 successful, 0 skipped, 0 failed, 0 timed out]
I0505 00:00:35.666841   45978 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:00:35.666912   45978 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:00:35.668894   45978 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:00:35.668955   45978 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:00:35.795896   45978 scanner.go:43] stream stdOut: forwarding "4"
I0505 00:00:35.795958   45978 subshell.go:78] accum stdOut: [4]
... skipping 6 lines ...
I0505 00:00:35.798254   45978 subshell.go:121] Expecting output of destroyAppDeleteKindCluster (7/7) from /home/prow/go/src/sigs.k8s.io/cli-utils/examples/alphaTestExamples/MultipleServices.md
I0505 00:00:35.798279   45978 subshell.go:124] 
kapply destroy $BASE/wordpress | tee $OUTPUT/status;

expectedOutputLine "service/wordpress delete successful"
expectedOutputLine "deployment.apps/wordpress delete successful"
expectedOutputLine "delete result: 2 attempted, 2 successful, 0 skipped, 0 failed"
expectedOutputLine "reconcile result: 2 attempted, 2 successful, 0 skipped, 0 failed, 0 timed out"

# Verify that we still have the mysql resources in the cluster.
kubectl get all --no-headers --selector=app=mysql | wc -l | xargs | tee $OUTPUT/status
expectedOutputLine "4"

# TODO: When we implement wait for prune/destroy, add a check here to make
... skipping 19 lines ...
I0505 00:00:36.055471   45978 subshell.go:78] accum stdOut: [deployment.apps/wordpress reconcile successful]
I0505 00:00:36.055477   45978 subshell.go:78] accum stdOut: [reconcile phase finished]
I0505 00:00:36.055598   45978 scanner.go:43] stream stdOut: forwarding "inventory update started"
I0505 00:00:36.055647   45978 subshell.go:78] accum stdOut: [inventory update started]
I0505 00:00:36.069392   45978 scanner.go:43] stream stdOut: forwarding "inventory update finished"
I0505 00:00:36.069476   45978 subshell.go:78] accum stdOut: [inventory update finished]
I0505 00:00:36.070534   45978 scanner.go:43] stream stdOut: forwarding "delete result: 2 attempted, 2 successful, 0 skipped, 0 failed"
I0505 00:00:36.070621   45978 scanner.go:43] stream stdOut: forwarding "reconcile result: 2 attempted, 2 successful, 0 skipped, 0 failed, 0 timed out"
I0505 00:00:36.070644   45978 subshell.go:78] accum stdOut: [delete result: 2 attempted, 2 successful, 0 skipped, 0 failed]
I0505 00:00:36.070652   45978 subshell.go:78] accum stdOut: [reconcile result: 2 attempted, 2 successful, 0 skipped, 0 failed, 0 timed out]
I0505 00:00:36.092634   45978 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:00:36.092701   45978 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:00:36.094497   45978 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:00:36.094562   45978 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:00:36.096633   45978 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:00:36.096845   45978 subshell.go:78] accum stdOut: [Success: output line found]
... skipping 47 lines ...
GREEN='\033[0;32m'
RED='\033[0;31m'
NC='\033[0m' # No Color

function expectedOutputLine() {
  if ! grep -q "$@" "$OUTPUT/status"; then
    echo -e "${RED}Error: output line not found${NC}"
    echo -e "${RED}Expected: $@${NC}"
    exit 1
  else
    echo -e "${GREEN}Success: output line found${NC}"
  fi
}
... skipping 183 lines ...
I0505 00:01:31.766225   49284 subshell.go:78] accum stdOut: [foo.custom.io/example-foo is Current: Resource is current]
I0505 00:01:31.766233   49284 subshell.go:78] accum stdOut: [foo.custom.io/example-foo reconcile successful]
I0505 00:01:31.766240   49284 subshell.go:78] accum stdOut: [reconcile phase finished]
I0505 00:01:31.766250   49284 subshell.go:78] accum stdOut: [inventory update started]
I0505 00:01:31.779283   49284 scanner.go:43] stream stdOut: forwarding "inventory update finished"
I0505 00:01:31.779352   49284 subshell.go:78] accum stdOut: [inventory update finished]
I0505 00:01:31.780302   49284 scanner.go:43] stream stdOut: forwarding "apply result: 2 attempted, 2 successful, 0 skipped, 0 failed"
I0505 00:01:31.780344   49284 scanner.go:43] stream stdOut: forwarding "reconcile result: 2 attempted, 2 successful, 0 skipped, 0 failed, 0 timed out"
I0505 00:01:31.780369   49284 subshell.go:78] accum stdOut: [apply result: 2 attempted, 2 successful, 0 skipped, 0 failed]
I0505 00:01:31.780400   49284 subshell.go:78] accum stdOut: [reconcile result: 2 attempted, 2 successful, 0 skipped, 0 failed, 0 timed out]
I0505 00:01:31.803809   49284 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:01:31.803937   49284 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:01:31.889019   49284 scanner.go:43] stream stdOut: forwarding "foos.custom.io"
I0505 00:01:31.889091   49284 subshell.go:78] accum stdOut: [foos.custom.io]
I0505 00:01:31.891533   49284 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:01:31.891597   49284 subshell.go:78] accum stdOut: [Success: output line found]
... skipping 44 lines ...
GREEN='\033[0;32m'
RED='\033[0;31m'
NC='\033[0m' # No Color

function expectedOutputLine() {
  if ! grep -q "$@" "$OUTPUT/status"; then
    echo -e "${RED}Error: output line not found${NC}"
    echo -e "${RED}Expected: $@${NC}"
    exit 1
  else
    echo -e "${GREEN}Success: output line found${NC}"
  fi
}

function expectedNotFound() {
  if grep -q "$@" $OUTPUT/status; then
    echo -e "${RED}Error: output line found:${NC}"
    echo -e "${RED}Found: $@${NC}"
    exit 1
  else
    echo -e "${GREEN}Success: output line not found found${NC}"
  fi
}
... skipping 167 lines ...
I0505 00:02:00.522855   51916 scanner.go:43] stream stdErr: forwarding "MDRIP_HAPPY_Completed_command_block createInventoryTemplate"
I0505 00:02:00.522866   51916 subshell.go:71] accum stdErr: MDRIP_HAPPY_Completed_command_block createInventoryTemplate
I0505 00:02:00.522876   51916 subshell.go:121] Expecting output of previewHelloApp (9/12) from /home/prow/go/src/sigs.k8s.io/cli-utils/examples/alphaTestExamples/helloapp.md
I0505 00:02:00.522888   51916 subshell.go:124] 
kapply preview $BASE | tee $OUTPUT/status

expectedOutputLine "apply result: 3 attempted, 3 successful, 0 skipped, 0 failed"

kapply preview $BASE --server-side | tee $OUTPUT/status

expectedOutputLine "apply result: 3 attempted, 3 successful, 0 skipped, 0 failed"

# Verify that preview didn't create any resources.
kubectl get all -n hellospace 2>&1 | tee $OUTPUT/status
expectedOutputLine "No resources found in hellospace namespace."
I0505 00:02:00.902462   51916 scanner.go:43] stream stdOut: forwarding "Preview strategy: client"
I0505 00:02:00.902518   51916 subshell.go:78] accum stdOut: [Preview strategy: client]
... skipping 11 lines ...
I0505 00:02:00.960754   51916 scanner.go:43] stream stdOut: forwarding "apply phase finished"
I0505 00:02:00.960761   51916 scanner.go:43] stream stdOut: forwarding "inventory update started"
I0505 00:02:00.960785   51916 subshell.go:78] accum stdOut: [deployment.apps/the-deployment apply successful]
I0505 00:02:00.960794   51916 subshell.go:78] accum stdOut: [apply phase finished]
I0505 00:02:00.960798   51916 subshell.go:78] accum stdOut: [inventory update started]
I0505 00:02:00.961180   51916 scanner.go:43] stream stdOut: forwarding "inventory update finished"
I0505 00:02:00.961202   51916 scanner.go:43] stream stdOut: forwarding "apply result: 3 attempted, 3 successful, 0 skipped, 0 failed"
I0505 00:02:00.961401   51916 subshell.go:78] accum stdOut: [inventory update finished]
I0505 00:02:00.961425   51916 subshell.go:78] accum stdOut: [apply result: 3 attempted, 3 successful, 0 skipped, 0 failed]
I0505 00:02:00.984978   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:00.985031   51916 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:02:01.168739   51916 scanner.go:43] stream stdOut: forwarding "Preview strategy: server"
I0505 00:02:01.168790   51916 subshell.go:78] accum stdOut: [Preview strategy: server]
I0505 00:02:01.177964   51916 scanner.go:43] stream stdOut: forwarding "inventory update started"
I0505 00:02:01.178018   51916 subshell.go:78] accum stdOut: [inventory update started]
... skipping 9 lines ...
I0505 00:02:03.517079   51916 scanner.go:43] stream stdOut: forwarding "apply phase finished"
I0505 00:02:03.517085   51916 scanner.go:43] stream stdOut: forwarding "inventory update started"
I0505 00:02:03.517132   51916 subshell.go:78] accum stdOut: [deployment.apps/the-deployment apply successful]
I0505 00:02:03.517147   51916 subshell.go:78] accum stdOut: [apply phase finished]
I0505 00:02:03.517153   51916 subshell.go:78] accum stdOut: [inventory update started]
I0505 00:02:03.517453   51916 scanner.go:43] stream stdOut: forwarding "inventory update finished"
I0505 00:02:03.517486   51916 scanner.go:43] stream stdOut: forwarding "apply result: 3 attempted, 3 successful, 0 skipped, 0 failed"
I0505 00:02:03.517504   51916 subshell.go:78] accum stdOut: [inventory update finished]
I0505 00:02:03.517512   51916 subshell.go:78] accum stdOut: [apply result: 3 attempted, 3 successful, 0 skipped, 0 failed]
I0505 00:02:03.554559   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:03.554689   51916 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:02:03.673397   51916 scanner.go:43] stream stdOut: forwarding "No resources found in hellospace namespace."
I0505 00:02:03.673463   51916 subshell.go:78] accum stdOut: [No resources found in hellospace namespace.]
I0505 00:02:03.679890   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:03.679939   51916 scanner.go:43] stream stdOut: forwarding "MDRIP_HAPPY_Completed_command_block previewHelloApp"
... skipping 59 lines ...
I0505 00:02:24.487535   51916 subshell.go:78] accum stdOut: [deployment.apps/the-deployment is Current: Deployment is available. Replicas: 3]
I0505 00:02:24.487573   51916 subshell.go:78] accum stdOut: [deployment.apps/the-deployment reconcile successful]
I0505 00:02:24.487584   51916 subshell.go:78] accum stdOut: [reconcile phase finished]
I0505 00:02:24.487598   51916 subshell.go:78] accum stdOut: [inventory update started]
I0505 00:02:24.499510   51916 scanner.go:43] stream stdOut: forwarding "inventory update finished"
I0505 00:02:24.499584   51916 subshell.go:78] accum stdOut: [inventory update finished]
I0505 00:02:24.501394   51916 scanner.go:43] stream stdOut: forwarding "apply result: 3 attempted, 3 successful, 0 skipped, 0 failed"
I0505 00:02:24.501429   51916 scanner.go:43] stream stdOut: forwarding "reconcile result: 3 attempted, 3 successful, 0 skipped, 0 failed, 0 timed out"
I0505 00:02:24.501455   51916 subshell.go:78] accum stdOut: [apply result: 3 attempted, 3 successful, 0 skipped, 0 failed]
I0505 00:02:24.501464   51916 subshell.go:78] accum stdOut: [reconcile result: 3 attempted, 3 successful, 0 skipped, 0 failed, 0 timed out]
I0505 00:02:24.523464   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:24.523552   51916 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:02:24.525457   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:24.525503   51916 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:02:24.527292   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:24.527356   51916 subshell.go:78] accum stdOut: [Success: output line found]
... skipping 79 lines ...
I0505 00:02:24.886453   51916 scanner.go:43] stream stdOut: forwarding "reconcile phase finished"
I0505 00:02:24.886495   51916 scanner.go:43] stream stdOut: forwarding "inventory update started"
I0505 00:02:24.886512   51916 subshell.go:78] accum stdOut: [reconcile phase finished]
I0505 00:02:24.886520   51916 subshell.go:78] accum stdOut: [inventory update started]
I0505 00:02:24.908640   51916 scanner.go:43] stream stdOut: forwarding "inventory update finished"
I0505 00:02:24.908704   51916 subshell.go:78] accum stdOut: [inventory update finished]
I0505 00:02:24.910802   51916 scanner.go:43] stream stdOut: forwarding "apply result: 3 attempted, 3 successful, 0 skipped, 0 failed"
I0505 00:02:24.910840   51916 scanner.go:43] stream stdOut: forwarding "prune result: 1 attempted, 1 successful, 0 skipped, 0 failed"
I0505 00:02:24.910848   51916 scanner.go:43] stream stdOut: forwarding "reconcile result: 4 attempted, 4 successful, 0 skipped, 0 failed, 0 timed out"
I0505 00:02:24.910927   51916 subshell.go:78] accum stdOut: [apply result: 3 attempted, 3 successful, 0 skipped, 0 failed]
I0505 00:02:24.910958   51916 subshell.go:78] accum stdOut: [prune result: 1 attempted, 1 successful, 0 skipped, 0 failed]
I0505 00:02:24.910963   51916 subshell.go:78] accum stdOut: [reconcile result: 4 attempted, 4 successful, 0 skipped, 0 failed, 0 timed out]
I0505 00:02:24.932169   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:24.932228   51916 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:02:24.934027   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:24.934087   51916 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:02:25.010733   51916 scanner.go:43] stream stdOut: forwarding "inventory-16194262"
I0505 00:02:25.010895   51916 scanner.go:43] stream stdOut: forwarding "kube-root-ca.crt"
... skipping 13 lines ...
I0505 00:02:25.015234   51916 subshell.go:124] 
kapply preview $BASE --destroy | tee $OUTPUT/status

expectedOutputLine "deployment.apps/the-deployment delete successful"
expectedOutputLine "configmap/the-map2 delete successful"
expectedOutputLine "service/the-service delete successful"
expectedOutputLine "delete result: 3 attempted, 3 successful, 0 skipped, 0 failed"

kapply preview $BASE --destroy --server-side | tee $OUTPUT/status

expectedOutputLine "deployment.apps/the-deployment delete successful"
expectedOutputLine "configmap/the-map2 delete successful"
expectedOutputLine "service/the-service delete successful"
expectedOutputLine "delete result: 3 attempted, 3 successful, 0 skipped, 0 failed"

# Verify that preview all resources are still there after running preview.
kubectl get --no-headers all -n hellospace | wc -l | xargs | tee $OUTPUT/status
expectedOutputLine "6"

kapply destroy $BASE | tee $OUTPUT/status;

expectedOutputLine "deployment.apps/the-deployment delete successful"
expectedOutputLine "configmap/the-map2 delete successful"
expectedOutputLine "service/the-service delete successful"
expectedOutputLine "delete result: 3 attempted, 3 successful, 0 skipped, 0 failed"
expectedOutputLine "reconcile result: 3 attempted, 3 successful, 0 skipped, 0 failed, 0 timed out"
expectedNotFound "prune result"

kind delete cluster;
I0505 00:02:25.187474   51916 scanner.go:43] stream stdOut: forwarding "Preview strategy: client"
I0505 00:02:25.187585   51916 subshell.go:78] accum stdOut: [Preview strategy: client]
I0505 00:02:25.211552   51916 scanner.go:43] stream stdOut: forwarding "delete phase started"
... skipping 6 lines ...
I0505 00:02:25.211972   51916 subshell.go:78] accum stdOut: [deployment.apps/the-deployment delete successful]
I0505 00:02:25.212002   51916 subshell.go:78] accum stdOut: [service/the-service delete successful]
I0505 00:02:25.212010   51916 subshell.go:78] accum stdOut: [configmap/the-map2 delete successful]
I0505 00:02:25.212041   51916 subshell.go:78] accum stdOut: [delete phase finished]
I0505 00:02:25.212059   51916 subshell.go:78] accum stdOut: [inventory update started]
I0505 00:02:25.218479   51916 scanner.go:43] stream stdOut: forwarding "inventory update finished"
I0505 00:02:25.218518   51916 scanner.go:43] stream stdOut: forwarding "delete result: 3 attempted, 3 successful, 0 skipped, 0 failed"
I0505 00:02:25.218540   51916 subshell.go:78] accum stdOut: [inventory update finished]
I0505 00:02:25.218614   51916 subshell.go:78] accum stdOut: [delete result: 3 attempted, 3 successful, 0 skipped, 0 failed]
I0505 00:02:25.240343   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:25.240404   51916 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:02:25.242109   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:25.242171   51916 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:02:25.244035   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:25.244103   51916 subshell.go:78] accum stdOut: [Success: output line found]
... skipping 11 lines ...
I0505 00:02:25.445487   51916 subshell.go:78] accum stdOut: [deployment.apps/the-deployment delete successful]
I0505 00:02:25.445495   51916 subshell.go:78] accum stdOut: [service/the-service delete successful]
I0505 00:02:25.445502   51916 subshell.go:78] accum stdOut: [configmap/the-map2 delete successful]
I0505 00:02:25.445511   51916 subshell.go:78] accum stdOut: [delete phase finished]
I0505 00:02:25.445518   51916 subshell.go:78] accum stdOut: [inventory update started]
I0505 00:02:25.451697   51916 scanner.go:43] stream stdOut: forwarding "inventory update finished"
I0505 00:02:25.451736   51916 scanner.go:43] stream stdOut: forwarding "delete result: 3 attempted, 3 successful, 0 skipped, 0 failed"
I0505 00:02:25.451758   51916 subshell.go:78] accum stdOut: [inventory update finished]
I0505 00:02:25.451765   51916 subshell.go:78] accum stdOut: [delete result: 3 attempted, 3 successful, 0 skipped, 0 failed]
I0505 00:02:25.474600   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:25.474668   51916 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:02:25.476391   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:25.476471   51916 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:02:25.478711   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:25.478774   51916 subshell.go:78] accum stdOut: [Success: output line found]
... skipping 26 lines ...
I0505 00:02:25.873046   51916 scanner.go:43] stream stdOut: forwarding "inventory update started"
I0505 00:02:25.873073   51916 subshell.go:78] accum stdOut: [deployment.apps/the-deployment reconcile successful]
I0505 00:02:25.873081   51916 subshell.go:78] accum stdOut: [reconcile phase finished]
I0505 00:02:25.873087   51916 subshell.go:78] accum stdOut: [inventory update started]
I0505 00:02:25.885130   51916 scanner.go:43] stream stdOut: forwarding "inventory update finished"
I0505 00:02:25.885184   51916 subshell.go:78] accum stdOut: [inventory update finished]
I0505 00:02:25.887431   51916 scanner.go:43] stream stdOut: forwarding "delete result: 3 attempted, 3 successful, 0 skipped, 0 failed"
I0505 00:02:25.887487   51916 scanner.go:43] stream stdOut: forwarding "reconcile result: 3 attempted, 3 successful, 0 skipped, 0 failed, 0 timed out"
I0505 00:02:25.887512   51916 subshell.go:78] accum stdOut: [delete result: 3 attempted, 3 successful, 0 skipped, 0 failed]
I0505 00:02:25.887521   51916 subshell.go:78] accum stdOut: [reconcile result: 3 attempted, 3 successful, 0 skipped, 0 failed, 0 timed out]
I0505 00:02:25.909249   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:25.909304   51916 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:02:25.911866   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:25.911925   51916 subshell.go:78] accum stdOut: [Success: output line found]
I0505 00:02:25.914442   51916 scanner.go:43] stream stdOut: forwarding "Success: output line found"
I0505 00:02:25.914518   51916 subshell.go:78] accum stdOut: [Success: output line found]
... skipping 46 lines ...
GREEN='\033[0;32m'
RED='\033[0;31m'
NC='\033[0m' # No Color

function expectedOutputLine() {
  if ! grep -q "$@" "$OUTPUT/status"; then
    echo -e "${RED}Error: output line not found${NC}"
    echo -e "${RED}Expected: $@${NC}"
    exit 1
  else
    echo -e "${GREEN}Success: output line found${NC}"
  fi
}
... skipping 206 lines ...
GREEN='\033[0;32m'
RED='\033[0;31m'
NC='\033[0m' # No Color

function expectedOutputLine() {
  if ! grep -q "$@" "$OUTPUT/status"; then
    echo -e "${RED}Error: output line not found${NC}"
    echo -e "${RED}Expected: $@${NC}"
    exit 1
  else
    echo -e "${GREEN}Success: output line found${NC}"
  fi
}
... skipping 33 lines ...