Skip to content

Instantly share code, notes, and snippets.

@mjudeikis

mjudeikis/v3.11 logs

Created June 25, 2020 09:08
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save mjudeikis/d7ecde3f6692b9a5cceb5fd5f4fa5b22 to your computer and use it in GitHub Desktop.
Save mjudeikis/d7ecde3f6692b9a5cceb5fd5f4fa5b22 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
v3.11 logs
RESOURCEGROUP is ci-2302-e2e-upgrade-uupgpq
go build -ldflags "-X main.gitCommit=v4.0-1349-g7be18e7" ./cmd/monitoring
time="2020-06-25T08:36:57Z" level=info msg="monitoring pod starting, git commit v4.0-1349-g7be18e7" component=monitor
time="2020-06-25T08:36:57Z" level=fatal msg="Cannot load clusterConfiguration from /tmp/tmp.OFakTUNPAm/src/github.com/openshift/openshift-azure/_data/containerservice.yaml: open /tmp/tmp.OFakTUNPAm/src/github.com/openshift/openshift-azure/_data/containerservice.yaml: no such file or directory" component=monitor
Note: checking out '8c178e7953e6ade46782753cc45d11b4e8d60dc8'.
You are in 'detached HEAD' state. You can look around, make experimental
changes and commit them, and you can discard any commits you make in this
state without impacting any branches by performing another checkout.
If you want to create a new branch to retain commits you create, you may
do so (now or later) by using -b with the checkout command again. Example:
git checkout -b new_branch_name
./hack/create.sh ci-2302-e2e-upgrade-uupgpq
time="2020-06-25T08:37:46Z" level=info msg="starting the fake resource provider" func="main.main()" file="cmd/fakerp/main.go:25"
time="2020-06-25T08:37:46Z" level=info msg="validating external plugin api data models" func="pkg/plugin.(*plugin).ValidatePluginTemplate()" file="pkg/plugin/plugin.go:128"
time="2020-06-25T08:37:46Z" level=info msg="starting server on localhost:8080" func="pkg/fakerp.(*Server).Run()" file="pkg/fakerp/server.go:78"
time="2020-06-25T08:37:49Z" level=info msg="using region australiasoutheast"
time="2020-06-25T08:37:49Z" level=info msg="using management resource group management-australiasoutheast"
time="2020-06-25T08:37:49Z" level=info msg="ensuring resource group ci-2302-e2e-upgrade-uupgpq"
time="2020-06-25T08:37:51Z" level=info msg="waiting for successful provision of resource group ci-2302-e2e-upgrade-uupgpq"
time="2020-06-25T08:37:52Z" level=info msg="create()"
time="2020-06-25T08:37:52Z" level=info msg="creating/updating cluster"
time="2020-06-25T08:37:52Z" level=debug msg="starting: PUT /subscriptions/225e02bc-43d0-43d1-a01a-17e584a4ef69/resourceGroups/ci-2302-e2e-upgrade-uupgpq/providers/Microsoft.ContainerService/openShiftManagedClusters/ci-2302-e2e-upgrade-uupgpq?api-version=2019-09-30-preview" func="pkg/fakerp.(*Server).logger.func1()" file="pkg/fakerp/middleware.go:16"
time="2020-06-25T08:37:52Z" level=info msg="read request and convert to internal" func="pkg/fakerp.(*Server).handlePut()" file="pkg/fakerp/customer_handlers.go:86"
time="2020-06-25T08:37:52Z" level=info msg="using region australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:68"
time="2020-06-25T08:37:52Z" level=info msg="using management resource group management-australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:72"
time="2020-06-25T08:37:52Z" level=info msg=enrich func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:183"
time="2020-06-25T08:37:52Z" level=info msg="setting up service principals" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:194"
time="2020-06-25T08:37:52Z" level=debug msg="create aad app auto-1593074272-ci-2302-e2e-upgrade-uupgpq-master" func="pkg/fakerp.(*aadManager).ensureApp()" file="pkg/fakerp/aad.go:66"
time="2020-06-25T08:38:14Z" level=debug msg="create aad app auto-1593074272-ci-2302-e2e-upgrade-uupgpq-worker" func="pkg/fakerp.(*aadManager).ensureApp()" file="pkg/fakerp/aad.go:66"
time="2020-06-25T08:38:31Z" level=info msg="validating internal data models" func="pkg/plugin.(*plugin).Validate()" file="pkg/plugin/plugin.go:56"
time="2020-06-25T08:38:31Z" level=info msg="setting up DNS" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:226"
time="2020-06-25T08:38:31Z" level=debug msg="creating cluster root dns zone \"ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateDns()" file="pkg/fakerp/dns.go:45"
time="2020-06-25T08:38:42Z" level=debug msg="creating NS record set \"ci-2302-e2e-upgrade-uupgpq\" in dns zone \"osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateZone()" file="pkg/fakerp/dns.go:127"
time="2020-06-25T08:38:43Z" level=debug msg="creating CNAME record set \"openshift\" in dns zone \"ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateDns()" file="pkg/fakerp/dns.go:52"
time="2020-06-25T08:38:43Z" level=debug msg="creating apps dns zone \"apps.ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateDns()" file="pkg/fakerp/dns.go:63"
time="2020-06-25T08:38:49Z" level=debug msg="creating NS record set \"apps\" in dns zone \"ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateZone()" file="pkg/fakerp/dns.go:127"
time="2020-06-25T08:38:50Z" level=debug msg="creating CNAME record set \"*\" in dns zone \"apps.ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateDns()" file="pkg/fakerp/dns.go:69"
time="2020-06-25T08:38:50Z" level=info msg="setting up key vault" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:237"
time="2020-06-25T08:38:58Z" level=info msg="waiting for keyvault DNS to be ready" func="pkg/fakerp.(*vaultManager).createOrUpdateVault()" file="pkg/fakerp/vault.go:192"
time="2020-06-25T08:39:07Z" level=info msg="validating internal data models" func="pkg/plugin.(*plugin).Validate()" file="pkg/plugin/plugin.go:56"
time="2020-06-25T08:39:07Z" level=info msg="generating configs" func="pkg/plugin.(*plugin).GenerateConfig()" file="pkg/plugin/plugin.go:140"
time="2020-06-25T08:39:28Z" level=info msg="write helpers" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:286"
time="2020-06-25T08:39:28Z" level=info msg="persist config" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:293"
time="2020-06-25T08:39:28Z" level=info msg="plugin createorupdate" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:299"
time="2020-06-25T08:39:28Z" level=info msg="creating clients" func="pkg/plugin.(*plugin).createOrUpdateExt()" file="pkg/plugin/plugin.go:296"
time="2020-06-25T08:39:28Z" level=info msg="creating Config storage" func="pkg/plugin.(*plugin).createOrUpdateExt()" file="pkg/plugin/plugin.go:302"
time="2020-06-25T08:39:28Z" level=info msg="creating/updating storage account" func="pkg/cluster.(*Upgrade).CreateOrUpdateConfigStorageAccount()" file="pkg/cluster/initialize.go:70"
time="2020-06-25T08:39:53Z" level=info msg="generating arm templates" func="pkg/plugin.(*plugin).createOrUpdateExt()" file="pkg/plugin/plugin.go:308"
time="2020-06-25T08:39:53Z" level=info msg="writing startup blobs" func="pkg/cluster.(*Upgrade).WriteStartupBlobs()" file="pkg/cluster/initialize.go:56"
time="2020-06-25T08:39:54Z" level=info msg="starting deploy" func="pkg/plugin.(*plugin).createOrUpdateExt()" file="pkg/plugin/plugin.go:344"
time="2020-06-25T08:39:54Z" level=info msg="applying arm template deployment" func="pkg/fakerp.GetDeployer.func1()" file="pkg/fakerp/fakerp.go:78"
time="2020-06-25T08:40:02Z" level=info msg="waiting for arm template deployment to complete" func="pkg/fakerp.GetDeployer.func1()" file="pkg/fakerp/fakerp.go:101"
time="2020-06-25T08:51:36Z" level=info msg="check PE existence" func="pkg/fakerp.GetDeployer.func1()" file="pkg/fakerp/fakerp.go:111"
time="2020-06-25T08:51:41Z" level=info msg="waiting for API server healthz" func="pkg/cluster.(*Upgrade).WaitForHealthzStatusOk()" file="pkg/cluster/healthcheck.go:41"
time="2020-06-25T08:51:42Z" level=info msg="updating sync pod" func="pkg/cluster.(*Upgrade).CreateOrUpdateSyncPod()" file="pkg/cluster/update_syncpod.go:9"
time="2020-06-25T08:51:49Z" level=info msg="waiting for master-000000 to be ready" func="pkg/cluster.(*Upgrade).WaitForNodesInAgentPoolProfile()" file="pkg/cluster/ready.go:19"
time="2020-06-25T08:51:53Z" level=info msg="waiting for master-000001 to be ready" func="pkg/cluster.(*Upgrade).WaitForNodesInAgentPoolProfile()" file="pkg/cluster/ready.go:19"
time="2020-06-25T08:51:57Z" level=info msg="waiting for master-000002 to be ready" func="pkg/cluster.(*Upgrade).WaitForNodesInAgentPoolProfile()" file="pkg/cluster/ready.go:19"
time="2020-06-25T08:52:01Z" level=info msg="waiting for infra-1593074368-000000 to be ready" func="pkg/cluster.(*Upgrade).WaitForNodesInAgentPoolProfile()" file="pkg/cluster/ready.go:19"
time="2020-06-25T08:53:49Z" level=info msg="waiting for infra-1593074368-000001 to be ready" func="pkg/cluster.(*Upgrade).WaitForNodesInAgentPoolProfile()" file="pkg/cluster/ready.go:19"
time="2020-06-25T08:53:50Z" level=info msg="waiting for infra-1593074368-000002 to be ready" func="pkg/cluster.(*Upgrade).WaitForNodesInAgentPoolProfile()" file="pkg/cluster/ready.go:19"
time="2020-06-25T08:53:52Z" level=info msg="waiting for compute-1593074368-000000 to be ready" func="pkg/cluster.(*Upgrade).WaitForNodesInAgentPoolProfile()" file="pkg/cluster/ready.go:19"
time="2020-06-25T08:53:54Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:54:06Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:54:16Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:54:26Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:54:36Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:54:46Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:54:56Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:55:06Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:55:16Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:55:26Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:55:36Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:55:46Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:55:56Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:56:06Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:56:15Z" level=info msg="checking developer console health" func="pkg/cluster.(*Upgrade).HealthCheck()" file="pkg/cluster/healthcheck.go:27"
time="2020-06-25T08:56:16Z" level=info msg="persist final config" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:306"
time="2020-06-25T08:56:16Z" level=debug msg="ending: PUT /subscriptions/225e02bc-43d0-43d1-a01a-17e584a4ef69/resourceGroups/ci-2302-e2e-upgrade-uupgpq/providers/Microsoft.ContainerService/openShiftManagedClusters/ci-2302-e2e-upgrade-uupgpq?api-version=2019-09-30-preview" func="pkg/fakerp.(*Server).logger.func1()" file="pkg/fakerp/middleware.go:18"
time="2020-06-25T08:56:16Z" level=debug msg="starting: GET /subscriptions/225e02bc-43d0-43d1-a01a-17e584a4ef69/resourceGroups/ci-2302-e2e-upgrade-uupgpq/providers/Microsoft.ContainerService/openShiftManagedClusters/ci-2302-e2e-upgrade-uupgpq?api-version=2019-09-30-preview" func="pkg/fakerp.(*Server).logger.func1()" file="pkg/fakerp/middleware.go:16"
time="2020-06-25T08:56:16Z" level=info msg="using region australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:68"
time="2020-06-25T08:56:16Z" level=info msg="using management resource group management-australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:72"
time="2020-06-25T08:56:18Z" level=debug msg="ending: GET /subscriptions/225e02bc-43d0-43d1-a01a-17e584a4ef69/resourceGroups/ci-2302-e2e-upgrade-uupgpq/providers/Microsoft.ContainerService/openShiftManagedClusters/ci-2302-e2e-upgrade-uupgpq?api-version=2019-09-30-preview" func="pkg/fakerp.(*Server).logger.func1()" file="pkg/fakerp/middleware.go:18"
time="2020-06-25T08:56:18Z" level=info msg="created/updated cluster"
time="2020-06-25T08:56:19Z" level=info msg="linked cluster ci-2302-e2e-upgrade-uupgpq to aad object id c51a2e51-0335-474c-bb0a-ce8810152239"
Cluster available at https://openshift.ci-2302-e2e-upgrade-uupgpq.osadev.cloud/
go-bindata 3.1.3 (Go runtime go1.12.15).
Copyright (c) 2010-2013, Jim Teeuwen.
go build -ldflags "-X main.gitCommit=v4.0-1349-g7be18e7" ./cmd/azure
./hack/image-build.sh images/azure/Dockerfile quay.io/openshift-on-azure/ci-azure:v4.0-1349-g7be18e7
time="2020-06-25T08:56:52Z" level=info msg="starting the fake resource provider" func="main.main()" file="cmd/fakerp/main.go:25"
time="2020-06-25T08:56:53Z" level=info msg="validating external plugin api data models" func="pkg/plugin.(*plugin).ValidatePluginTemplate()" file="pkg/plugin/plugin.go:128"
time="2020-06-25T08:56:53Z" level=info msg="starting server on localhost:8080" func="pkg/fakerp.(*Server).Run()" file="pkg/fakerp/server.go:78"
time="2020-06-25T08:56:54Z" level=debug msg="starting: GET /" func="pkg/fakerp.(*Server).logger.func1()" file="pkg/fakerp/middleware.go:16"
time="2020-06-25T08:56:54Z" level=info msg="using region australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:68"
time="2020-06-25T08:56:54Z" level=info msg="using management resource group management-australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:72"
time="2020-06-25T08:56:56Z" level=debug msg="ending: GET /" func="pkg/fakerp.(*Server).logger.func1()" file="pkg/fakerp/middleware.go:18"
map[kubelet_docker_operations_errors != 0:true kubelet_runtime_operations_errors != 0:true]=== RUN TestE2E
e2e tests starting, git commit COMMIT
Running Suite: e2e tests
========================
Random Seed: 1593075467
Will run 1 of 41 specs
configuring the fake resource provider
configuring the fake resource provider
SSSS
------------------------------
Change a single image to latest E2E tests [ChangeImage][LongRunning]
should be possible for an SRE to update a single container image
/home/prow/go/src/github.com/openshift/openshift-azure/test/e2e/specs/fakerp/setcontainerimage.go:26
STEP: getting the current Webconsole image to use
time="2020-06-25T08:57:54Z" level=debug msg="starting: GET /admin/subscriptions/225e02bc-43d0-43d1-a01a-17e584a4ef69/resourceGroups/ci-2302-e2e-upgrade-uupgpq/providers/Microsoft.ContainerService/openShiftManagedClusters/ci-2302-e2e-upgrade-uupgpq" func="pkg/fakerp.(*Server).logger.func1()" file="pkg/fakerp/middleware.go:16"
time="2020-06-25T08:57:54Z" level=info msg="using region australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:68"
time="2020-06-25T08:57:54Z" level=info msg="using management resource group management-australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:72"
time="2020-06-25T08:57:55Z" level=debug msg="ending: GET /admin/subscriptions/225e02bc-43d0-43d1-a01a-17e584a4ef69/resourceGroups/ci-2302-e2e-upgrade-uupgpq/providers/Microsoft.ContainerService/openShiftManagedClusters/ci-2302-e2e-upgrade-uupgpq" func="pkg/fakerp.(*Server).logger.func1()" file="pkg/fakerp/middleware.go:18"
STEP: finding a new Webconsole image to use
STEP: Executing a cluster update with updated image.
STEP: Reading the update blob before the update
time="2020-06-25T08:57:56Z" level=debug msg="starting: PUT /admin/subscriptions/225e02bc-43d0-43d1-a01a-17e584a4ef69/resourceGroups/ci-2302-e2e-upgrade-uupgpq/providers/Microsoft.ContainerService/openShiftManagedClusters/ci-2302-e2e-upgrade-uupgpq" func="pkg/fakerp.(*Server).logger.func1()" file="pkg/fakerp/middleware.go:16"
time="2020-06-25T08:57:56Z" level=info msg="using region australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:68"
time="2020-06-25T08:57:56Z" level=info msg="using management resource group management-australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:72"
time="2020-06-25T08:57:57Z" level=info msg="read request and convert to internal" func="pkg/fakerp.(*Server).handlePut()" file="pkg/fakerp/customer_handlers.go:86"
time="2020-06-25T08:57:57Z" level=info msg="admin request" func="pkg/fakerp.(*Server).handlePut()" file="pkg/fakerp/customer_handlers.go:90"
time="2020-06-25T08:57:57Z" level=info msg="using region australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:68"
time="2020-06-25T08:57:57Z" level=info msg="using management resource group management-australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:72"
time="2020-06-25T08:57:57Z" level=info msg=enrich func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:183"
time="2020-06-25T08:57:57Z" level=info msg="setting up service principals" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:194"
time="2020-06-25T08:57:57Z" level=info msg="validating internal admin data models" func="pkg/plugin.(*plugin).ValidateAdmin()" file="pkg/plugin/plugin.go:102"
time="2020-06-25T08:57:57Z" level=info msg="setting up DNS" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:226"
time="2020-06-25T08:57:57Z" level=debug msg="creating cluster root dns zone \"ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateDns()" file="pkg/fakerp/dns.go:45"
time="2020-06-25T08:58:00Z" level=debug msg="creating NS record set \"ci-2302-e2e-upgrade-uupgpq\" in dns zone \"osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateZone()" file="pkg/fakerp/dns.go:127"
time="2020-06-25T08:58:00Z" level=debug msg="creating CNAME record set \"openshift\" in dns zone \"ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateDns()" file="pkg/fakerp/dns.go:52"
time="2020-06-25T08:58:01Z" level=debug msg="creating apps dns zone \"apps.ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateDns()" file="pkg/fakerp/dns.go:63"
time="2020-06-25T08:58:03Z" level=debug msg="creating NS record set \"apps\" in dns zone \"ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateZone()" file="pkg/fakerp/dns.go:127"
time="2020-06-25T08:58:04Z" level=debug msg="creating CNAME record set \"*\" in dns zone \"apps.ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateDns()" file="pkg/fakerp/dns.go:69"
time="2020-06-25T08:58:05Z" level=info msg="setting up key vault" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:237"
time="2020-06-25T08:58:07Z" level=info msg="waiting for keyvault DNS to be ready" func="pkg/fakerp.(*vaultManager).createOrUpdateVault()" file="pkg/fakerp/vault.go:192"
time="2020-06-25T08:58:09Z" level=info msg="validating internal admin data models" func="pkg/plugin.(*plugin).ValidateAdmin()" file="pkg/plugin/plugin.go:102"
time="2020-06-25T08:58:09Z" level=info msg="generating configs" func="pkg/plugin.(*plugin).GenerateConfig()" file="pkg/plugin/plugin.go:140"
time="2020-06-25T08:58:09Z" level=info msg="write helpers" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:286"
time="2020-06-25T08:58:09Z" level=info msg="persist config" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:293"
time="2020-06-25T08:58:09Z" level=info msg="plugin createorupdate" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:299"
time="2020-06-25T08:58:09Z" level=info msg="creating clients" func="pkg/plugin.(*plugin).createOrUpdateExt()" file="pkg/plugin/plugin.go:296"
time="2020-06-25T08:58:09Z" level=info msg="creating Config storage" func="pkg/plugin.(*plugin).createOrUpdateExt()" file="pkg/plugin/plugin.go:302"
time="2020-06-25T08:58:09Z" level=info msg="creating/updating storage account" func="pkg/cluster.(*Upgrade).CreateOrUpdateConfigStorageAccount()" file="pkg/cluster/initialize.go:70"
time="2020-06-25T08:58:18Z" level=info msg="generating arm templates" func="pkg/plugin.(*plugin).createOrUpdateExt()" file="pkg/plugin/plugin.go:308"
time="2020-06-25T08:58:19Z" level=info msg="writing startup blobs" func="pkg/cluster.(*Upgrade).WriteStartupBlobs()" file="pkg/cluster/initialize.go:56"
time="2020-06-25T08:58:20Z" level=info msg="starting update" func="pkg/plugin.(*plugin).createOrUpdateExt()" file="pkg/plugin/plugin.go:342"
time="2020-06-25T08:58:20Z" level=info msg="applying arm template deployment" func="pkg/fakerp.GetDeployer.func1()" file="pkg/fakerp/fakerp.go:78"
time="2020-06-25T08:58:27Z" level=info msg="waiting for arm template deployment to complete" func="pkg/fakerp.GetDeployer.func1()" file="pkg/fakerp/fakerp.go:101"
time="2020-06-25T08:58:59Z" level=info msg="check PE existence" func="pkg/fakerp.GetDeployer.func1()" file="pkg/fakerp/fakerp.go:111"
time="2020-06-25T08:59:14Z" level=info msg="skipping vm \"master-000000\" since it's already updated" func="pkg/cluster.(*Upgrade).UpdateMasterAgentPool()" file="pkg/cluster/update_master.go:34"
time="2020-06-25T08:59:14Z" level=info msg="skipping vm \"master-000001\" since it's already updated" func="pkg/cluster.(*Upgrade).UpdateMasterAgentPool()" file="pkg/cluster/update_master.go:34"
time="2020-06-25T08:59:14Z" level=info msg="skipping vm \"master-000002\" since it's already updated" func="pkg/cluster.(*Upgrade).UpdateMasterAgentPool()" file="pkg/cluster/update_master.go:34"
time="2020-06-25T08:59:14Z" level=info msg="updating worker agent pool infra" func="pkg/cluster.(*Upgrade).UpdateWorkerAgentPool()" file="pkg/cluster/update_worker.go:62"
time="2020-06-25T08:59:15Z" level=info msg="found target scaleset ss-infra-1593074368" func="pkg/cluster.(*Upgrade).findScaleSets()" file="pkg/cluster/update_worker.go:43"
time="2020-06-25T08:59:15Z" level=info msg="updating worker agent pool compute" func="pkg/cluster.(*Upgrade).UpdateWorkerAgentPool()" file="pkg/cluster/update_worker.go:62"
time="2020-06-25T08:59:16Z" level=info msg="found target scaleset ss-compute-1593074368" func="pkg/cluster.(*Upgrade).findScaleSets()" file="pkg/cluster/update_worker.go:43"
time="2020-06-25T08:59:16Z" level=info msg="updating sync pod" func="pkg/cluster.(*Upgrade).CreateOrUpdateSyncPod()" file="pkg/cluster/update_syncpod.go:9"
time="2020-06-25T08:59:30Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:59:41Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T08:59:51Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T09:00:01Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T09:00:11Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T09:00:21Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T09:00:31Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T09:00:42Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T09:00:52Z" level=info msg="pod not yet started" func="pkg/cluster/kubeclient.(*Kubeclientset).WaitForReadySyncPod.func1()" file="pkg/cluster/kubeclient/ready.go:66"
time="2020-06-25T09:01:01Z" level=info msg="checking developer console health" func="pkg/cluster.(*Upgrade).HealthCheck()" file="pkg/cluster/healthcheck.go:27"
time="2020-06-25T09:01:02Z" level=info msg="persist final config" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:306"
time="2020-06-25T09:01:02Z" level=debug msg="ending: PUT /admin/subscriptions/225e02bc-43d0-43d1-a01a-17e584a4ef69/resourceGroups/ci-2302-e2e-upgrade-uupgpq/providers/Microsoft.ContainerService/openShiftManagedClusters/ci-2302-e2e-upgrade-uupgpq" func="pkg/fakerp.(*Server).logger.func1()" file="pkg/fakerp/middleware.go:18"
STEP: checking running webconsole image
STEP: Reading the update blob after the update
STEP: Verifying that the instance hashes of the update blob are identical (masters)
STEP: Verifying that the scaleset hashes of the update blob are identical (workers)
STEP: Checking that we can still access the console
STEP: checking https://console.apps.ci-2302-e2e-upgrade-uupgpq.osadev.cloud/health
• [SLOW TEST:190.581 seconds]
Change a single image to latest E2E tests [ChangeImage][LongRunning]
/home/prow/go/src/github.com/openshift/openshift-azure/test/e2e/specs/fakerp/setcontainerimage.go:22
should be possible for an SRE to update a single container image
/home/prow/go/src/github.com/openshift/openshift-azure/test/e2e/specs/fakerp/setcontainerimage.go:26
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
Ran 1 of 41 Specs in 193.054 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 40 Skipped
--- PASS: TestE2E (193.06s)
PASS
ok github.com/openshift/openshift-azure/test/e2e 198.150s
./hack/upgrade.sh ci-2302-e2e-upgrade-uupgpq
time="2020-06-25T09:01:08Z" level=info msg="starting the fake resource provider" func="main.main()" file="cmd/fakerp/main.go:25"
time="2020-06-25T09:01:08Z" level=info msg="validating external plugin api data models" func="pkg/plugin.(*plugin).ValidatePluginTemplate()" file="pkg/plugin/plugin.go:128"
time="2020-06-25T09:01:08Z" level=info msg="starting server on localhost:8080" func="pkg/fakerp.(*Server).Run()" file="pkg/fakerp/server.go:78"
time="2020-06-25T09:01:10Z" level=info msg="using region eastus"
time="2020-06-25T09:01:10Z" level=info msg="using management resource group management-eastus"
time="2020-06-25T09:01:10Z" level=info msg="ensuring resource group ci-2302-e2e-upgrade-uupgpq"
time="2020-06-25T09:01:11Z" level=info msg="create()"
time="2020-06-25T09:01:11Z" level=info msg="creating/updating cluster"
time="2020-06-25T09:01:11Z" level=debug msg="starting: PUT /admin/subscriptions/225e02bc-43d0-43d1-a01a-17e584a4ef69/resourceGroups/ci-2302-e2e-upgrade-uupgpq/providers/Microsoft.ContainerService/openShiftManagedClusters/ci-2302-e2e-upgrade-uupgpq" func="pkg/fakerp.(*Server).logger.func1()" file="pkg/fakerp/middleware.go:16"
time="2020-06-25T09:01:11Z" level=info msg="using region australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:68"
time="2020-06-25T09:01:11Z" level=info msg="using management resource group management-australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:72"
time="2020-06-25T09:01:14Z" level=info msg="read request and convert to internal" func="pkg/fakerp.(*Server).handlePut()" file="pkg/fakerp/customer_handlers.go:86"
time="2020-06-25T09:01:14Z" level=info msg="admin request" func="pkg/fakerp.(*Server).handlePut()" file="pkg/fakerp/customer_handlers.go:90"
time="2020-06-25T09:01:14Z" level=info msg="using region australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:68"
time="2020-06-25T09:01:14Z" level=info msg="using management resource group management-australiasoutheast" func="pkg/fakerp/client.newConfig()" file="pkg/fakerp/client/config.go:72"
time="2020-06-25T09:01:14Z" level=info msg=enrich func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:183"
time="2020-06-25T09:01:14Z" level=info msg="setting up service principals" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:194"
time="2020-06-25T09:01:14Z" level=info msg="validating internal admin data models" func="pkg/plugin.(*plugin).ValidateAdmin()" file="pkg/plugin/plugin.go:102"
time="2020-06-25T09:01:14Z" level=info msg="setting up DNS" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:226"
time="2020-06-25T09:01:14Z" level=debug msg="creating cluster root dns zone \"ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateDns()" file="pkg/fakerp/dns.go:45"
time="2020-06-25T09:01:19Z" level=debug msg="creating NS record set \"ci-2302-e2e-upgrade-uupgpq\" in dns zone \"osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateZone()" file="pkg/fakerp/dns.go:127"
time="2020-06-25T09:01:19Z" level=debug msg="creating CNAME record set \"openshift\" in dns zone \"ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateDns()" file="pkg/fakerp/dns.go:52"
time="2020-06-25T09:01:20Z" level=debug msg="creating apps dns zone \"apps.ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateDns()" file="pkg/fakerp/dns.go:63"
time="2020-06-25T09:01:23Z" level=debug msg="creating NS record set \"apps\" in dns zone \"ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateZone()" file="pkg/fakerp/dns.go:127"
time="2020-06-25T09:01:23Z" level=debug msg="creating CNAME record set \"*\" in dns zone \"apps.ci-2302-e2e-upgrade-uupgpq.osadev.cloud\"" func="pkg/fakerp.(*dnsManager).createOrUpdateDns()" file="pkg/fakerp/dns.go:69"
time="2020-06-25T09:01:24Z" level=info msg="setting up key vault" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:237"
time="2020-06-25T09:01:27Z" level=info msg="waiting for keyvault DNS to be ready" func="pkg/fakerp.(*vaultManager).createOrUpdateVault()" file="pkg/fakerp/vault.go:192"
time="2020-06-25T09:01:29Z" level=info msg="validating internal admin data models" func="pkg/plugin.(*plugin).ValidateAdmin()" file="pkg/plugin/plugin.go:102"
time="2020-06-25T09:01:29Z" level=info msg="generating configs" func="pkg/plugin.(*plugin).GenerateConfig()" file="pkg/plugin/plugin.go:140"
time="2020-06-25T09:01:29Z" level=info msg="write helpers" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:286"
time="2020-06-25T09:01:29Z" level=info msg="persist config" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:293"
time="2020-06-25T09:01:29Z" level=info msg="plugin createorupdate" func="pkg/fakerp.createOrUpdateWrapper()" file="pkg/fakerp/fakerp.go:299"
time="2020-06-25T09:01:29Z" level=info msg="creating clients" func="pkg/plugin.(*plugin).createOrUpdateExt()" file="pkg/plugin/plugin.go:296"
time="2020-06-25T09:01:29Z" level=info msg="creating Config storage" func="pkg/plugin.(*plugin).createOrUpdateExt()" file="pkg/plugin/plugin.go:302"
time="2020-06-25T09:01:29Z" level=info msg="creating/updating storage account" func="pkg/cluster.(*Upgrade).CreateOrUpdateConfigStorageAccount()" file="pkg/cluster/initialize.go:70"
time="2020-06-25T09:01:40Z" level=info msg="generating arm templates" func="pkg/plugin.(*plugin).createOrUpdateExt()" file="pkg/plugin/plugin.go:308"
time="2020-06-25T09:01:40Z" level=info msg="writing startup blobs" func="pkg/cluster.(*Upgrade).WriteStartupBlobs()" file="pkg/cluster/initialize.go:56"
time="2020-06-25T09:01:41Z" level=info msg="starting update" func="pkg/plugin.(*plugin).createOrUpdateExt()" file="pkg/plugin/plugin.go:342"
time="2020-06-25T09:01:41Z" level=info msg="applying arm template deployment" func="pkg/fakerp.GetDeployer.func1()" file="pkg/fakerp/fakerp.go:78"
time="2020-06-25T09:01:49Z" level=info msg="waiting for arm template deployment to complete" func="pkg/fakerp.GetDeployer.func1()" file="pkg/fakerp/fakerp.go:101"
time="2020-06-25T09:02:21Z" level=info msg="check PE existence" func="pkg/fakerp.GetDeployer.func1()" file="pkg/fakerp/fakerp.go:111"
time="2020-06-25T09:02:23Z" level=info msg="draining master-000000" func="pkg/cluster.(*Upgrade).UpdateMasterAgentPool()" file="pkg/cluster/update_master.go:38"
time="2020-06-25T09:02:24Z" level=info msg="deallocating master-000000" func="pkg/cluster.(*Upgrade).UpdateMasterAgentPool()" file="pkg/cluster/update_master.go:44"
time="2020-06-25T09:06:31Z" level=info msg="updating master-000000" func="pkg/cluster.(*Upgrade).UpdateMasterAgentPool()" file="pkg/cluster/update_master.go:50"
time="2020-06-25T09:07:27Z" level=info msg="reimaging master-000000" func="pkg/cluster.(*Upgrade).UpdateMasterAgentPool()" file="pkg/cluster/update_master.go:58"
time="2020-06-25T09:07:28Z" level=debug msg="400 Bad Request: Failed to apply request: UpdateMasterAgentPoolReimage: compute.VirtualMachineScaleSetVMsClient#Reimage: Failure sending request: StatusCode=400 -- Original Error: Code=\"BadRequest\" Message=\"The VM Instance 0 in Virtual Machine Scale Set ss-master cannot be found.\"" func="pkg/fakerp.(*Server).badRequest()" file="pkg/fakerp/util.go:24"
time="2020-06-25T09:07:28Z" level=debug msg="ending: PUT /admin/subscriptions/225e02bc-43d0-43d1-a01a-17e584a4ef69/resourceGroups/ci-2302-e2e-upgrade-uupgpq/providers/Microsoft.ContainerService/openShiftManagedClusters/ci-2302-e2e-upgrade-uupgpq" func="pkg/fakerp.(*Server).logger.func1()" file="pkg/fakerp/middleware.go:18"
time="2020-06-25T09:07:28Z" level=fatal msg="400: 400 Bad Request: Failed to apply request: UpdateMasterAgentPoolReimage: compute.VirtualMachineScaleSetVMsClient#Reimage: Failure sending request: StatusCode=400 -- Original Error: Code=\"BadRequest\" Message=\"The VM Instance 0 in Virtual Machine Scale Set ss-master cannot be found.\"\n"
exit status 1
make: *** [upgrade] Error 1
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment